Bug 1309764

This is due to _plutorun not being used with systemd (which printed the "subsystem" line). the pluto daemon itself prints "Starting Pluto", so the barf command should grep for that instead to match either case.

A fix was pushed upstream. It would come into 7.3 via a rebase.

Hi Paul,

unfortunately, this bug is not fixed. It does not show last ipsec's log only. Switching it to assigned state. 


You added journalctl command to show last ipsec's log in ipsec barf command.

journalctl -u ipsec.service --since '1 hour ago'

This command shows all ipsec's logs newer then one hour, but you want to show only last ipsec's log. If ipsec runs longer than one hour, journalctl does not show all log. If ipsec runs less then one hour and there was at least one previous ipsec's run, journalctl shows more then last log.

There is another issue with journalctl. journalctl has a default pager, so if the log is longer then one page, default pager is run and you can not see what ipsec barf printed before. You have to use --no-pager option to avoid journalctl's pager.

You can use this command to show last ipsec's log. I know it is not elegant, but it illustrates what I mean.

last_ipsec_run="$(date -d "$(grep 'Starting Internet Key Exchange (IKE) Protocol Daemon for IPsec...' /var/log/messages | tail -n 1 | cut -d ' ' -f 1,2,3)" '+%Y-%m-%d %H:%M:%S')"
journalctl --unit ipsec.service --no-page --since "$last_ipsec_run"

I see, there is a fallback on systems where journalctl does not exist or it is not executable. It uses sed. This fallback does not seem be fixed too. It shows much more information than journalctl version.

There can be arbitrary many logs in the system for ipsec. We cannot just go back and list all the logs. the "barf" command is meant to run as a test tool for enduers to give the developers a snapshot of the system and what happened.

If you want all the logs, you should configure logfile=/some/pluto.log instead and barf won't do the log part, or you can run journalctl manually and decide how far you want to look back.

if systemd adds an option to journalctl to show "logs since start of service" then we can change this behaviour to use that. but the man page of journalctl did not show me that option.

(In reply to Paul Wouters from comment #4)
> There can be arbitrary many logs in the system for ipsec. We cannot just go
> back and list all the logs. the "barf" command is meant to run as a test
> tool for enduers to give the developers a snapshot of the system and what
> happened.

Understand, but I reported this ticket, because ipsec barf on rhel-7 does not show logs for last ipsec run as it shows on rhel-6. In current release, it still does not show logs for the last ipsec run, so for me, this bug is not fixed. If you think it is not a bug, we can close the ticket, without that, I can not verify this bug, because reported issue is not fixed.
 
> If you want all the logs, you should configure logfile=/some/pluto.log
> instead and barf won't do the log part, or you can run journalctl manually
> and decide how far you want to look back.

I want ipsec barf to work as it works on rhel-6.

> if systemd adds an option to journalctl to show "logs since start of
> service" then we can change this behaviour to use that. but the man page of
> journalctl did not show me that option.

No, journalctl does not have this option, but I gave you a workaround how to find out the time when last ipsec has started.

last_ipsec_run="$(date -d "$(grep 'Starting Internet Key Exchange (IKE) Protocol Daemon for IPsec...' /var/log/messages | tail -n 1 | cut -d ' ' -f 1,2,3)" '+%Y-%m-%d %H:%M:%S')"

Then you can use this datetime in journalctl.

journalctl --unit ipsec.service --no-page --since "$last_ipsec_run"

Whether or not you will decide use this, you have to add, at least, --no-page option, because without that journalctl starts pager and pager removes all previous ipsec barf output. It's stupid, but it's sytstemd :-(. You can test it yourself with ipsec logs longer than one page.

Why are you assuming /var/log/messages exists on systemd systems? I think that is only true if someone installed rsyslog along with systemd.

ipsec barf shows for me near the end:

+ dmesg
+ egrep -i 'klips|ipsec'
[89888.010280] IPv4 over IPsec tunneling driver
+ _________________________ plog
+ test -x /usr/bin/journalctl
+ journalctl -u ipsec.service --since '1 hour ago'
-- Logs begin at Mon 2016-08-01 15:44:00 EDT, end at Thu 2016-08-04 11:31:06 EDT. --
+ _________________________ date
+ date
Thu Aug  4 11:32:51 EDT 2016

which seems to match journalctl -u ipsec.service --since '1 hour ago'

# journalctl --unit ipsec.service  --since '1 hour ago'
-- Logs begin at Mon 2016-08-01 15:44:00 EDT, end at Thu 2016-08-04 11:31:06 EDT. --

It shows no logs because I have logfile= set. When I unset that, syslog is used. It shows a lot of data and "ipsec barf" ends on the journalctl pager. But redirecting with "ipsec barf > out" works properly and all logs show up in the file including all the parts before the journalctl command is issued:

head -10 out

root@bofh7:/var/www/cgi-bin# head -10 out
bofh7.nohats.ca
Thu Aug  4 11:35:32 EDT 2016
+ _________________________ version
+ ipsec --version
Linux Libreswan 3.15 (netkey) on 3.10.0-327.22.2.el7.x86_64
+ _________________________ /proc/version
+ cat /proc/version
Linux version 3.10.0-327.22.2.el7.x86_64 (builder.centos.org) (gcc version 4.8.3 20140911 (Red Hat 4.8.3-9) (GCC) ) #1 SMP Thu Jun 23 17:05:11 UTC 2016
+ _________________________ /proc/net/ipsec_eroute
+ test -r /proc/net/ipsec_eroute


So I cannot reproduce your problem, and I think we cannot add any code that relies on /var/log/messages being present. I think a bug/feature request can be send to systemd to ask for "all logs since last service start", however that would also not be ideal to use, for instance if the pluto daemon crashes, and you want to send us a bunch of debug logs, you would want it to cover before the crash as well, so I believe saying "the last hour" is better.

(In reply to Paul Wouters from comment #6)
> Why are you assuming /var/log/messages exists on systemd systems? I think
> that is only true if someone installed rsyslog along with systemd.

Good point. You are right.

> It shows a lot of data and "ipsec barf" ends on the journalctl pager.
> But redirecting with "ipsec barf > out" works properly and all logs show up
> in the file including all the parts before the journalctl command is issued:

Run pager inside program is stupid and it's against unix philosophy. It's up to users whether or not they use | and less/more. I know, I can redirect all output into the file or use '| less' and journalctl detects it, but I do not see any reason why restrict users to print _all_ ipsec barf output on the console if they want.

> So I cannot reproduce your problem, and I think we cannot add any code that
> relies on /var/log/messages being present. I think a bug/feature request can
> be send to systemd to ask for "all logs since last service start", however
> that would also not be ideal to use, for instance if the pluto daemon
> crashes, and you want to send us a bunch of debug logs, you would want it to
> cover before the crash as well, so I believe saying "the last hour" is
> better.

Ok. I agree with change ipsec barf's output. What you wrote makes sense, but I have to insist on '--no-pager' option.

Two notes:

1,

It would be fine to have updated ipsec_barf man-page. There is a description how ipsec barf works, but there is no mention about journalctl.

2,

It is not redhat-7 issue, but there is a fall-back for systems which do not use systemd. This fall-back has not been changed in the new version, so it still uses string 'Starting Pluto subsystem' for grep, see first comment. Is it ok?

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHSA-2016-2603.html