stupid question: syslogging plaintext non-syslog-format messages unchanged (netconsole)
So I'm trying to get the Linux kernel netconsole working, to diagnose some nasty persistent panics... and after some struggle I've got most of it working, but I can't make syslog-ng (3.0 from git as of tonight) cooperate. The problem seems to be that netconsole is handing syslog-ng completely bare text lines over UDP, and syslog-ng is persistently trying to linebreak them at apparently random space characters, even with the no-parse flag turned on. Some specifics. I'm receiving the netconsole messages with the following (trimmed down from the real 500-line-long config, all global options preserved in this trim, I'm pretty sure this is everything relevant but I haven't tested this on its own yet 'cos it would break syslogging for a fairly large network to actually replace the syslog-ng config with this): ,---- | options | { | keep_hostname(no); | create_dirs(1); | perm(0644); | dir_perm(0755); | log_fifo_size(1000); | use_dns(yes); | dns_cache(yes); | use_fqdn(no); | log_iw_size(5192); | flush_lines(100); | flush_timeout(1000); | stats_freq(3600); | chain_hostnames(yes); | }; | | source netconsole | { | udp(ip(0.0.0.0) port(24183) log_fetch_limit(100) flags(no-parse no-multi-line)); | }; | | # A bare template, for netconsole messages. | template bare | { | template("$MSG\n"); | template_escape(no); | }; | | destination netconsole | { | file("/var/log/$HOST-netconsole.log" | template(bare)); | }; | | log | { | source(netconsole); | destination(netconsole); | }; `---- but this is not enough. Most of the time the same message is received over an ordinary syslog source, too, so I can compare the two. If the syslogged message reads: ,---- | Oct 20 21:17:53 mutilate warning: : [ 6783.237435] pktcdvd: Fixed packets, 32 blocks, Mode-2 disc | Oct 20 21:17:53 mutilate warning: : [ 6783.238541] pktcdvd: write caching control failed | Oct 20 21:17:53 mutilate warning: : [ 6783.238547] pktcdvd: 55 10 00 00 00 00 00 00 14 00 00 00 - sense 05.00.00 (Illegal request) `---- the netconsole message that's logged using the configuration above reads ,---- | [ 6783.237435] pktcdvd: Fixed packets, | 32 blocks, | Mode-2 disc | [ 6783.238541] pktcdvd: write caching control failed | [ 6783.238547] pktcdvd: | 55 | 10 | 00 | 00 | 00 | 00 | 00 | 00 | 14 | 00 | 00 | 00 | - | sense 05.00.00 | (Illegal request) `---- This is obviously not sane. Removing the no-multi-line flag doesn't change anything at all (I only added it in desperation, because I *want* linebreaks in the original message to be reproduced in the output: I just don't want *more* linebreaks than are present in the original output), so that's not it either. I'm logging kernel messages using ,---- | source local | { | unix-stream("/dev/log" flags(no-multi-line)); | internal(); | file("/proc/kmsg" program_override("kernel: ") flags(kernel no-multi-line)); | }; `---- and things hanging off that, without incident: no random linebreaks or anything. So, what am I missing? It's probably incredibly obvious, but I've blown several hours hacking at configs and digging through the syslog-ng source and have seen nothing to indicate what's going on...
On Tue, 2009-10-20 at 21:30 +0100, Nix wrote:
So I'm trying to get the Linux kernel netconsole working, to diagnose some nasty persistent panics... and after some struggle I've got most of it working, but I can't make syslog-ng (3.0 from git as of tonight) cooperate. The problem seems to be that netconsole is handing syslog-ng completely bare text lines over UDP, and syslog-ng is persistently trying to linebreak them at apparently random space characters, even with the no-parse flag turned on.
Some specifics.
I'm receiving the netconsole messages with the following (trimmed down from the real 500-line-long config, all global options preserved in this trim, I'm pretty sure this is everything relevant but I haven't tested this on its own yet 'cos it would break syslogging for a fairly large network to actually replace the syslog-ng config with this):
,---- | options | { | keep_hostname(no); | create_dirs(1); | perm(0644); | dir_perm(0755); | log_fifo_size(1000); | use_dns(yes); | dns_cache(yes); | use_fqdn(no); | log_iw_size(5192); | flush_lines(100); | flush_timeout(1000); | stats_freq(3600); | chain_hostnames(yes); | }; | | source netconsole | { | udp(ip(0.0.0.0) port(24183) log_fetch_limit(100) flags(no-parse no-multi-line)); | }; | | # A bare template, for netconsole messages. | template bare | { | template("$MSG\n"); | template_escape(no); | }; | | destination netconsole | { | file("/var/log/$HOST-netconsole.log" | template(bare)); | }; | | log | { | source(netconsole); | destination(netconsole); | }; `----
but this is not enough. Most of the time the same message is received over an ordinary syslog source, too, so I can compare the two. If the syslogged message reads:
,---- | Oct 20 21:17:53 mutilate warning: : [ 6783.237435] pktcdvd: Fixed packets, 32 blocks, Mode-2 disc | Oct 20 21:17:53 mutilate warning: : [ 6783.238541] pktcdvd: write caching control failed | Oct 20 21:17:53 mutilate warning: : [ 6783.238547] pktcdvd: 55 10 00 00 00 00 00 00 14 00 00 00 - sense 05.00.00 (Illegal request) `----
the netconsole message that's logged using the configuration above reads
,---- | [ 6783.237435] pktcdvd: Fixed packets, | 32 blocks, | Mode-2 disc | [ 6783.238541] pktcdvd: write caching control failed | [ 6783.238547] pktcdvd: | 55 | 10 | 00 | 00 | 00 | 00 | 00 | 00 | 14 | 00 | 00 | 00 | - | sense 05.00.00 | (Illegal request) `----
This is obviously not sane. Removing the no-multi-line flag doesn't change anything at all (I only added it in desperation, because I *want* linebreaks in the original message to be reproduced in the output: I just don't want *more* linebreaks than are present in the original output), so that's not it either. I'm logging kernel messages using
,---- | source local | { | unix-stream("/dev/log" flags(no-multi-line)); | internal(); | file("/proc/kmsg" program_override("kernel: ") flags(kernel no-multi-line)); | }; `----
and things hanging off that, without incident: no random linebreaks or anything.
So, what am I missing? It's probably incredibly obvious, but I've blown several hours hacking at configs and digging through the syslog-ng source and have seen nothing to indicate what's going on...
Hmm, I guess that the kernel outputs those characters as individual UDP frames, right? At least syslog-ng probably receives them as individual packets, perhaps because a single line of kernel message is generated by separate printk() invocations in the kernel source. /proc/kmsg is not packet terminated. However I've personally used syslog-ng for netconsole, and I can't remember having this issue. Can you confirm that this is the case? -- Bazsi
[Sorry about the delay, reading lists intermittently right now owing to far too much travel] On 3 Nov 2009, Balazs Scheidler spake thusly:
On Tue, 2009-10-20 at 21:30 +0100, Nix wrote:
So, what am I missing? It's probably incredibly obvious, but I've blown several hours hacking at configs and digging through the syslog-ng source and have seen nothing to indicate what's going on...
Hmm, I guess that the kernel outputs those characters as individual UDP frames, right? At least syslog-ng probably receives them as individual packets, perhaps because a single line of kernel message is generated by separate printk() invocations in the kernel source. /proc/kmsg is not packet terminated.
You're probably right, but most of the time when this happens the kernel is oopsing, so it's sort of hard to get a packet dump :) However, certainly in this case those linefeed-terminated things are separate printk()s, and, hm, looking at the netconsole source every printk() yields an immediate UDP packet, without buffering. (This makes sense given the last-ditch nature of netconsole: even doing this, it sometimes lops chunks off the ends of panics.)
However I've personally used syslog-ng for netconsole, and I can't remember having this issue.
Can you confirm that this is the case?
Looks like it. End-of-packet shuld not imply linefeed in this case (I suspect real linefeeds get sent across the line, and we should never add linefeeds merely because a packet has ended. At least not for this application.)
On Wed, 2009-11-11 at 21:23 +0000, Nix wrote:
[Sorry about the delay, reading lists intermittently right now owing to far too much travel]
On 3 Nov 2009, Balazs Scheidler spake thusly:
On Tue, 2009-10-20 at 21:30 +0100, Nix wrote:
So, what am I missing? It's probably incredibly obvious, but I've blown several hours hacking at configs and digging through the syslog-ng source and have seen nothing to indicate what's going on...
Hmm, I guess that the kernel outputs those characters as individual UDP frames, right? At least syslog-ng probably receives them as individual packets, perhaps because a single line of kernel message is generated by separate printk() invocations in the kernel source. /proc/kmsg is not packet terminated.
You're probably right, but most of the time when this happens the kernel is oopsing, so it's sort of hard to get a packet dump :)
However, certainly in this case those linefeed-terminated things are separate printk()s, and, hm, looking at the netconsole source every printk() yields an immediate UDP packet, without buffering. (This makes sense given the last-ditch nature of netconsole: even doing this, it sometimes lops chunks off the ends of panics.)
However I've personally used syslog-ng for netconsole, and I can't remember having this issue.
Can you confirm that this is the case?
Looks like it. End-of-packet shuld not imply linefeed in this case (I suspect real linefeeds get sent across the line, and we should never add linefeeds merely because a packet has ended. At least not for this application.)
Yeah, but the problem is that syslog-ng is assuming it is receving a syslog protocol, where packet ending implies end of message even if tehre's no newline character. I've been biten with this before, although ancient syslog-ng versions didn't behave like they do now, and it'd be possible to modify the current logic to not use packet based termination, but to use the same logic as when using TCP. If you want to do that, you could change afsocket_sc_init(), not to pass an LPPF_PKTTERM flag to the protocol implementation in this block: /* plain protocol */ proto = log_proto_plain_new_server(transport, self->owner->reader_options.padding, self->owner->reader_options.msg_size, (self->owner->flags & AFSOCKET_DGRAM) ? (LPPF_PKTTERM + LPPF_IGNORE_EOF) : 0); -- Bazsi
participants (2)
-
Balazs Scheidler
-
Nix