Xavier <xavier.tromp@...> writes:
>
> Hello,
>
> First thanks for open sourcing heka, it is my first attempt at trying
to
> build a centralized log infrastructure, and being on a small budget, I
> really appreciate the small memory/cpu footprint !
>
> So I send my docker logs to the docker host syslog, then I run a heka
> container with a volume mounting the docker host syslog file.
> As in syslog I have both my application/php logs (monolog) and my
nginx
> logs, I use a multi decoder.
>
> In my nginx.conf file, I have the following log_format :
> log_format custom '$remote_addr - $remote_user [$time_local]
"$request"
> $status $body_bytes_sent "$http_referer" "$http_user_agent"
> "$http_x_forwarded_for" "$hostname" $request_time
> $upstream_response_time $pipe';
>
> In my heka.toml, I have the following (so the log_format in nginx.conf
> is the same as in the nginx-access-decoder.config) :
>
> [nginx-app-logs]
> type = "LogstreamerInput"
> log_directory = "/var/log"
> file_match = 'syslog'
> decoder = "nginx-syslog-decoder"
>
> [nginx-syslog-decoder]
> type = "MultiDecoder"
> subs = ['nginx-access-decoder', 'rsyslog-decoder']
> cascade_strategy = "first-wins"
> log_sub_errors = true
>
> [nginx-access-decoder]
> type = "SandboxDecoder"
> filename = "lua_decoders/nginx_access.lua"
>
> [nginx-access-decoder.config]
> type = "nginx.access"
> user_agent_transform = true
> log_format = '$remote_addr - $remote_user [$time_local] "$request"
> $status $body_bytes_sent "$http_referer" "$http_user_agent"
> "$http_x_forwarded_for" "$hostname" $request_time
> $upstream_response_time $pipe'
>
> [rsyslog-decoder]
> type = "SandboxDecoder"
> filename = "lua_decoders/rsyslog.lua"
>
> [rsyslog-decoder.config]
> template = '<%pri%>%TIMESTAMP% %HOSTNAME% %syslogtag%%msg:::sp-if-
> no-1st-sp%%msg:::drop-last-lf%\n'
> type = "rsyslog.main"
> tz = "UTC"
>
> [PayloadEncoder]
> append_newlines = false
>
> [LogOutput]
> message_matcher = "TRUE"
> encoder = "PayloadEncoder"
>
> Here is a sample nginx log :
> Jul 30 01:25:50 test docker/2ff84aa6f7a5[14793]: 172.17.42.1 - -
> [30/Jul/2015:01:25:50 +0000] "GET /some_url HTTP/1.1" 200 60543 "-"
> "Mozilla/5.0 (Windows NT 6.3; WOW64) AppleWebKit/537.36 (KHTML, like
> Gecko) Chrome/44.0.2403.125 Safari/537.36" "-" "test.dev" 0.841 0.841
.
>
> When I check my heka docker logs, I have the following errors :
> 2015/07/30 01:17:01 Decoder 'nginx-app-logs-nginx-syslog-decoder-1'
> error: All subdecoders failed.
> 2015/07/30 01:25:51 Decoder 'nginx-app-logs-nginx-syslog-decoder-1'
> error: Subdecoder 'nginx-access-decoder' decode error: Failed parsing:
> payload: Jul 30 01:25:50 test docker/2ff84aa6f7a5[14793]: 172.17.42.1
-
> - [30/Jul/2015:01:25:50 +0000] "GET /some_url HTTP/1.1" 200 60543 "-"
> "Mozilla/5.0 (Windows NT 6.3; WOW64) AppleWebKit/537.36 (KHTML, like
> Gecko) Chrome/44.0.2403.125 Safari/537.36" "-" "test.dev" 0.841 0.841
.
> 2015/07/30 01:25:51 Decoder 'nginx-app-logs-nginx-syslog-decoder-1'
> error: Subdecoder 'rsyslog-decoder' decode error: Failed parsing:
> payload: Jul 30 01:25:50 test docker/2ff84aa6f7a5[14793]: 172.17.42.1
-
> - [30/Jul/2015:01:25:50 +0000] "GET /some_url HTTP/1.1" 200 60543 "-"
> "Mozilla/5.0 (Windows NT 6.3; WOW64) AppleWebKit/537.36 (KHTML, like
> Gecko) Chrome/44.0.2403.125 Safari/537.36" "-" "test.dev" 0.841 0.841
.
>
> Do you have some clues why the nginx decoder fails in the first place
?
> Or maybe the multi decoder approach is wrong for this usecase ?
> Thanks for the help.
>
> Cheers,
> Xavier
>
I forgot to mention that I was running the Heka 0.10.0.b0 version from
deb package on a phusion:baseimage.
I did further testing to try to understand what is going on.
Test 1 : I tried to use DockerLogInput
First I stopped and removed all containers (so noting on docker ps and
psa)
Second I start a container that output some text to stdout "docker run -
d busybox /bin/sh -c 'while true; do echo Hello world; sleep 30; done'"
Third I start my heka container with the following configs :
[DockerLogInput]
endpoint = "unix:///var/run/docker.sock"
[LogOutput]
message_matcher = "Type == 'DockerLog'"
encoder = "RstEncoder"
[RstEncoder]
When I docker logs on the heka container, it outputs thousands of :
2015/07/30 12:01:18
:Timestamp: 2015-07-30 12:01:18.250235518 +0000 UTC
:Type: DockerLog
:Hostname: f64129eee133
:Pid: 0
:Uuid: 179354bb-ef4f-45b9-992d-da8458e05474
:Logger: stdout
:Payload: :Fields:
:EnvVersion:
:Severity: 7
:Fields:
| name:"ContainerID" type:string value:"f64129eee133"
| name:"ContainerName" type:string value:"heka_1.0"
2015/07/30 12:01:18
:Timestamp: 2015-07-30 12:01:18.250255038 +0000 UTC
:Type: DockerLog
:Hostname: f64129eee133
:Pid: 0
:Uuid: a6561a31-bfdd-4b0d-abc3-27067de864e7
:Logger: stdout
:Payload: | name:"ContainerID" type:string value:"f64129eee133"
:EnvVersion:
:Severity: 7
:Fields:
| name:"ContainerName" type:string value:"heka_1.0"
| name:"ContainerID" type:string value:"f64129eee133"
I don't understand why I get all those messages, like if heka where
getting old docker containers logs. Is it possible to get only logs from
running containers ? Or maybe those messages are a different issue...
Test 2 : I tried to make nginx log decoding works separatly by mounting
an access.log file in the heka container with just one line of my syslog
"Jul 30 01:25:50 test docker/2ff84aa6f7a5[14793]: 172.17.42.1 - -
[30/Jul/2015:01:25:50 +0000] "GET /some_url HTTP/1.1" 200 60543 "-"
"Mozilla/5.0 (Windows NT 6.3; WOW64) AppleWebKit/537.36 (KHTML, like
Gecko) Chrome/44.0.2403.125 Safari/537.36" "-" "test.dev" 0.841 0.841 ."
I have the following config :
[LogstreamerInput]
log_directory = "/var/log/nginx"
file_match = 'access\.log'
decoder = "nginx-access-decoder"
[nginx-access-decoder]
type = "SandboxDecoder"
script_type = "lua"
filename = "lua_decoders/nginx_access.lua"
[nginx-access-decoder.config]
type = "nginx.access"
user_agent_transform = true
log_format = '$remote_addr - $remote_user [$time_local] "$request"
$status $body_bytes_sent "$http_referer" "$http_user_agent"
"$http_x_forwarded_for" "$hostname" $request_time
$upstream_response_time $pipe'
[PayloadEncoder]
append_newlines = false
[LogOutput]
message_matcher = "TRUE"
encoder = "PayloadEncoder"
I get the following error as before :
2015/07/30 12:30:28 Decoder 'LogstreamerInput-nginx-access-decoder-1'
error: Failed parsing: payload: Jul 30 01:25:50 test
docker/2ff84aa6f7a5[14793]: 172.17.42.1 - - [30/Jul/2015:01:25:50 +0000]
"GET /some_url HTTP/1.1" 200 60543 "-" "Mozilla/5.0 (Windows NT 6.3;
WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.125
Safari/537.36" "-" "test.dev" 0.841 0.841 .
Now if I remove "Jul 30 01:25:50 test docker/2ff84aa6f7a5[14793]: " from
the access.log, the content will match the log_format and I get no
errors but nothing is outputed when I "docker logs".
Is this the excpected behaviour ? Does the nginx_access.lua excpects
logs without "Jul 30 01:25:50 test docker/2ff84aa6f7a5[14793]: ", or
there is a way to substring that part ?
Thanks
_______________________________________________
Heka mailing list
[email protected]
https://mail.mozilla.org/listinfo/heka
