Upgrade to Pro
— share decks privately, control downloads, hide ads and more …
Speaker Deck
Speaker Deck
PRO
Sign in
Sign up
for free
Log Everything with Fluentd
Kentaro Kuribayashi
February 15, 2013
Technology
4
4k
Log Everything with Fluentd
Kentaro Kuribayashi
February 15, 2013
Tweet
Share
More Decks by Kentaro Kuribayashi
See All by Kentaro Kuribayashi
kentaro
2
500
kentaro
1
1k
kentaro
0
120
kentaro
1
490
kentaro
3
480
kentaro
0
430
kentaro
3
1.3k
kentaro
3
570
kentaro
0
12k
Other Decks in Technology
See All in Technology
techharmony
0
160
oracle4engineer
9
6.1k
akabekobeko
0
160
halhira
1
120
ayatokura
1
170
kadoppe
1
220
tatsy
0
120
ayatokura
0
260
tsuyo
0
730
finengine
0
330
ishiayaya
PRO
0
140
sat
1
270
Featured
See All Featured
edds
56
9.4k
geoffreycrofte
25
1k
lynnandtonic
272
16k
reverentgeek
27
2.1k
zakiwarfel
88
3.4k
iamctodd
22
2.2k
notwaldorf
19
2.1k
pauljervisheath
195
15k
mza
80
4.2k
deanohume
294
28k
danielanewman
2
560
roundedbygravity
242
21k
Transcript
Log Everything @kentaro
@kentaro Software engineer Rubyist / Perl Monger Kentaro Kuribayashi paperboy&co.
PHPer
None
Contributions to Fluentd World
out_flatten https://github.com/kentaro/fluent-plugin-flatten out_extract_query_params https://github.com/kentaro/fluent-plugin-extract_query_params out_rewrite https://github.com/kentaro/fluent-plugin-rewrite
None
Log Format
None
• Easy to extend • Easy to parse
Key Description Apache Nginx time Time request is received %t
$time_local vhost Host name %v $host host Remote host %h $remote_addr method Request method %m $method path Request path %U%q $request_uri version HTTP version %H $server_protocol status Response status %>s $status size Response size %b $body_bytes_sent referer Referer %{Referer}i $http_referer ua User-agent %{User-Agent}i $http_user_agent restime Time elapsed for response %D $request_time ustime Time elapsed for upstream response - $upstream_response_time
LogFormat "vhost:%V\ttime:%t\thost:%h\tmethod:%m\tpath:%U%q \tversion:%H\tstatus:%>s\tsize:%b\treferer:%{Referer}i\tua: %{User-Agent}i\trestime:%D" ltsv log_format ltsv "vhost:$host\ttime:$time_local\thost: $remote_addr\tmethod:$request_method\tpath:$request_uri \tversion:$server_protocol\tstatus:$status\tsize:
$body_bytes_sent\treferer:$http_referer\tua: $http_user_agent\trestime:$request_time\tustime: $upstream_response_time"; Apache Nginx
Log Everything to Access Log File
with Log Everything to Access Log File
fluent-plugin-php
None
apache_note()
%{foo}n #=> bar apache_note(‘foo’, ‘bar’) PHP Code Apache Log Format
Flags
• URL Groups • User/Guest • Device • Bot Access
• etc.
Structuralize URLs • Visualization • Analysis • Rough grouping is
enough
Group Path read ^/book buy ^/cart ^/book/\d+/purchase find ^/special ^/label
^/users ^/books ^/authors write ^/admin ^/users/{account}/draft set ^/users/{account}/manage ^/users/{account}/profile ^/users/{account}/account communicate ^/users/{account}/contact ^/users/{account}/reaction top ^/$ ^$
out_rewrite
<match apache.log.**> type rewrite remove_prefix apache.log add_prefix filtered # url
group <rule> key uriGroup pattern ^(.+)$ append_to_tag true fallback other </rule> ...
... # pc/smartphone <rule> key device pattern ^(pc|sp)$ append_to_tag true
</rule> ...
... # user/guest <rule> key loggedIn pattern ^(user|guest)$ append_to_tag true
</rule> </match>
filtered.book.pc.user => { ... } filtered.book.sp.guest => { ... }
filtered.read.pc.guest => { ... } ... uriGroup:book device:pc loggedIn:user ... ... uriGroup:book device:sp loggedIn:guest ... ... uriGroup:read device:pc loggedIn:guest ... Raw Log Lines Filtered Key/Values
None
Profiling
Problem Hard to track results continuously
class Foo { function hoge () { $this->profiler->start(‘method-hoge’); // ...
do something ... $this->profiler->end(‘method-hoge’); } function fuga () { $this->profiler->start(‘method-fuga-foo’); // ... do something ... $this->profiler->end(‘method-fuga-foo’); $this->profiler->start(‘method-fuga-bar’); // ... do something ... $this->profiler->end(‘method-fuga-bar’); } }
public function dispatchLoopShutdown() { $profile_result = Model_Measure::dump(); if (APPLICATION_ENV !==
'production') { Pb_Logger::debug($profile_result); } Pb_Util::httpd_note('profile', json_encode($profile_result)); }
static public function httpd_note($name, $value = '') { if (function_exists('apache_note'))
{ if ($value) { return apache_note($name, $value); } else { // do nothing... } } }
... profile:%{profile}n" ... profile:{\"book.index.get_book\":0.1010639667511, \"book.index.get_author\":0.2032630443573, \"book.index.get_chapters\":0.23988509178162, \"book.index.get_version\":0.039833068847656, \"book.index.check\":0.00014090538024902, \"book.index.get_pager\":0.00022792816162109} Log
Format Raw Log Line
out_flatten
<match test.**> type flatten key foo add_tag_prefix flattened. remove_tag_prefix test.
inner_key value_for_flat_key </match> "test" => { "foo" => '{"bar" : {"qux" : "quux", "hoe" : "poe" }, "baz" : "bazz" }', "hoge" => "fuga" } "flattened.foo.bar.qux" => { "value_for_flat_key" => "quux" } "flattened.foo.bar.hoe" => { "value_for_flat_key" => "poe" } "flattened.foo.baz" => { "value_for_flat_key" => "bazz" } flattened
<match app.httpd.access> type flatten key profile inner_key response_time add_tag_prefix flattened.
remove_tag_prefix app.httpd.access. </store>
None
None
Bonus
out_extract_query_params
<match test.**> type extract_query_params key url add_tag_prefix extracted. only foo,
baz </match> "test" => { "url" => "http://example.com/?foo=bar&baz=qux&hoge=fuga" } "extracted.test" => { "url" => "http://example.com/?foo=bar&baz=qux&hoge=fuga" "foo" => "bar", "baz" => "qux" } Extract Params
<match access_log> type extract_query_params key path add_tag_prefix extracted. only hoge
</match> method:%m path:%U%q version:%H #=> method:GET path:/foo/bar?campaign_id=1 version:HTTP1.1 extracted.access_log => { "method" : "GET", "path" : "/foo/bar?campaign_id=1", "version" : "HTTP1.1", "campaign_id" : "1" } Extract Params Works fine with LTSV
Recap
• Adopt LTSV asap • Log things as much as
possible • My plugins help you