[opensuse-factory] logger only working with strace?
Hi all, this issue is so strange, that I'd first like to ask if someone else is also seeing this before filing a bug report :-) System: * pretty current FACTORY * running systemd * running rsyslogd Symptoms: * "logger foo" does nothing. No entry in /var/log/messages or anywhere * "strace logger foo" does work. * "echo foo > /dev/kmsg" also works as a workaround. anyone else seeing this? -- Stefan Seyfried "Dispatch war rocket Ajax to bring back his body!" -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org For additional commands, e-mail: opensuse-factory+help@opensuse.org
On 08/19/2011 02:11 PM, Stefan Seyfried wrote:
Hi all,
this issue is so strange, that I'd first like to ask if someone else is also seeing this before filing a bug report :-)
System: * pretty current FACTORY * running systemd * running rsyslogd
Symptoms: * "logger foo" does nothing. No entry in /var/log/messages or anywhere * "strace logger foo" does work. * "echo foo > /dev/kmsg" also works as a workaround.
anyone else seeing this? I did not try strace, but gave a quick test to syslog-ng (as I'm from syslog-ng upstream...). It's only slightly better: the first "logger bla" seems to come through, but no more additional logs until restart.
In another thread, when I asked about systemd and syslog-ng packaging, I
got this answer:
"Werner is working on a systemd-generator which should take care of
systemd .service generation at startup for syslog-ng.
I'd say, don't worry for systemd right now."
So I suppose, that if you need logging, you should change back to sysvinit for now...
Bye,
--
Peter Czanik (CzP)
Am Wed, 24 Aug 2011 09:34:51 +0200
schrieb Peter Czanik
On 08/19/2011 02:11 PM, Stefan Seyfried wrote:
Hi all,
this issue is so strange, that I'd first like to ask if someone else is also seeing this before filing a bug report :-)
System: * pretty current FACTORY * running systemd * running rsyslogd
Symptoms: * "logger foo" does nothing. No entry in /var/log/messages or anywhere * "strace logger foo" does work. * "echo foo > /dev/kmsg" also works as a workaround.
anyone else seeing this? I did not try strace, but gave a quick test to syslog-ng (as I'm from syslog-ng upstream...). It's only slightly better: the first "logger bla" seems to come through, but no more additional logs until restart.
Even with strace is is not totally reliable, but it seems to increase the chance of getting the message through.
In another thread, when I asked about systemd and syslog-ng packaging, I got this answer: "Werner is working on a systemd-generator which should take care of
systemd .service generation at startup for syslog-ng.
I'd say, don't worry for systemd right now."
So I suppose, that if you need logging, you should change back to sysvinit for now...
Well, for my scripts something like that works :-) logger() { echo $@ > /dev/kmsg } but is of course not a solution. The funny thing is that I did check with "fuser /dev/log" and then attached strace to all those processes (systemd (pid 1), systemd-kmsg-syslogd (pid 347) and rsyslogd (pid 1090), and though "strace logger foo" clearly shows that something was sent to the /dev/log socket, none of the 3 processes even got woken up. Maybe it is not even a systemd issue but something in the kernel? (FACTORY and Kernel-HEAD are pretty outdated, so maybe it's something already fixed upstream?) Thanks for checking, Stefan -- Stefan Seyfried "Dispatch war rocket Ajax to bring back his body!" -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org For additional commands, e-mail: opensuse-factory+help@opensuse.org
Maybe it is not even a systemd issue but something in the kernel? (FACTORY and Kernel-HEAD are pretty outdated, so maybe it's something already fixed upstream?) It's systemd, but with the syslog infrastructure changes it's getting better. Testing syslog-ng, as usual (and finally "zypper dup" does not reinstall rsyslog!), logging seems to work now even from systemd. It's not 100% perfect yet, as there seems to be some delay between "logger bla" and its actual appearance in logs. There is no such problem with
Hello, On 08/24/2011 11:46 AM, Stefan Seyfried wrote: traditional sysvinit. So it's time for some debugging :) Bye, CzP -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org For additional commands, e-mail: opensuse-factory+help@opensuse.org
On 08/25/2011 08:58 AM, Peter Czanik wrote:
Hello,
Maybe it is not even a systemd issue but something in the kernel? (FACTORY and Kernel-HEAD are pretty outdated, so maybe it's something already fixed upstream?) It's systemd, but with the syslog infrastructure changes it's getting better. Testing syslog-ng, as usual (and finally "zypper dup" does not reinstall rsyslog!), logging seems to work now even from systemd. It's not 100% perfect yet, as there seems to be some delay between "logger bla" and its actual appearance in logs. There is no such problem with
On 08/24/2011 11:46 AM, Stefan Seyfried wrote: traditional sysvinit. So it's time for some debugging :) Here it is. I added a few lines to my syslog-ng config:
destination d_debug { file("/var/log/czp" template("$S_DATE $R_DATE $MSG\n")); }; log { source(src); destination(d_debug); }; Which means, that logs are sent to /var/log/czp with a custom template, which consists of: sent date (the date, which is in the log message), received date (when it arrived to syslog-ng) and the message. And here are my logs. Lines, where the message starts with 'bla' are sent with logger in the following form: logger bla `date` When using tail -f on logs, it seemed to me, that logs are received only when a kernel message (like the one from firewall on ssh login) arrives. It only seems to be a problem with systemd. I'll check it with Fedora alpha, as that also has systemd and syslog-ng 3.2.4. Or just wait a few days, as syslog-ng 3.3 should arrive to factory in any minute... Aug 25 09:12:07 Aug 25 09:10:59 Accepted keyboard-interactive/pam for root from 172.16.105.1 port 52529 ssh2 Aug 25 09:12:07 Aug 25 09:12:07 [ 106.668118] SFW2-INext-ACC-TCP IN=eth0 OUT= MAC=00:0c:29:f5:0f:44:00:50:56:c0:00:08:08:00 SRC=172.16.105.1 DST=172.16.105.150 LEN=60 TOS=0x00 PREC=0x00 TTL=64 ID=11651 DF PROTO=TCP SPT=52529 DPT=22 WINDOW=4380 RES=0x00 SYN URGP=0 OPT (020405B40402080A007A22EA0000000001030306) Aug 25 09:12:07 Aug 25 09:12:07 pam_apparmor(sshd:session): Unknown error occurred changing to root hat: Operation not permitted Aug 25 09:12:07 Aug 25 09:12:07 New user root logged in. Aug 25 09:12:07 Aug 25 09:12:07 New session 1 of user root. Aug 25 09:12:07 Aug 25 09:12:07 [ warning] [guestinfo] Failed to get vmstats. Aug 25 09:12:26 Aug 25 09:12:07 bla Thu Aug 25 09:12:26 CEST 2011 Aug 25 09:12:33 Aug 25 09:12:07 Received disconnect from 172.16.105.1: 11: disconnected by user Aug 25 09:12:33 Aug 25 09:12:07 Removed session 1. Aug 25 09:12:36 Aug 25 09:12:07 Accepted keyboard-interactive/pam for root from 172.16.105.1 port 52530 ssh2 Aug 25 09:12:36 Aug 25 09:12:07 pam_apparmor(sshd:session): Unknown error occurred changing to root hat: Operation not permitted Aug 25 09:12:36 Aug 25 09:12:07 New session 2 of user root. Aug 25 09:12:36 Aug 25 09:12:36 [ 135.867570] SFW2-INext-ACC-TCP IN=eth0 OUT= MAC=00:0c:29:f5:0f:44:00:50:56:c0:00:08:08:00 SRC=172.16.105.1 DST=172.16.105.150 LEN=60 TOS=0x00 PREC=0x00 TTL=64 ID=23600 DF PROTO=TCP SPT=52530 DPT=22 WINDOW=4380 RES=0x00 SYN URGP=0 OPT (020405B40402080A007A952B0000000001030306) Aug 25 09:12:37 Aug 25 09:12:37 [ warning] [guestinfo] Failed to get vmstats. Aug 25 09:13:07 Aug 25 09:12:37 [ warning] [guestinfo] Failed to get vmstats. Aug 25 09:13:37 Aug 25 09:12:37 [ warning] [guestinfo] Failed to get vmstats. Aug 25 09:13:46 Aug 25 09:12:37 Started sntp Aug 25 09:13:52 Aug 25 09:12:37 Started sntp Aug 25 09:13:58 Aug 25 09:12:37 bla Thu Aug 25 09:13:58 CEST 2011 Aug 25 09:14:07 Aug 25 09:12:37 [ warning] [guestinfo] Failed to get vmstats. Aug 25 09:14:37 Aug 25 09:12:37 [ warning] [guestinfo] Failed to get vmstats. Aug 25 09:15:07 Aug 25 09:12:37 [ warning] [guestinfo] Failed to get vmstats. Aug 25 09:15:15 Aug 25 09:12:37 Accepted keyboard-interactive/pam for root from 172.16.105.1 port 40524 ssh2 Aug 25 09:15:15 Aug 25 09:15:15 [ 294.663452] SFW2-INext-ACC-TCP IN=eth0 OUT= MAC=00:0c:29:f5:0f:44:00:50:56:c0:00:08:08:00 SRC=172.16.105.1 DST=172.16.105.150 LEN=60 TOS=0x00 PREC=0x00 TTL=64 ID=47574 DF PROTO=TCP SPT=40524 DPT=22 WINDOW=4380 RES=0x00 SYN URGP=0 OPT (020405B40402080A007D028A0000000001030306) Bye, CzP -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org For additional commands, e-mail: opensuse-factory+help@opensuse.org
Hello, On 08/25/2011 09:45 AM, Peter Czanik wrote:
And here are my logs. Lines, where the message starts with 'bla' are sent with logger in the following form: logger bla `date` When using tail -f on logs, it seemed to me, that logs are received only when a kernel message (like the one from firewall on ssh login) arrives. It only seems to be a problem with systemd. I'll check it with Fedora alpha, as that also has systemd and syslog-ng 3.2.4. Or just wait a few days, as syslog-ng 3.3 should arrive to factory in any minute...
Just tested, rsyslog seems to work correctly with systemd. And our git tree ( http://git.balabit.hu/?p=bazsi/syslog-ng-3.2.git;a=summary ) has some systemd related patches, which were committed after the syslog-ng 3.2.4 release. As syslog-ng 3.3 sources are already in factory and have these patches, I'll come back to this question once the 3.3 binary is available. Bye, CzP -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org For additional commands, e-mail: opensuse-factory+help@opensuse.org
Hello, On 08/25/2011 10:34 AM, Peter Czanik wrote: > On 08/25/2011 09:45 AM, Peter Czanik wrote: >> And here are my logs. Lines, where the message starts with 'bla' are >> sent with logger in the following form: logger bla `date` When using >> tail -f on logs, it seemed to me, that logs are received only when a >> kernel message (like the one from firewall on ssh login) arrives. It >> only seems to be a problem with systemd. I'll check it with Fedora >> alpha, as that also has systemd and syslog-ng 3.2.4. Or just wait a few >> days, as syslog-ng 3.3 should arrive to factory in any minute... > Just tested, rsyslog seems to work correctly with systemd. And our git > tree ( http://git.balabit.hu/?p=bazsi/syslog-ng-3.2.git;a=summary ) has > some systemd related patches, which were committed after the syslog-ng > 3.2.4 release. As syslog-ng 3.3 sources are already in factory and have > these patches, I'll come back to this question once the 3.3 binary is > available. OK, it arrived to factory this morning, so I could test it. Logging with syslog-ng works now as epxected. I still ran into a couple of systemd related issues, which I still need to test a bit more before reporting to bugzilla: - changing from rsyslog to syslog-ng or back seems to work only after a reboot - when editing syslog-ng.conf and making a mistake, the error message is not printed on screen on "rcsyslog restart" making it difficult to find the problem or even to find that there is a problem... Neither of these problems appear with good old-fashioned sysvinit... Bye, CzP -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org For additional commands, e-mail: opensuse-factory+help@opensuse.org
On Fri, Aug 26, 2011 at 11:48:14AM +0200, Peter Czanik wrote:
> Hello,
>
> On 08/25/2011 10:34 AM, Peter Czanik wrote:
> > On 08/25/2011 09:45 AM, Peter Czanik wrote:
> >> And here are my logs. Lines, where the message starts with 'bla' are
> >> sent with logger in the following form: logger bla `date` When using
> >> tail -f on logs, it seemed to me, that logs are received only when a
> >> kernel message (like the one from firewall on ssh login) arrives. It
> >> only seems to be a problem with systemd. I'll check it with Fedora
> >> alpha, as that also has systemd and syslog-ng 3.2.4. Or just wait a few
> >> days, as syslog-ng 3.3 should arrive to factory in any minute...
> > Just tested, rsyslog seems to work correctly with systemd. And our git
> > tree ( http://git.balabit.hu/?p=bazsi/syslog-ng-3.2.git;a=summary ) has
> > some systemd related patches, which were committed after the syslog-ng
> > 3.2.4 release. As syslog-ng 3.3 sources are already in factory and have
> > these patches, I'll come back to this question once the 3.3 binary is
> > available.
> OK, it arrived to factory this morning, so I could test it. Logging with
> syslog-ng works now as epxected. I still ran into a couple of systemd
> related issues, which I still need to test a bit more before reporting
> to bugzilla:
> - changing from rsyslog to syslog-ng or back seems to work only after a
> reboot
systemctl stop syslog.service
systemctl --system daemon-reload
systemctl start syslog.service
> - when editing syslog-ng.conf and making a mistake, the error message is
> not printed on screen on "rcsyslog restart" making it difficult to find
> the problem or even to find that there is a problem...
This is a problem of how to use error logs in systemd, you may try
DefaultStandardOutput=syslog+console
DefaultStandardError=syslog+console
in /etc/systemd/system.conf (it's not a bug but a feature)
> Neither of these problems appear with good old-fashioned sysvinit...
that is an other story :/
--
Dr. Werner Fink -- Software Engineer Consultant
SuSE LINUX Products GmbH, Maxfeldstrasse 5, Nuernberg, Germany
GF: Jeff Hawn, Jennifer Guild, Felix Imendörffer, HRB 21284 (AG Nuernberg)
phone: +49-911-740-53-0, fax: +49-911-3206727, www.opensuse.org
------------------------------------------------------------------
"Having a smoking section in a restaurant is like having
a peeing section in a swimming pool." -- Edward Burr
--
To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org
For additional commands, e-mail: opensuse-factory+help@opensuse.org
participants (3)
-
Dr. Werner Fink -
Peter Czanik -
Stefan Seyfried