[ClusterLabs] "After = syslog.service" it is not working?

[Ken Gaillot]

On 02/08/2016 12:20 AM, 飯田 雄介 wrote:
> Hi, Ken
> 
> Log sent last time, it was acquired in an environment that has been set so as to output the syslog to a file called ha-log.
> Because I think that this in hard to understand, we again get the log in a more set close to default.
> I have collected the two types of log.
> Each attachment was, including those of the following other.
> /etc/rsyslog.conf
> /usr/lib/systemd/system/pacemaker.service
> /usr/lib/systemd/system/corosync.service
> /usr/lib/systemd/system/rsyslog.service
> 
> after-syslog.tar.bz2 is that to get the information in a set of "After = syslog.service".
> 
> - Time that rsyslog has stopped (from rhel72-7 / messages)
> Feb 8 14:24:54 rhel72-7 rsyslogd: [origin software = "rsyslogd" swVersion = "7.4.7" x-pid = "769" x-info = "http://www.rsyslog.com"] exiting on signal 15.
> 
> - Time that Pacemaker is stopped (from rhel72-7 / pacemaker.log)
> Feb 08 14:24:56 [8235] rhel72-7 pacemakerd: notice: pcmk_shutdown_worker: Shutdown complete
> 
> From the above, Pacemaker will find that it has been stopped after a halt on rsyslog.
> 
> after-rsyslog.tar.bz2 is that to get the information to change the setting of "After = rsyslog.service".
> 
> - Time that Pacemaker is stopped (from rhel72-7 / messages)
> Feb 8 14:44:52 rhel72-7 pacemakerd [18528]: notice: Shutdown complete
> 
> - Time that rsyslog has stopped (from rhel72-7 / messages)
> Feb 8 14:44:52 rhel72-7 rsyslogd: [origin software = "rsyslogd" swVersion = "7.4.7" x-pid = "768" x-info = "http://www.rsyslog.com"] exiting on signal 15.
> 
> From the above, rsyslog will find that it has been stopped after the Pacemaker.
> 
> Is this information will help you understand?
> 
> Regards, Yusuke

Hi Yusuke,

Systemd wants all syslog implementations to use Requires=syslog.socket
and Alias=syslog.service:
https://www.freedesktop.org/wiki/Software/systemd/syslog/

But rsyslog prefers to do things differently, so those are commented out
in its rsyslog.service unit file:
http://lists.adiscon.net/pipermail/rsyslog/2015-March/039885.html

Mr. Systemd himself commented on a similar issue in
https://bugzilla.redhat.com/show_bug.cgi?id=766103#c13 : "I figure this
is a problem of the past as rsyslog will read shutdown messages (and
early-boot messages) from systemd's buffer on next reboot."

And the rsyslog folks seem to agree:
http://lists.adiscon.net/pipermail/rsyslog/2015-March/039888.html

So it may be that the rsyslog will print the later messages on the next
boot, or it may be possible to see them using journald instead of
looking in rsyslog's text logs.

Since the syslog.service alias exists for the purpose of abstracting the
specific syslog implementation from other software, it *should* be
sufficient for Pacemaker to order after it, but here we see rsyslog
doesn't use it. I suppose we could order after both syslog.service and
rsyslog.service; I don't think that would hurt.

>> -----Original Message-----
>> From: Ken Gaillot [mailto:kgaillot at redhat.com]
>> Sent: Saturday, February 06, 2016 7:32 AM
>> To: 飯田 雄介; 'Cluster Labs - All topics related to open-source clustering
>> welcomed'
>> Cc: 島崎 勝美
>> Subject: Re: [ClusterLabs] "After = syslog.service" it is not working?
>>
>> On 01/28/2016 10:27 PM, 飯田 雄介 wrote:
>>> Hi, Ken
>>>
>>> I have to get the log.
>>> shutdown the -r now ran to "03:00:22".
>>> rsyslog also "03:00:22" to receive a TERM appears to have stopped.
>>>
>>> Regards, Yusuke
>>
>> Hello Yusuke,
>>
>> I see in your logs that /var/log/messages does not have any messages at all
>> from pacemaker (not only at shutdown).
>>
>> Meanwhile, pacemaker.log does have messages, including from shutdown.
>> The cluster writes directly to this file, without going through rsyslog.
>>
>> Both logs end at 03:00:22. I'm guessing that systemd waited until pacemaker
>> exited, then stopped rsyslog. I don't think they're exiting at the same time
>> (or that rsyslog exited before pacemaker).
>>
>> Instead, I suspect that either pacemaker is configured not to log via syslog,
>> or rsyslog is configured not to send pacemaker logs to /var/log/messages.
>>
>> Check the value of PCMK_logfacility and PCMK_logpriority in your
>> /etc/sysconfig/pacemaker. By default, pacemaker will log via syslog, but if
>> these are explicitly set, they might be turning that off.
>>
>> Also, pacemaker will try to inherit log options from corosync, so check
>> /etc/corosync/corosync.conf for logging options, especially to_syslog and
>> syslog_facility.
>>
>> If that isn't an issue, then I would check /etc/rsyslog.conf and
>> /etc/rsyslog.d/* to see if they do anything nonstandard.
>>
>>>> -----Original Message-----
>>>> From: Ken Gaillot [mailto:kgaillot at redhat.com]
>>>> Sent: Friday, January 29, 2016 12:16 AM
>>>> To: users at clusterlabs.org
>>>> Subject: Re: [ClusterLabs] "After = syslog.service" it is not working?
>>>>
>>>> On 01/28/2016 12:48 AM, 飯田 雄介 wrote:
>>>>> Hi, All
>>>>>
>>>>> I am building a cluster in the following environments.
>>>>> RHEL7.2
>>>>> Pacemaker-1.1.14
>>>>>
>>>>> The OS while it is running the Pacemaker was allowed to shutdown.
>>>>> Logs at this time Pacemaker in the stop was not output to the syslog.
>>>>>
>>>>> This "After = syslog.service" does not work is set to start-up
>>>>> script, it
>>>> seems pacemaker and rsyslog is stopped at the same time.
>>>>>
>>>>> Because I think it's rsyslog.service In RHEL7, whether this setting
>>>>> should
>>>> not be the "After = rsyslog.service"?
>>>>>
>>>>> Regards, Yusuke
>>>>
>>>> The "After = syslog.service" line neither helps nor hurts, and we
>>>> should just take it out.
>>>>
>>>> For a long time (and certainly in RHEL 7's systemd version 219),
>>>> systemd automatically orders the system log to start before and stop
>>>> after other services, so I don't think that's the cause of your problem.
>>>>
>>>> I'm not sure what would cause that behavior; can you post the
>>>> messages that are logged once shutdown is initiated?