https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c0
Summary: Bogus systemd log message regarding sendmail Classification: openSUSE Product: openSUSE 12.1 Version: Final Platform: x86-64 OS/Version: SuSE Other Status: NEW Severity: Minor Priority: P5 - None Component: Basesystem AssignedTo: bnc-team-screening@forge.provo.novell.com ReportedBy: nrickert@ameritech.net QAContact: qa@suse.de Found By: --- Blocker: ---
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:8.0) Gecko/20100101 Firefox/8.0
(note: the operating system selector for reports needs an entry for 12.1)
When looking through /var/log/messages (researching unrelated bug 732910), I noticed some bogus lines relating to "sendmail".
Nov 26 23:52:19 nwr2 echo[4075]: Initializing SMTP port (sendmail) .. Nov 26 23:52:19 nwr2 systemd[1]: Failed to read PID file /var/run/sendmail.pid a fter start. The service might be broken. .. Nov 26 23:52:36 nwr2 systemd[1]: Failed to read PID file /var/spool/clientmqueue/sm-client.pid after start. The service might be broken.
In fact, sendmail is running fine, and the two "pid" files exist: -rw------- 1 root mail 54 Nov 26 23:52 /var/run/sendmail.pid -rw------- 1 mail mail 53 Nov 26 23:52 /var/spool/clientmqueue/sm-client.pid
This might be a timing issue. Perhaps systemd is checking for the existence of the files a few milliseconds too early.
It would be better to not have those log messages at all, than to have them when they are wrong.
I see those messages on every boot.
The system uses AMD Athlon(tm) 64 X2 Dual Core Processor 4000+ in case that is relevant (the dual core might be relevant)
Reproducible: Always
Steps to Reproduce: 1. 2. 3.
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c1
Cristian Rodríguez crrodriguez@opensuse.org changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |crrodriguez@opensuse.org AssignedTo|bnc-team-screening@forge.pr |fcrozat@suse.com |ovo.novell.com | Severity|Minor |Normal
--- Comment #1 from Cristian Rodríguez crrodriguez@opensuse.org 2011-11-29 14:17:53 CLST --- Im seeing this as well.
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c2
--- Comment #2 from Frederic Crozat fcrozat@suse.com 2011-11-29 18:05:28 UTC --- Does sendmail uses an initscript or a systemd .service file ?
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c3
--- Comment #3 from Neil Rickert nrickert@ameritech.net 2011-11-29 20:23:41 UTC ---
Does sendmail uses an initscript or a systemd .service file ?
There's certainly an initscript. I'm not sure where to look for ".service" files.
Directory "/lib/systemd/system" contains:
-rw-r--r-- 1 root root 510 Oct 29 14:59 sendmail-client.path -rw-r--r-- 1 root root 849 Oct 29 14:59 sendmail-client.service -rw-r--r-- 1 root root 1402 Oct 29 14:59 sendmail.service
I would guess that means it is using a ".service" file. There are symlinks to these from files in "/etc/systemd/system/multi-user.target.wants".
I guess I will eventually get the hang of how systemd does things.
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c4
Frederic Crozat fcrozat@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- AssignedTo|fcrozat@suse.com |werner@suse.com
--- Comment #4 from Frederic Crozat fcrozat@suse.com 2011-11-30 09:03:06 UTC --- if you want to better understand systemd, I suggest reading http://www.freedesktop.org/wiki/Software/systemd (the part called systemd for administrators)
So, sendmail is shipping with systemd .service, which means initscript are not used at all (and it looks like it doesn't follow the systemd packaging guidelines too cf http://en.opensuse.org/openSUSE:Systemd_packaging_guidelines )
reassigning to werner, since he wrote the systemd service file.
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c5
Dr. Werner Fink werner@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |NEEDINFO CC| |fcrozat@suse.com InfoProvider| |fcrozat@suse.com
--- Comment #5 from Dr. Werner Fink werner@suse.com 2011-11-30 09:40:29 UTC --- Last time I've tested (Aug 12) it has worked well ... the question rises if the interface of systemd has changed in the mean while?
Don't know how old this guidelines are. As I'm was busy with SLES11-SP2 it could be that I've missed this. Nevertheless it should work after using systemctl by the system admin.
Beside this missing rpm spec macros and as I'm using systemctl in the direct way I'd like to know why systemd is reporting this error about a missing /var/run/sendmail.pid?
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c6
Frederic Crozat fcrozat@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEEDINFO |NEW InfoProvider|fcrozat@suse.com |
--- Comment #6 from Frederic Crozat fcrozat@suse.com 2011-11-30 10:46:48 UTC --- I'm not aware of interface change regarding PID file
however, looking at systemd git, it looks like this warning was maybe a little too sensitive ( https://bugzilla.redhat.com/show_bug.cgi?id=752396 )
Could you test package from home:fcrozat:systemd / systemd where I've added upstream patch which should improve the situation ?
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c7
Dr. Werner Fink werner@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |NEEDINFO InfoProvider| |nrickert@ameritech.net
--- Comment #7 from Dr. Werner Fink werner@suse.com 2011-11-30 10:58:33 UTC --- Neil? Cristian?
Simply have look at
http://download.opensuse.org/repositories/home:/fcrozat:/systemd/openSUSE_12...
but be aware this could be bleeding-edge :)
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c8
--- Comment #8 from Frederic Crozat fcrozat@suse.com 2011-11-30 11:48:36 UTC --- don't worry, it is not, just some fixes pending for 12.1 maintenance update ;)
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c9
Neil Rickert nrickert@ameritech.net changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEEDINFO |NEW InfoProvider|nrickert@ameritech.net |
--- Comment #9 from Neil Rickert nrickert@ameritech.net 2011-11-30 14:51:18 UTC --- By the way, thanks for that reference to systemd documentation. Appreciated.
I installed your package on my test system.
I then rebooted.
The bogus message is still there. I guess that doesn't solve the problem.
The comment in the redhat bugzilla is as bit cryptic, but on my reading it does not seem to apply. That seemed to be, at least in part, about service shutdown.
Sendmail does not drop privileges. The daemon, which creates the pidfile, sits there with full privileges. On an incoming connection, it may drop privileges in the child process after fork(), but that would not affect the pidfile. The sendmail client daemon runs with lower privileges, but its pidfile is where it does have sufficient privileges to create or remove that file.
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c10
Dr. Werner Fink werner@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |NEEDINFO InfoProvider| |fcrozat@suse.com
--- Comment #10 from Dr. Werner Fink werner@suse.com 2011-11-30 15:42:23 UTC --- Maybe we see a race condition that is that the pid file will be created *after* systemd checks for it ... is there a way simply to wait on the pid file?
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c11
--- Comment #11 from Dr. Werner Fink werner@suse.com 2011-11-30 15:59:31 UTC --- The service part is:
[Service] Type=forking PIDFile=/var/run/sendmail.pid ExecStartPre=-/bin/echo 'Initializing SMTP port (sendmail)' ExecStartPre=-/etc/mail/system/sm.pre Environment=SENDMAIL_ARGS=-L sendmail -Am -bd -q30m -om Environment=SENDMAIL_PORT_OPTS= EnvironmentFile=-/etc/sysconfig/mail EnvironmentFile=-/etc/sysconfig/sendmail EnvironmentFile=-/var/run/sendmail/port ExecStart=/usr/sbin/sendmail $SENDMAIL_PORT_OPTS $SENDMAIL_ARGS
.. and it is type forking. Beside this wihthout a connection three procresses are running
ps ax | grep sendmail
17395 ? Ss 1:39 sendmail: accepting connections 17401 ? Ss 0:00 sendmail: Queue control 17402 ? S 2:27 sendmail: running queue: /var/spool/clientmqueue 27775 pts/2 S+ 0:00 grep sendmail
ps auxc | grep sendmail
root 17395 0.0 0.0 11504 772 ? Ss Sep20 1:39 sendmail mail 17401 0.0 0.0 7588 420 ? Ss Sep20 0:00 sendmail mail 17402 0.0 0.0 26780 1504 ? S Sep20 2:27 sendmail
the pid file /var/run/sendmail.pid belongs to 17395 here:
sudo cat /var/run/sendmail.pid
17395 /usr/sbin/sendmail -L sendmail -Am -bd -q30m -om
we have either a race or systemd can not handle a simply pid file if more that one process us running (and both looks more like a bug of systemd).
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c12
--- Comment #12 from Neil Rickert nrickert@ameritech.net 2011-11-30 16:19:29 UTC --- I'm not sure what or who that "NEEDINFO" is for.
I agree that this is likely a race situation, with the pidfile being checked before it is created. My personal opinion would be that the pidfile checking should be turned off for sendmail, assuming that is possible.
Here's a little background on those sendmail processes:
"sendmail" should be started twice, presumably by systemd. It is started with different command line arguments on the two occasions.
Process 17395 in that listing is the main sendmail process that creates the pid file in "/var/run" and handles all incoming mail.
Process 17401 is a client queue manager to handle local command line email with less than root privileges. It queues mail in "/var/spool/clientmqueue" and it creates a separate pid file in that "clientmqueue" directory. It typically uses "/etc/mail/submit.cf" as its configuration file. And the default configuration is for it to start a persistent queue running, which is process 17402. If the persistent queue runner dies, then the queue control daemon (process 17401) will restart it.
In particular, the three processes that you are seeing are normal and do not indicate a problem with the systemd startup.
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c13
--- Comment #13 from Dr. Werner Fink werner@suse.com 2011-11-30 16:26:53 UTC --- I'm aware ... not only as maintainer of the sendmail package but also as user/admin of sendmail now more than 15 years ;) The listing from above was from taken from my workstation, nevertheless at home my systems also use sendmail (and currently sysvinit 8)
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c14
Frederic Crozat fcrozat@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEEDINFO |NEW InfoProvider|fcrozat@suse.com |
--- Comment #14 from Frederic Crozat fcrozat@suse.com 2011-11-30 16:35:28 UTC --- according to systemd upstream, sendmail daemonize is racy :
https://bugzilla.redhat.com/show_bug.cgi?id=748171
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c15
Dr. Werner Fink werner@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |NEEDINFO InfoProvider| |fcrozat@suse.com
--- Comment #15 from Dr. Werner Fink werner@suse.com 2011-11-30 16:42:17 UTC --- Hmmm ... why is systemd not able to wait on the pids
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c16
Frederic Crozat fcrozat@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEEDINFO |NEW InfoProvider|fcrozat@suse.com |
--- Comment #16 from Frederic Crozat fcrozat@suse.com 2011-11-30 16:50:44 UTC --- I can't comment on that (see http://0pointer.de/public/systemd-man/daemon.html and probably some articles from Lennart on the way systemd handles daemon)
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c17
Dr. Werner Fink werner@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |NEEDINFO InfoProvider| |fcrozat@suse.com
--- Comment #17 from Dr. Werner Fink werner@suse.com 2011-11-30 17:01:27 UTC --- .. reading leads to the point
12 In the daemon process, write the daemon PID (as returned by getpid()) to a PID file, for example /var/run/foobar.pid (for a hypothetical daemon "foobar"), to ensure that the daemon cannot be started more than once. This must be implemented in race-free fashion so that the PID file is only updated when at the same time it is verified that the PID previously stored in the PID file no longer exists or belongs to a foreign process. Commonly some kind of file locking is employed to implement this logic.
.. IMHO it is race free as sendmail creates its pids only if all is OK (configuration, network, ..) and running. It is upto systemd to handle this, e.g. by a timeout or similar or will systemd upstream really will cause sendmail and other daemons to be rewritten due the new systemd isn't able to handle timeouts in a clear way?
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c18
Cristian Rodríguez crrodriguez@opensuse.org changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEEDINFO |NEW InfoProvider|fcrozat@suse.com |
--- Comment #18 from Cristian Rodríguez crrodriguez@opensuse.org 2011-11-30 14:09:08 CLST --- If you want to reproduce the issue with a more simple program, try unscd from current factory, exactly the same messages and problem.
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c19
--- Comment #19 from Frederic Crozat fcrozat@suse.com 2011-11-30 17:09:52 UTC --- I suggest you raise this point on systemd upstream mailing list (or bugzilla), since you are much more knowledgable than me on this topic.
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c20
Dr. Werner Fink werner@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |NEEDINFO InfoProvider| |fcrozat@suse.com
--- Comment #20 from Dr. Werner Fink werner@suse.com 2011-11-30 17:11:35 UTC --- Btw: for sendmail client service unit I'm waiting on port 25 with the help of the shell script /etc/mail/system/sm-client.pre ..see sendmail-client.service:
[Service] Type=forking PIDFile=/var/spool/clientmqueue/sm-client.pid ExecStartPre=-/etc/mail/system/sm-client.pre Environment=SENDMAIL_CLIENT_ARGS=-L sendmail-client -Ac -qp30m EnvironmentFile=-/etc/sysconfig/mail EnvironmentFile=-/etc/sysconfig/sendmail ExecStart=/usr/sbin/sendmail $SENDMAIL_CLIENT_ARGS
.. it could be an option if systemd would provide a similar feature that is wait on the existence of a port or ports
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c21
--- Comment #21 from Neil Rickert nrickert@ameritech.net 2011-11-30 20:30:35 UTC --- A general comment:
I don't agree that sendmail is racy. The interaction between sendmail and systemd is racy.
Having been part of the sendmail volunteer team, I think the RH people are correct that a patch would not be accepted for this.
The whole point of such a patch would be to make systemd reporting more reliable at the cost of reducing the reliability of sendmail itself. At present, the pidfile is written by the running daemon when it is up and ready. The proposed patch would require that the pidfile be written by its parent process, based only on the hope that it will work out.
As for what to do at opensuse? It's not my call, but I would not have any problem with setting it as WONTFIX. It's only a cosmetic problem anyway. And there are plenty of other log messages that we learn to ignore.
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c22
--- Comment #22 from Dr. Werner Fink werner@suse.com 2011-12-01 07:56:50 UTC --- IMHO this bug belongs to systemd ... but ... let me guess: upstream of systemd may not see this as their onw bug but will close such a bug with more political motivation than technical rationale
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c23
Frederic Crozat fcrozat@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEEDINFO |NEW InfoProvider|fcrozat@suse.com |
--- Comment #23 from Frederic Crozat fcrozat@suse.com 2011-12-05 12:31:23 UTC --- please test package in home:fcrozat:systemd / systemd, systemd folk apparently fixed systemd to correctly handle sendmail (and other similar daemon) without complaining anymore and I've included their patches.
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c24
--- Comment #24 from Cristian Rodríguez crrodriguez@opensuse.org 2011-12-05 12:57:04 CLST --- (In reply to comment #23)
please test package in home:fcrozat:systemd / systemd, systemd folk apparently fixed systemd to correctly handle sendmail (and other similar daemon) without complaining anymore and I've included their patches.
That worked for my case, thanks :-D
Wow, looking at the changeset, this systemd stuff is even more clever than I thought ;)
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c25
--- Comment #25 from Neil Rickert nrickert@ameritech.net 2011-12-06 00:39:00 UTC ---
please test package in home:fcrozat:systemd / systemd
That works in my testing, too. Thanks.
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c26
Frederic Crozat fcrozat@suse.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |NEEDINFO InfoProvider| |maintenance@opensuse.org
--- Comment #26 from Frederic Crozat fcrozat@suse.com 2011-12-09 14:41:54 UTC --- sr 96122 pushed to openSUSE:12.1:Update:Test requesting maintenance update for 12.1
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c27
--- Comment #27 from Bernhard Wiedemann bwiedemann@suse.com 2011-12-09 16:01:04 CET --- This is an autogenerated message for OBS integration: This bug (732912) was mentioned in https://build.opensuse.org/request/show/96122 12.1 / systemd https://build.opensuse.org/request/show/96125 Factory / systemd
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c28
--- Comment #28 from Bernhard Wiedemann bwiedemann@suse.com 2011-12-09 19:01:01 CET --- This is an autogenerated message for OBS integration: This bug (732912) was mentioned in https://build.opensuse.org/request/show/96193 Factory / systemd
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c29
--- Comment #29 from Bernhard Wiedemann bwiedemann@suse.com 2011-12-12 18:01:11 CET --- This is an autogenerated message for OBS integration: This bug (732912) was mentioned in https://build.opensuse.org/request/show/96377 12.1 / systemd
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c31
Cristian Rodríguez crrodriguez@opensuse.org changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |RESOLVED Resolution| |FIXED
--- Comment #31 from Cristian Rodríguez crrodriguez@opensuse.org 2011-12-15 16:47:40 CLST --- This bug has been already fixed...
https://bugzilla.novell.com/show_bug.cgi?id=732912
https://bugzilla.novell.com/show_bug.cgi?id=732912#c32
--- Comment #32 from Frederic Crozat fcrozat@suse.com 2012-01-04 09:25:56 UTC --- Maintenance update has been released for 12.1
-
bugzilla_noreply＠novell.com