Forum Discussion
kiwibloke_17342
Nimbostratus
NimbostratusHSL logging sending multiple log entries in one message?
Hi,
I have an iRule that generates Apache style "combined" format access logs for one of our sites. it is based on the iRule for "W3c logging".
Our LTMs run 10.x so HSL is an option. These logs are destined to be used for fraud detection systems, so I have to use TCP.
I have one syslog server in the syslog pool and it should be able to handle the traffic.
The irule is attached as is an example (sanitised) access log captured on the syslog server.
The syslog server takes the entire message received and dumps it raw as a single log entry into a log file that rolls hourly.
Most of the time it seems to be that one request = one log entry, however occasionally I see a single log entry as being made up of two distinct http_requests
Its almost as if the events have been concatenated together before being sent. logic tells me this can't happen since the iRule only fires once per request, so by virtue of that alone one request should equal one log entry.
Has anyone else come across this before? I want to rule out the LTMs before I look deeper at the syslog server.
KB
hooleylistCirrostratus
Hi KB,
I think by design, HSL can reuse an existing connection to the pool for multiple messages. Ideally, the syslog server would be able to split the messages regardless of the connection reuse. Or maybe you could configure the syslog server to close the connection after one message? I'm not sure there is a simple way to prevent connection reuse on HSL.
Aaron
kiwibloke_17342Hi,
Thanks, I am going to run TCP dump shortly so I can do a packet analysis to see exactly what the LTMs are firing out.
It still seems odd that I am seeing multiple messages appearing in a single message transmit only some of the time. I would expect it that would be doing this all the time or none of the time. it can't be load related as I am using a shadow vIP for my testing. I am the only one hitting the shadow vIP and I am pretty sure F5 designed the HSL engine to scale higher than one concurrent user! :D
Regarding the site this is intended for the page I am testing on generates 25 http requests, yet I usually only see 20 lines in the log
Thanks for your help, if i find out anything that might be useful to the group I will post my findings.
Cheers,
KB- kiwibloke_17342Done the TCP dump.
It looks as if the LTM is sending multiple log entries in some of its transmissions
I have seen some packets that contain upto 3 access log entries.
I wonder if this is a direct consequence of using TCP over UDP.
If using UDP it wouldn't have the overhead of a handshake on every packet so it probably just fires them out individually. Using TCP it does so it might be optimizing each sent packet to contain as much information a possible so as to reduce the overhead of the handshake.
I think I need to log a support ticket.
:) - hooleylistIf you do open a case with F5 Support, can you post the case number so I can follow it?
Thanks, Aaron - Classical syslog (RFC3164) expects one message per UDP packet with no terminating newline. Many servers also support TCP transport and expect the messages to be separated by newlines, but there is no formal standard for this -- even the later RFC5424 does not define how messages should be separated when encapsulated in protocols other than UDP.
Your iRule is not providing a separator, so message separation is essentially being left up to server intelligence and luck. If you add a "\n" to the end of your string, your problems should go away :).
It would be possible to make HSL::send "smart" enough to automagically append a newline when logging to a TCP destination and add a -nonewline flag for users who really do want a "raw" send so they can use arbitrary separators. OTOH, any time you make something "smart", you also make it more confusing. - kiwibloke_17342Hi,
The case ID is C1087278.
Thanks for the tip Jessie, I thought about this last night too!
So this morning I added a "\r\n" to the end of the log entry (a CRLF) and configured my syslog server to split on CR/LF.
Hey presto it works.
I also had to do some tweaking on the clock format and handling for when referrer,content size and uri_query were zero. But that was pretty straight forward.
So now the iRule output looks identical to the output you'd get from an Apache tomcat server using the combined log format.
KB. - kiwibloke_17342The final (sanitised) iRule is attached.
This iRule generates Tomcat "combined" format style access logs and sends them via HSL to your remote syslog server.
KB. - hooleylistNice work kiwi. And thanks for the info Jessie. I need to go back and add terminators to all my HSL examples now!
Aaron
