Bug 1426152 - Journalctl miss to show logs from unit
Summary: Journalctl miss to show logs from unit
Keywords:
Status: CLOSED DUPLICATE of bug 963620
Alias: None
Product: Fedora
Classification: Fedora
Component: systemd
Version: 24
Hardware: x86_64
OS: Linux
unspecified
medium
Target Milestone: ---
Assignee: systemd-maint
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-02-23 10:09 UTC by Davide Lima "Duarte" Daum
Modified: 2018-12-18 08:10 UTC (History)
9 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-02-24 08:24:24 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description Davide Lima "Duarte" Daum 2017-02-23 10:09:10 UTC
Description of problem:
With the command journalctl -u {unit} you can see the logs of the specified unit
only. The problem is that this command miss some log message from the unit.
Here the example on my desktop:

journalctl --since "2017-02-23 08:30:00"

-- Logs begin at lun 2016-08-22 07:00:02 CEST, end at gio 2017-02-23 10:58:15 CET. --
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions audit[21639]: USER_ACCT 
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions audit[21639]: CRED_ACQ 
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions systemd[1]: Starting system activity accounting tool...
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions audit[1]: SERVICE_START 
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions audit[1]: SERVICE_STOP 
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions systemd[1]: Started system activity accounting tool.
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions systemd[1]: Started Session 8 of user dlima.
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions audit[21639]: USER_START 
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions audit[21639]: CRED_REFR 
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions CROND[21647]: (dlima) CMD ($HOME/bin/download-log.sh >> $HOME/tmp/log/download-log.log 2>&1)
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions audit[21639]: CRED_DISP 
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions audit[21639]: USER_END 
feb 23 08:30:01 dlima-ktm.soulsociety.dimensions postfix/pickup[30981]: 

The important line of log is the CROND at 08:30:01

feb 23 08:30:01 dlima-ktm.soulsociety.dimensions CROND[21647]: (dlima) CMD ($HOME/bin/download-log.sh >> $HOME/tmp/download-log.log 2>&1)

But if i use the command journalctl -u crond.service, the output is this:

[.....]feb 23 05:01:01 dlima-ktm.soulsociety.dimensions run-parts[6726]: (/etc/cron.hourly) starting 0anacron
feb 23 05:01:01 dlima-ktm.soulsociety.dimensions run-parts[6732]: (/etc/cron.hourly) finished 0anacron
feb 23 05:01:02 dlima-ktm.soulsociety.dimensions run-parts[6756]: (/etc/cron.hourly) finished awstats
feb 23 06:01:01 dlima-ktm.soulsociety.dimensions CROND[15336]: (root) CMD (run-parts /etc/cron.hourly)
feb 23 07:01:01 dlima-ktm.soulsociety.dimensions CROND[22663]: (root) CMD (run-parts /etc/cron.hourly)
feb 23 07:01:02 dlima-ktm.soulsociety.dimensions run-parts[22699]: (/etc/cron.hourly) finished awstats
feb 23 08:01:01 dlima-ktm.soulsociety.dimensions CROND[444]: (root) CMD (run-parts /etc/cron.hourly)
feb 23 08:01:01 dlima-ktm.soulsociety.dimensions run-parts[453]: (/etc/cron.hourly) finished 0anacron
feb 23 08:01:01 dlima-ktm.soulsociety.dimensions run-parts[455]: (/etc/cron.hourly) starting awstats
feb 23 09:01:01 dlima-ktm.soulsociety.dimensions CROND[7735]: (root) CMD (run-parts /etc/cron.hourly)
feb 23 10:01:01 dlima-ktm.soulsociety.dimensions CROND[18773]: (root) CMD (run-parts /etc/cron.hourly)

As You can see the scheduled crond at 8:30 is missing from the output...
I don't know if this happen not only with the cron logs.

Version-Release number of selected component (if applicable):
229-18.fc24

How reproducible:
Create a cron schedule for a user, wait the time it will be executed, and use the command journactl -u crond.service 
to see the missing line of the executed schedule.

Steps to Reproduce:
1. Create a personal cron, cron -e
2. Run journalctl -u crond.service after the scheduled job


Actual results:
Missing line of the scheduled job

Expected results:
A log line about the execution of the scheduled job.

Additional info:

Comment 1 Michal Sekletar 2017-02-23 13:20:02 UTC
This is a known issue. systemd-journald sometimes fails to record information about unit from which log message originates. There is a higher probability of hitting this problem if the process that logs the message is short lived.

Comment 2 Davide Lima "Duarte" Daum 2017-02-23 16:33:15 UTC
So in the end the old, This is not a good thing, the logs can not disappear in this way. In addition, the denied possibility to return to the good old *syslog makes it quite ridiculous...

Comment 3 Davide Lima "Duarte" Daum 2017-02-23 16:33:37 UTC
This is not a good thing, the logs can not disappear in this way. In addition, the denied possibility to return to the good old *syslog makes it quite ridiculous...

Comment 4 Michal Sekletar 2017-02-24 08:24:24 UTC
Logs are not disappearing anywhere. It's just that for some log messages that originate from short lived processes journald can't figure out respective cgroup (unit). Thus you will not see those log lines if you apply filtering based on unit name. We can't do anything about this until kernel gives us a way to gather cgroup information in non racy way. But then again, logs are there and your first command that uses time based filtering proves that.

Comment 5 Peter Valdemar Mørch 2018-12-18 00:37:44 UTC
Since this is a "known issue", I'd like to know if we could be pointed to an issue filed against the kernel for this in https://bugzilla.kernel.org/ ?

Peter

Comment 6 Zbigniew Jędrzejewski-Szmek 2018-12-18 08:10:36 UTC
See the other bugs for multiple patch submission attempts.

*** This bug has been marked as a duplicate of bug 963620 ***


Note You need to log in before you can comment on or make changes to this bug.