alibaba / tengine

A distribution of Nginx with some advanced features
https://tengine.taobao.org
BSD 2-Clause "Simplified" License
12.84k stars 2.52k forks source link

Support for rsyslog tags. #169

Open seefood opened 11 years ago

seefood commented 11 years ago

Hi yaoweibin! I have been playing with tengine for the last 48 hours as a syslog-abled nginx, after rsyslog's imfile proved to be generating way too many duplicate, triplicate and at times 50-cate log lines.

the only thing missing is the rsyslog's ability to use "tags" to create a detailed log taxonomy beyond just the standard facilities. I produce an error log and three different access logs from my backend API server (based on uri prefix) in with different CSV columns for different statistics gathering. With tengine I was able to give each one a different "ident" but it does not translate to a different rsyslog tag, only adds it to the beginning of the line and wracks my csv logformat. does this have a patch?

yaoweibin commented 11 years ago

It seems the first column is the server's hostname, the second is the ident name. I will talk to my colleague about your request. Thanks.

cfsego commented 11 years ago

I have no idea why rsyslog do not recognize the tag because the log format is quite correct according to RFC 3164. I think you should capture network packets and inquire rsyslog first.

pkmiec commented 11 years ago

I believe the "problem" is tengine always sending hostname as part of the message.

Here is a snippet from my nginx.conf,

access_log syslog:user:info:/dev/log:nginx-dep;

which is received by rsyslog's imuxsock module as,

Debug line with all properties:
FROMHOST: 'my.host.name', fromhost-ip: '127.0.0.1', HOSTNAME: 'my.host.name', PRI: 14,
syslogtag 'my.host.name', programname: 'my.host.name', APP-NAME: 'my.host.name', PROCID: '-', MSGID: '-',
TIMESTAMP: 'Mar 20 17:34:10', STRUCTURED-DATA: '-',
msg: ' nginx-dep[5788]: localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -'
escaped msg: ' nginx-dep[5788]: localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -'
inputname: imuxsock rawmsg: '<14>Mar 20 17:33:58 my.host.name nginx-dep[5788]: localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -'

However, the imuxsock module cannot parse hostnames and considers 'my.host.name' to be the "tag".

Now change nginx.conf to,

access_log syslog:user:info:127.0.0.1:514:nginx-dep;

which is received by rsyslog's imtcp module as,

Debug line with all properties:
FROMHOST: 'localhost.localdomain', fromhost-ip: '127.0.0.1', HOSTNAME: 'my.host.name', PRI: 14,
syslogtag 'nginx-dep[5788]:', programname: 'nginx-dep', APP-NAME: 'nginx-dep', PROCID: '5788', MSGID: '-',
TIMESTAMP: 'Mar 20 17:34:10', STRUCTURED-DATA: '-',
msg: ' localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -'
escaped msg: ' localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -'
inputname: imtcp rawmsg: '<14>Mar 20 17:34:10 my.host.name nginx-dep[5788]: localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -'

But now, imtcp correctly parses 'my.host.name' as hostname and 'nginx-dep' as the "tag".

My understanding of the syslog standard is that there is not real standard, so it is difficult to say who is really at fault here (probably no one and everyone). However, when one uses the logger command it does not include the hostname. So perhaps tengine should also not include the hostname when logging to a unix socket.

Thoughts?

cfsego commented 11 years ago

i have doubt about this, when i dismiss hostname field from a message, whether all clients will accept it correctly. maybe i should follow the "freebsd syslog protocol" strictly, to cut the hostname into only one segment without a dot ( http://www.faqs.org/rfcs/rfc3164.html 5.2 ), but i am not sure whether it works. i will work on it soon, and perhaps you will help me make sure about this before my patch is done

On Thu, Mar 21, 2013 at 4:36 AM, Paul Kmiec notifications@github.comwrote:

I believe the "problem" is tengine always sending hostname as part of the message.

Here is a snippet from my nginx.conf,

access_log syslog:user:info:/dev/log:nginx-dep;

which is received by rsyslog's imuxsock module as,

Debug line with all properties: FROMHOST: 'my.host.name', fromhost-ip: '127.0.0.1', HOSTNAME: 'my.host.name', PRI: 14, syslogtag 'my.host.name', programname: 'my.host.name', APP-NAME: 'my.host.name', PROCID: '-', MSGID: '-', TIMESTAMP: 'Mar 20 17:34:10', STRUCTURED-DATA: '-', msg: ' nginx-dep[5788]: localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -' escaped msg: ' nginx-dep[5788]: localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -' inputname: imuxsock rawmsg: '<14>Mar 20 17:33:58 my.host.name nginx-dep[5788]: localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -'

However, the imuxsock module cannot parse hostnames and considers 'my.host' to be the "tag".

Now change nginx.conf to,

access_log syslog:user:info:127.0.0.1:514:nginx-dep;

which is received by rsyslog's imtcp module as,

Debug line with all properties: FROMHOST: 'localhost.localdomain', fromhost-ip: '127.0.0.1', HOSTNAME: 'my.host.name', PRI: 14, syslogtag 'nginx-dep[5788]:', programname: 'nginx-dep', APP-NAME: 'nginx-dep', PROCID: '5788', MSGID: '-', TIMESTAMP: 'Mar 20 17:34:10', STRUCTURED-DATA: '-', msg: ' localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -' escaped msg: ' localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -' inputname: imtcp rawmsg: '<14>Mar 20 17:34:10 my.host.name nginx-dep[5788]: localhost - "HEAD /system/ping HTTP/1.1" 200 0b 55.517s "-" "-" -'

But now, imtcp correctly parses 'my.host' as hostname and 'nginx-dep' as the "tag".

My understanding of the syslog standard is that there is not real standard, so it is difficult to say who is really at fault here (probably no one and everyone). However, when one uses the logger command it does not include the hostname. So perhaps nginx should also not include the hostname when logging to a unix socket.

Thoughts?

— Reply to this email directly or view it on GitHubhttps://github.com/alibaba/tengine/issues/169#issuecomment-15201721 .

Charles Chen

Software Engineer

Server Platforms Team at Taobao.com

pkmiec commented 11 years ago

Keep in mind that RFC3164 is not a spec ... but rather a document that "describes the observed behavior of the syslog protocol. This protocol has been used for the transmission of event notification messages across networks for many years." In fact, the document only talks about UDP.

The /dev/log is meant for logging by local processes. It does not send messages across network. As I said, I think the best example to follow is the "logger" command.

pkmiec commented 11 years ago

I also believe the original nginx syslog patch (by @yaoweibin I think) did not send hostname.

yaoweibin commented 11 years ago

@pkmiec, Thanks for your report and correct us. That's may be the difference with the udp socket and unix socket. We will review the logger program and check this problem.

ghost commented 11 years ago

This problem occurs in function "ngx_syslog_prebuild_header" at "/src/os/unix/ngx_syslog.c".

image