Clustered Logging with mod_log_spread Theo Schlossnagle - - PowerPoint PPT Presentation

Clustered Logging

with mod_log_spread Theo Schlossnagle <jesus@omniti.com>

2

The Speaker

• pen-source developer

mod_backhand W ackamole daiquiri OpenSSH/SecurID Spread etc. closed-source developer Ecelerity MTA Portcullis Anti-Spam

Theo Schlossnagle Pricipal @ OmniTI

3

Agenda

Understanding the Problem Space A Survey of Technologies Implementing Clustered Logging Understanding New Possibilities

Understanding the Problem Space

5

The Purpose of Logging

Journalling the fact that a transaction has taken place. Correlating a series of transactions into a session. An audit trail. Forensics. Activity analysis to understand current trends and predict the future.

6

Basic Expectations

Logs are reliable. Events are logged in the order they

• ccur.

They can be partitioned by date. They can be multiplexed and demultiplexed on demand.

7

Clustering: several machines acting together to provide a single service Sessions may now be composed of a series transactions that occur on different machines. Ordering is “harder” and more important.

Introducing Clustering

A Survey of Technologies

9

Traditional Logging

Logs written locally on web servers

space must be allocated

Consolidation happens periodically

crashes will result in missing data aggregators must preserve chronology real-time metrics cannot be calculated

Monitors must run against log servers

monitors must tail log files requires resources on the log servers

Traditional Approach:Logging in its infancy

11

Active Network Logging

Logs written directly to log servers

UDP is unreliable and thus not useful TCP is a point-to-point protocol Two log server mean double traffic Add a monitor and that’s triple!

Real-time metrics are possible

monitors must tail log files still (or publishers must send directly to the monitors... yuck!)

Network Approach:

Adolescent Logging

13

Passive Network Logging

Logs constructed from sniffed traffic

The players no longer matter W eb servers can be added easily

Drops logs!

When tested head-to-head with active logging frameworks we see loss Missing logs is unacceptable

Passive Logging:

A lapse in judgement

15

mod_log_spread Logging

Logs are published over Spread

Efficient reliable network multicast Preserves global ordering of logs

Multiple subscribers at no cost

well... almost zero

Extends well beyond Apache

All logging (enterprise wide) can be utilize this publish/subscribe messaging bus

mod_log_spread:

Mature Logging

17

With clustered logging we get:

instant aggregation

• rdering

publish/subscribe model multiple subscribers multiple subscribers multiple subscribers...

18

Data “feeds” Write them to disk Understand load- balanced click streams Real-time analysis:

popular pages concurrent sessions

Who’s online?

Multiple Subscriber Magic

Implementing Clustered Logging

20

Okay, so show me!

Spread Apache 1.3 or 2.0 mod_log_spread spreadlogd A spread client API for your favorite language:

Perl, Python, C Java, Ruby, PHP , etc.

21

Get and install Spread

http://www.spread.org/

