3.2.5 and Multiline(?) messages from Solaris
Admittedly haven't done enough searching or testing on this, but am hoping someone might have a quick answer. Recently moved from the 2.x verions to 3.2.5 (as part of EPEL on RHEL6). Have noticed that we're no longer getting the full messages from some Solaris boxen using the tcp() and udp() source definitions. Messages like this: May 10 02:29:30 dev-zfs2 scsi: [ID 365881 kern.info] /pci@0,0/pci8086,3410@9/pci15d9,400@0 (mpt_sas0): May 10 02:29:30 dev-zfs2 Log info 0x31080000 received for target 24. May 10 02:29:30 dev-zfs2 scsi_status=0x0, ioc_status=0x804b, scsi_state=0x0 Come through looking like this: May 10 02:29:30 dev-zfs2 scsi: [ID 365881 kern.info] /pci@0,0/pci8086,3410@9/pci15d9,400@0 (mpt_sas0): (Only the initial line) However, messages like this one: May 9 04:12:57 dev-zfs2 scsi: [ID 243001 kern.warning] WARNING: /pci@0,0/pci8086,3410@9/pci15d9,400@0 (mpt_sas0): May 9 04:12:57 dev-zfs2 mptsas_handle_event_sync: IOCStatus=0x8000, IOCLogInfo=0x31110610 .. do seem to be coming through "whole" (I do note that the priority is different in both). Relevant config items are as follows: log { source(remote); filter(syslog); destination(hosts_syslog); }; source remote { udp(); tcp(); # udp(ip(0.0.0.0) port(514)); # tcp(ip(0.0.0.0) port(514)); }; destination hosts_syslog { file("/logs/hosts/$HOST/$YEAR/$MONTH/syslog.$HOST.$YEAR.$MONTH.log" create_dirs(yes)); pipe("/logs/hosts/everything.fifo"); }; filter syslog { (not facility(mail) and not filter(f_ucgw) and not filter(f_esx)); }; Will try and do some packet captures to confirm Solaris is, in fact, sending the entire message (I believe it is since this worked on syslog-ng 2.x). Thanks, Ray
The most important thing with multiline is the transport. Udp can transmit multiline messages just as syslog(transport(tcp)) but of course the client has to support the same protocol. What do you use on the solaris side? If you haven't changed the client I don't see why the message would be truncated like that. Once received syslog-ng would only replace newlines with spaces. So I guess it is a transport issue on the sending side. But tcpdump/wireshark should help a lot here. On May 12, 2015 05:43, "Ray Van Dolson" <rvandolson@esri.com> wrote:
Admittedly haven't done enough searching or testing on this, but am hoping someone might have a quick answer.
Recently moved from the 2.x verions to 3.2.5 (as part of EPEL on RHEL6). Have noticed that we're no longer getting the full messages from some Solaris boxen using the tcp() and udp() source definitions.
Messages like this:
May 10 02:29:30 dev-zfs2 scsi: [ID 365881 kern.info] /pci@0 ,0/pci8086,3410@9/pci15d9,400@0 (mpt_sas0): May 10 02:29:30 dev-zfs2 Log info 0x31080000 received for target 24. May 10 02:29:30 dev-zfs2 scsi_status=0x0, ioc_status=0x804b, scsi_state=0x0
Come through looking like this:
May 10 02:29:30 dev-zfs2 scsi: [ID 365881 kern.info] /pci@0 ,0/pci8086,3410@9/pci15d9,400@0 (mpt_sas0):
(Only the initial line)
However, messages like this one:
May 9 04:12:57 dev-zfs2 scsi: [ID 243001 kern.warning] WARNING: /pci@0 ,0/pci8086,3410@9/pci15d9,400@0 (mpt_sas0): May 9 04:12:57 dev-zfs2 mptsas_handle_event_sync: IOCStatus=0x8000, IOCLogInfo=0x31110610
.. do seem to be coming through "whole" (I do note that the priority is different in both).
Relevant config items are as follows:
log { source(remote); filter(syslog); destination(hosts_syslog); };
source remote { udp(); tcp(); # udp(ip(0.0.0.0) port(514)); # tcp(ip(0.0.0.0) port(514)); };
destination hosts_syslog { file("/logs/hosts/$HOST/$YEAR/$MONTH/syslog.$HOST.$YEAR.$MONTH.log" create_dirs(yes)); pipe("/logs/hosts/everything.fifo"); };
filter syslog { (not facility(mail) and not filter(f_ucgw) and not filter(f_esx)); };
Will try and do some packet captures to confirm Solaris is, in fact, sending the entire message (I believe it is since this worked on syslog-ng 2.x).
Thanks, Ray
______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.balabit.com/wiki/syslog-ng-faq
On Tue, May 12, 2015 at 08:49:20AM +0200, Scheidler, Balázs wrote:
The most important thing with multiline is the transport.
Udp can transmit multiline messages just as syslog(transport(tcp)) but of course the client has to support the same protocol.
What do you use on the solaris side?
Using the default syslog daemon in Solaris 10 (uses UDP).
If you haven't changed the client I don't see why the message would be truncated like that. Once received syslog-ng would only replace newlines with spaces.
So I guess it is a transport issue on the sending side. But tcpdump/wireshark should help a lot here.
Packet capture results leave me scratching my head a bit: 714 2015-05-12 03:41:06.172567 10.49.6.166 10.49.7.16 Syslog 150 KERN.WARNING: May 12 03:41:06 scsi: [ID 243001 kern.warning] WARNING: /pci@0,0/pci8086,3410@9/pci15d9,400@0 (mpt_sas0): 715 2015-05-12 03:41:06.172575 10.49.6.166 10.49.7.16 Syslog 127 KERN.WARNING: May 12 03:41:06 \tmptsas_handle_event_sync: IOCStatus=0x8000, IOCLogInfo=0x31110610 718 2015-05-12 03:41:10.172475 10.49.6.166 10.49.7.16 Syslog 138 KERN.INFO: May 12 03:41:10 scsi: [ID 365881 kern.info] /pci@0,0/pci8086,3410@9/pci15d9,400@0 (mpt_sas0): 719 2015-05-12 03:41:10.172483 10.49.6.166 10.49.7.16 Syslog 105 KERN.INFO: May 12 03:41:10 \tLog info 0x31110610 received for target 24. 721 2015-05-12 03:41:10.172487 10.49.6.166 10.49.7.16 Syslog 142 KERN.WARNING: May 12 03:41:10 scsi: [ID 107833 kern.warning] WARNING: /scsi_vhci/disk@g5000c50019bc81e1 (sd31): 722 2015-05-12 03:41:10.172491 10.49.6.166 10.49.7.16 Syslog 110 KERN.WARNING: May 12 03:41:10 \tSCSI transport failed: reason 'reset': giving up (Sorry for the word-wrap). So, you can see the second line comes through as a completely separate message with a tab character '\t' at the beginning. The odd thing? Packets 714 & 715 come through fine and syslog-ng appends them both to my output log. However, for pairs 718 & 719 and 721 & 722, only the first line comes through. In both cases the tab character is 0x09 so not seeing a difference there. Makes me think it's something in the syslog-ng config rather than the message. Probably will move to something super simple to see that fixes it (keeping in mind this behavior didn't occur w/ syslog-ng 2.x). Ray
On May 12, 2015 05:43, "Ray Van Dolson" <rvandolson@esri.com> wrote:
Admittedly haven't done enough searching or testing on this, but am hoping someone might have a quick answer.
Recently moved from the 2.x verions to 3.2.5 (as part of EPEL on RHEL6). Have noticed that we're no longer getting the full messages from some Solaris boxen using the tcp() and udp() source definitions.
Messages like this:
May 10 02:29:30 dev-zfs2 scsi: [ID 365881 kern.info] /pci@0,0/ pci8086,3410@9/pci15d9,400@0 (mpt_sas0): May 10 02:29:30 dev-zfs2 Log info 0x31080000 received for target 24. May 10 02:29:30 dev-zfs2 scsi_status=0x0, ioc_status=0x804b, scsi_state=0x0
Come through looking like this:
May 10 02:29:30 dev-zfs2 scsi: [ID 365881 kern.info] /pci@0,0/ pci8086,3410@9/pci15d9,400@0 (mpt_sas0):
(Only the initial line)
However, messages like this one:
May 9 04:12:57 dev-zfs2 scsi: [ID 243001 kern.warning] WARNING: /pci@0,0/ pci8086,3410@9/pci15d9,400@0 (mpt_sas0): May 9 04:12:57 dev-zfs2 mptsas_handle_event_sync: IOCStatus=0x8000, IOCLogInfo=0x31110610
.. do seem to be coming through "whole" (I do note that the priority is different in both).
Relevant config items are as follows:
log { source(remote); filter(syslog); destination(hosts_syslog); };
source remote { udp(); tcp(); # udp(ip(0.0.0.0) port(514)); # tcp(ip(0.0.0.0) port(514)); };
destination hosts_syslog { file("/logs/hosts/$HOST/$YEAR/$MONTH/syslog.$HOST.$YEAR.$MONTH.log" create_dirs(yes)); pipe("/logs/hosts/everything.fifo"); };
filter syslog { (not facility(mail) and not filter(f_ucgw) and not filter(f_esx)); };
Will try and do some packet captures to confirm Solaris is, in fact, sending the entire message (I believe it is since this worked on syslog-ng 2.x).
Thanks, Ray
Hmm what was the sniffer that printed these lines? I would prefer to see what was in the wire exactly as these seem to have been processed somewhat. On May 12, 2015 5:02 PM, "Ray Van Dolson" <rvandolson@esri.com> wrote:
On Tue, May 12, 2015 at 08:49:20AM +0200, Scheidler, Balázs wrote:
The most important thing with multiline is the transport.
Udp can transmit multiline messages just as syslog(transport(tcp)) but of course the client has to support the same protocol.
What do you use on the solaris side?
Using the default syslog daemon in Solaris 10 (uses UDP).
If you haven't changed the client I don't see why the message would be truncated like that. Once received syslog-ng would only replace newlines with spaces.
So I guess it is a transport issue on the sending side. But tcpdump/wireshark should help a lot here.
Packet capture results leave me scratching my head a bit:
714 2015-05-12 03:41:06.172567 10.49.6.166 10.49.7.16 Syslog 150 KERN.WARNING: May 12 03:41:06 scsi: [ID 243001 kern.warning] WARNING: /pci@0 ,0/pci8086,3410@9/pci15d9,400@0 (mpt_sas0): 715 2015-05-12 03:41:06.172575 10.49.6.166 10.49.7.16 Syslog 127 KERN.WARNING: May 12 03:41:06 \tmptsas_handle_event_sync: IOCStatus=0x8000, IOCLogInfo=0x31110610
718 2015-05-12 03:41:10.172475 10.49.6.166 10.49.7.16 Syslog 138 KERN.INFO: May 12 03:41:10 scsi: [ID 365881 kern.info] /pci@0 ,0/pci8086,3410@9/pci15d9,400@0 (mpt_sas0): 719 2015-05-12 03:41:10.172483 10.49.6.166 10.49.7.16 Syslog 105 KERN.INFO: May 12 03:41:10 \tLog info 0x31110610 received for target 24.
721 2015-05-12 03:41:10.172487 10.49.6.166 10.49.7.16 Syslog 142 KERN.WARNING: May 12 03:41:10 scsi: [ID 107833 kern.warning] WARNING: /scsi_vhci/disk@g5000c50019bc81e1 (sd31): 722 2015-05-12 03:41:10.172491 10.49.6.166 10.49.7.16 Syslog 110 KERN.WARNING: May 12 03:41:10 \tSCSI transport failed: reason 'reset': giving up
(Sorry for the word-wrap).
So, you can see the second line comes through as a completely separate message with a tab character '\t' at the beginning.
The odd thing? Packets 714 & 715 come through fine and syslog-ng appends them both to my output log.
However, for pairs 718 & 719 and 721 & 722, only the first line comes through. In both cases the tab character is 0x09 so not seeing a difference there.
Makes me think it's something in the syslog-ng config rather than the message. Probably will move to something super simple to see that fixes it (keeping in mind this behavior didn't occur w/ syslog-ng 2.x).
Ray
On May 12, 2015 05:43, "Ray Van Dolson" <rvandolson@esri.com> wrote:
Admittedly haven't done enough searching or testing on this, but am hoping someone might have a quick answer.
Recently moved from the 2.x verions to 3.2.5 (as part of EPEL on RHEL6). Have noticed that we're no longer getting the full messages from some Solaris boxen using the tcp() and udp() source definitions.
Messages like this:
May 10 02:29:30 dev-zfs2 scsi: [ID 365881 kern.info] /pci@0,0/ pci8086,3410@9/pci15d9,400@0 (mpt_sas0): May 10 02:29:30 dev-zfs2 Log info 0x31080000 received for
target 24.
May 10 02:29:30 dev-zfs2 scsi_status=0x0, ioc_status=0x804b, scsi_state=0x0
Come through looking like this:
May 10 02:29:30 dev-zfs2 scsi: [ID 365881 kern.info] /pci@0,0/ pci8086,3410@9/pci15d9,400@0 (mpt_sas0):
(Only the initial line)
However, messages like this one:
May 9 04:12:57 dev-zfs2 scsi: [ID 243001 kern.warning] WARNING:
/pci@0,0/
pci8086,3410@9/pci15d9,400@0 (mpt_sas0): May 9 04:12:57 dev-zfs2 mptsas_handle_event_sync:
IOCStatus=0x8000,
IOCLogInfo=0x31110610
.. do seem to be coming through "whole" (I do note that the priority is different in both).
Relevant config items are as follows:
log { source(remote); filter(syslog); destination(hosts_syslog); };
source remote { udp(); tcp(); # udp(ip(0.0.0.0) port(514)); # tcp(ip(0.0.0.0) port(514)); };
destination hosts_syslog {
file("/logs/hosts/$HOST/$YEAR/$MONTH/syslog.$HOST.$YEAR.$MONTH.log"
create_dirs(yes)); pipe("/logs/hosts/everything.fifo"); };
filter syslog { (not facility(mail) and not filter(f_ucgw) and not filter(f_esx)); };
Will try and do some packet captures to confirm Solaris is, in fact, sending the entire message (I believe it is since this worked on syslog-ng 2.x).
Thanks, Ray
______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.balabit.com/wiki/syslog-ng-faq
The lines are from the sniffer (I used the "copy text summary" function in Wireshark for the relevant packets). Will have to see if there's a more verbose view that isn't hex. :) On Tue, May 12, 2015 at 09:18:22PM +0200, Scheidler, Balázs wrote:
Hmm what was the sniffer that printed these lines? I would prefer to see what was in the wire exactly as these seem to have been processed somewhat.
On May 12, 2015 5:02 PM, "Ray Van Dolson" <rvandolson@esri.com> wrote:
On Tue, May 12, 2015 at 08:49:20AM +0200, Scheidler, Balázs wrote: > The most important thing with multiline is the transport. > > Udp can transmit multiline messages just as syslog(transport(tcp)) > but of course the client has to support the same protocol. > > What do you use on the solaris side?
Using the default syslog daemon in Solaris 10 (uses UDP).
> > If you haven't changed the client I don't see why the message would > be truncated like that. Once received syslog-ng would only replace > newlines with spaces. > > So I guess it is a transport issue on the sending side. But > tcpdump/wireshark should help a lot here.
Packet capture results leave me scratching my head a bit:
714 2015-05-12 03:41:06.172567 10.49.6.166 10.49.7.16 Syslog 150 KERN.WARNING: May 12 03:41:06 scsi: [ID 243001 kern.warning] WARNING: / pci@0,0/pci8086,3410@9/pci15d9,400@0 (mpt_sas0): 715 2015-05-12 03:41:06.172575 10.49.6.166 10.49.7.16 Syslog 127 KERN.WARNING: May 12 03:41:06 \tmptsas_handle_event_sync: IOCStatus=0x8000, IOCLogInfo=0x31110610
718 2015-05-12 03:41:10.172475 10.49.6.166 10.49.7.16 Syslog 138 KERN.INFO: May 12 03:41:10 scsi: [ID 365881 kern.info] /pci@0,0/ pci8086,3410@9/pci15d9,400@0 (mpt_sas0): 719 2015-05-12 03:41:10.172483 10.49.6.166 10.49.7.16 Syslog 105 KERN.INFO: May 12 03:41:10 \tLog info 0x31110610 received for target 24.
721 2015-05-12 03:41:10.172487 10.49.6.166 10.49.7.16 Syslog 142 KERN.WARNING: May 12 03:41:10 scsi: [ID 107833 kern.warning] WARNING: / scsi_vhci/disk@g5000c50019bc81e1 (sd31): 722 2015-05-12 03:41:10.172491 10.49.6.166 10.49.7.16 Syslog 110 KERN.WARNING: May 12 03:41:10 \tSCSI transport failed: reason 'reset': giving up
(Sorry for the word-wrap).
So, you can see the second line comes through as a completely separate message with a tab character '\t' at the beginning.
The odd thing? Packets 714 & 715 come through fine and syslog-ng appends them both to my output log.
However, for pairs 718 & 719 and 721 & 722, only the first line comes through. In both cases the tab character is 0x09 so not seeing a difference there.
Makes me think it's something in the syslog-ng config rather than the message. Probably will move to something super simple to see that fixes it (keeping in mind this behavior didn't occur w/ syslog-ng 2.x).
Ray
> > On May 12, 2015 05:43, "Ray Van Dolson" <rvandolson@esri.com> wrote: > > Admittedly haven't done enough searching or testing on this, but am > hoping someone might have a quick answer. > > Recently moved from the 2.x verions to 3.2.5 (as part of EPEL on > RHEL6). Have noticed that we're no longer getting the full messages > from some Solaris boxen using the tcp() and udp() source definitions. > > Messages like this: > > May 10 02:29:30 dev-zfs2 scsi: [ID 365881 kern.info] /pci@0,0/ > pci8086,3410@9/pci15d9,400@0 (mpt_sas0): > May 10 02:29:30 dev-zfs2 Log info 0x31080000 received for target 24. > May 10 02:29:30 dev-zfs2 scsi_status=0x0, ioc_status=0x804b, > scsi_state=0x0 > > Come through looking like this: > > May 10 02:29:30 dev-zfs2 scsi: [ID 365881 kern.info] /pci@0,0/ > pci8086,3410@9/pci15d9,400@0 (mpt_sas0): > > (Only the initial line) > > However, messages like this one: > > May 9 04:12:57 dev-zfs2 scsi: [ID 243001 kern.warning] WARNING: / pci@0,0/ > pci8086,3410@9/pci15d9,400@0 (mpt_sas0): > May 9 04:12:57 dev-zfs2 mptsas_handle_event_sync: IOCStatus= 0x8000, > IOCLogInfo=0x31110610 > > .. do seem to be coming through "whole" (I do note that the priority > is different in both). > > Relevant config items are as follows: > > log { > source(remote); > filter(syslog); > destination(hosts_syslog); > }; > > source remote { > udp(); > tcp(); > # udp(ip(0.0.0.0) port(514)); > # tcp(ip(0.0.0.0) port(514)); > }; > > destination hosts_syslog { > file("/logs/hosts/$HOST/$YEAR/$MONTH/ syslog.$HOST.$YEAR.$MONTH.log" > create_dirs(yes)); > pipe("/logs/hosts/everything.fifo"); > }; > > filter syslog { > (not facility(mail) > and not filter(f_ucgw) > and not filter(f_esx)); > }; > > Will try and do some packet captures to confirm Solaris is, in fact, > sending the entire message (I believe it is since this worked on > syslog-ng 2.x). > > Thanks, > Ray
participants (2)
-
Ray Van Dolson
-
Scheidler, Balázs