A simple /etc/spread.conf: DebugFlags = { EXIT CONFIGURATION } EventLogFile = /var/log/spread/mainlog EventTimeStamp Spread_Segment 10.225.209.255:4913 { # order matters admin-va-1 10.225.209.68 # staging server www-va-1 10.225.209.71 www-va-2 10.225.209.72 www-va-3 10.225.209.73 samwise 10.225.209.240 # logging machines gollum 10.225.209.241 # monitoring machine }

22

Get and install mod_log_spread

http://www.backhand.org/

A simple httpd.conf: LoadModule log_spread_module libexec/mod_log_spread.so AddModule mod_log_spread.c #AddModule mod_log_config.c SpreadDaemon 4913 LogFormat “%h %l %u %t \”%r\” %>s %b” common <VirtualHost coolsiteip:80> CustomLog $coolsite common </VirtualHost> <VirtualHost slicksiteip:80> CustomLog $slicksite common </VirtualHost>

23

V erify by hand that it is working...

; /opt/spread/bin/spuser -s 4913 User: connected to 4913 with private group #user#admin-va-1 User> j coolsite ============================ Received REGULAR membership for group coolsite with 2 members, where I am member 1: #user#admin-va-1 grp id is 182571332 1092928408 2 Due to the JOIN of #user#admin-va-1 User> ============================ received RELIABLE message from #ap25454#admin-va-1, of type 1, (endian 0) to 1 groups (182 bytes): 68.55.183.91 - - [30/Oct/2004:11:48:51 -0400] “GET /~jesus/ HTTP/1.1” 200 57940 “-” “Mozilla/5.0 (Macintosh; U; PPC Mac OS X; en) AppleW ebKit/125.5 (KHTML, like Gecko) Safari/125.9” ... ... ...

24

Get spreadlogd and install it:

http://www.backhand.org/mod_log_spread/

A simple /etc/spreadlogd.conf: BufferSize = 65536 Spread { Port = 4913 Log { RewriteTimestamp = CommonLogFormat Group = “coolsite” File = /data/logs/apache/coolsite/common_log } Log { RewriteTimestamp = CommonLogFormat Group = “slicksite” File = /data/logs/apache/slicksite/combined_log } }

25

Spreadlogd

Super advanced Kung-Fu

BufferSize = 65536 PerlLib /opt/spreadlogd/custom PerlUse mylogger Spread { Port = 4913 Log { RewriteTimestamp = CommonLogFormat Group = “coolsite” PerlLog mylogger::log File = /data/logs/apache/coolsite/common_log } Log { RewriteTimestamp = CommonLogFormat Group = “slicksite” File = /data/logs/apache/slicksite/combined_log } }

26

Spreadlogd

Super advanced Kung-Fu (continued)

package mylogger; use DBI;

• ur $dbh;
• ur $sth;

sub log($$$) { my $sender = shift; my $group = shift; my $message = shift; my ($user, $host) = ($sender =~ /#([^#]+)#([^#]+)/); chomp($message); $dbh ||= DBI->connect(”DBI:mysql:database=weblogs”, “logger”, “”, { RaiseError => 0 }); warn “DBI->connect failed.” unless($dbh); if($dbh) { $sth ||= $dbh->prepare(q{INSERT INTO logs (host, group, timestamp, data) VALUES(?,?,NOW(),?)}); $sth->execute($host, $group, $message); } }

Understanding New Possibilities

28

Logs are now streaming in real time

Real-time metrics per server hit rates (traffic) per server hits by response code

relative error serving rate

per server document size metrics

detect unexpected bugs do to anomalous traffic

T rack deeper data user habits length of visit online

All this happens passively!!!

29

On community sites and social networking sites it is vital to understand who is online and what they are looking at. Having that in real-time afford unprecedented opportunity. Why not expose the information to a user’s peers as a value add.

Who’s Online?

30

Skiplist Index on:

username url,hitdate hitdate

Single thread, event driven Receive messages from Spread:

parse username, url, hitdate delete from skiplist by username O(lg n) insert into skiplist O(lg n) pop the end of the skiplist of any hitdate > 30 minutes O(1)

Receive client requests

Cardinality query is O(1), single write() Users on a url query is O(lg), O(1) to fill out iovec, single writev()

The concept:

31

6 hours worth of coding and testing 800 lines of C code (server) use libspread and libskiplist 40 lines of perl (client module for web app) On commodity hardware ($2k box) ~80,000 inserts/second more hits than we’ll ever see! ~100,000,000 counts/second -- not including write() ~500,000 users for urls/second -- not including writev() Add a bit more effort and expose this data over SOAP or SNMP or something clever and you can integrate it seamlessly into your overall architecture.

The result:

32

Stupid Pet Tricks

Credit Where Credit’s Due

The John Hopkins University

The Center for Networking and Distributed Systems

OmniTI Computer Consulting The Authors and Contributors of Spread:

Yair Amir, Michal Miskin-Amir, Jonathan Stanton, Christin Nita-Rotaru, Theo Schlossnagle, Dan Schoenblum, John Schultz, Ryan Caudy, Ben Laurie, Daniel Rall, Marc Zyngier

The Authors of mod_log_spread and Tools:

George Schlossnagle, Theo Schlossnagle, Jonathan Stanton, Yair Amir

Questions?