Phenquestions
Understanding logs is important: if you ever fall on a server that has a bug or is hacked, generally your only way to understand what happened is via logs. The main application we're going to use is journalctl hence the name of the article. So listen carefully as on the right day, you may be happy to know how it works.
Where are stored systemd logs? And what format it is stored in?
We'll take assumption you have a normal system, because systemd can be customized to be in exceptional places. As well, some Linux distributions like Ubuntu 16.04 disabled persistent logging by default, which prevent systemd to do its job correctly. If you have such distribution, edit /etc/systemd/journald.conf file, change Storage=auto to Storage=persistent and finally, reboot.
So you will find normally the systemd logs files in /var/log/journal. The journalling system is itself a service called system-journald.service. Let's try to list the files in this directory:
# ls /var/log/journal/ -R/var/log/journal/:
15e43c1734090ac7fbea6b40fcd99d31
/var/log/journal/15e43c1734090ac7fbea6b40fcd99d31:
[email protected]~
system@62ac1299826d036cb043d6c06a9493b7-0000000000000001-00067d6410099a19.journal
[email protected]~
user-1000@2123bc076b58569fe1fb13e9dbc1b0e0-0000000000000001-0007fe36ac2810e0.journal
user-1000.journal
[lots of other files like the ones above… ]
Because I want you to keep reading, I had to shorten the output as it contains many files (in my example, more than 60 files), sorry about that! Tempted to open one maybe?
# head --bytes=512 /var/log/journal/15e43c1734090ac7fbea6b40fcd99d31/[email protected]b58569fe1fb13e9dbc1b0e0-0000000000000001-0007fe36ac2810e0.journal
?s,q?n/FLz???Ulz?l?]????
?_?b???z????o?y1KN ?i?eO??W?u? ?=?x0?L?d?7??X4n#?e? d3l?
p??o|MFO:?!qs?.tK??R?\??1?|5 ????$?g??#?S??;??B7???????t???Y????mN?q????ZQ
?Yv?e?????BD?C?? wF??d|
?2?? 7???????[??Un?=8????c?2=p?&?" ?0
????*????_?? ???
5?????yk?G? ?6?|??u??w: #12?Y??
3 TU;???'?jX??2?x'?=??[[email protected]
[email protected]?_?>??3S???,lR?.?$?g?L???s?/E??M1??q???
Hey, see, that doesn't really looks like the usual log files you see right? Don't worry, this file isn't corrupted, you just discovered an aspect of systemd: systemd stores files in a binary format. That's why it's as small as possible: structured data such as time or location is stored straight in binary, which generally takes less bytes than does text. But that's not the only reason.
systemd doesn't only store log lines. Its intent is to make logs monitoring and exploration easier. To help in this task, log messages are in fact a line of text accompanied with data such as log severity (warning, error, etc.), or even fields that would be only useful to your application (URL requested for example).
# journalctl --output=verbose --allPRIORITY=6
_UID=0
_GID=0
_CAP_EFFECTIVE=3fffffffff
_BOOT_ID=ee4cc2ce7e8273aaffb5fc59c873ce7b
_MACHINE_ID=bc422e0feaab64bb7dd218c24e6830e5
_HOSTNAME=linux
SYSLOG_FACILITY=3
SYSLOG_IDENTIFIER=systemd
UNIT=dnf-makecache.service
_TRANSPORT=journal
_PID=1
_COMM=systemd
_EXE=/usr/lib/systemd/systemd
_CMDLINE=/usr/lib/systemd/systemd --switched-root --system --deserialize 76
_SYSTEMD_CGROUP=/init.scope
_SYSTEMD_UNIT=init.scope
_SYSTEMD_SLICE=-.slice
_SELINUX_CONTEXT=system_u:system_r:init_t:s0
CODE_FILE=src/core/job.c
CODE_LINE=795
CODE_FUNCTION=job_log_status_message
MESSAGE_ID=a76e08846f5f0971371dbb11126e62e1
MESSAGE=Started dnf makecache.
# journalctl --catalog --lines=3000 --pager-end "_TRANSPORT=kernel" RESULT=done
_SOURCE_REALTIME_TIMESTAMP=1532886335471422
I have told you there's a lot of fields (here there's 25 fields, or 29 counting timestamps), all of the snippet above is only for a single log message! The big benefit is that you can run a search by filtering on any field in this log message. This really enables you to advanced filtering.
One of the most obvious filter you would want is to filter by the service. As you can see above, there's a UNIT field so you can easily filter to get only log messages from one service. I'll tell you more about that later.
But this amount of data also means something else: in nearly all cases, you'll never open a log file manually and you won't ever touch to the /var/log/journal folder. You'll use journalctl for any task related to logging. There's no such log rotation thing, everything is managed by log message time.
As well, the number of fields will depend on how good is the integration of systemd in your application. The more fields a log message contains, the better it is. For base system services, systemd already took care of doing a good integration but for other applications and services, the quality of integration varies a lot. Normally, this should get better over time as people gets used to systemd.
Okay, now it's time to discover journalctl's features.
Most used commands for journalctl
The first command you might want to take a look on is the one showing the Linux kernel's logs. Yes, systemd also handles the storage of kernel's logs, so you can get the logs of previous boots as well. Here is the command:
# journalctl --catalog --lines=3000 --pager-end "_TRANSPORT=kernel"It shows you a pager where you can see the last messages. You can scroll up to the last 3,000 lines using arrow keys (↑ / ↓) or Page Up / Page Down. The -catalog flag instructs journalctl to show context around log lines, much like computer reboots or, in other contexts, a service stopping / starting. I always put this flag as context always matters, it helps to know in which situation the log line appeared, so you can guess why you got this log line.
Now, maybe you want to only see the log lines from the current boot:
# journalctl --catalog --lines=35000 --pager-end --boot "_TRANSPORT=kernel"Note the -boot command line argument works in all situations, not only with kernel's logs. If you prefer to start from the beginning:
# journalctl --catalog --boot "_TRANSPORT=kernel"I don't know if it's the case for you, but I've enough of kernel logs! And what about having a general overview of your machine?
# journalctl --catalog --lines=3000 --pager-endWow, there's a lot of things happening on your system! A bit of filtering would be helpful here. One of the most used filters is matching a specific service (like your SSH server or HTTP server), the systemd unit filename for SSH service is sshd.service, so:
# journalctl --catalog --lines=3000 --pager-end --unit=sshd.serviceThat's cool, isn't it? Well it's only usable if you know the name of the service - but in lot of cases, you don't know the name of that service. If you're on such situation, you may want a listing of the services, their descriptions and their status:
# systemctl list-units --type=serviceOkay, this problem is now solved. But sometimes, you have an error message you get from an external system like your own website or from an application on your desktop. So you will probably want to search a specific word or sentence in the log message. Since systemd v237, it's now possible.
In journalctl, the search is case insensitive if the word you search is all in lowercase. So if you search the word port, it will also search the word port with capitalized letters. An example:
# journalctl --catalog --lines=3000 --pager-end --grep="port"Now, if you search a word like CPU, it will only search CPU with all capitalized letters, it won't search cpu.
# journalctl --catalog --lines=3000 --pager-end --grep="CPU"You remember the error message from the external system? Generally, these messages contains a timestamp. To filter the log message, you may want to use that timestamp. journalctl can list you all log messages since a specific date and time with the -since argument:
# journalctl --catalog --since="2018-07-30 09:30:00"If that external system is remote or is using UTC timestamps, you'll want to filter based on a UTC date and time and display in the terminal the UTC timestamps so you don't need to convert it in your head, that tends to be really confusing. To do so, you'll need to add UTC after the time string in -since argument. You will then need to add the -utc flag. So, for example:
# journalctl --catalog --since="2018-07-30 10:45:00 UTC" --utcNote you can use the -utc flag alone, in this case it will basically display all dates and times in UTC timezone.
# journalctl --catalog --lines=3000 --pager-end --utcLogs are better managed with journalctl
As you can see with all previous commands, systemd journaling makes filtering and so debugging easier as you can select through all log lines using a single command, journalctl. Some of you probably knew ancient times where you had to manually open every file in /var/log to have a general idea of the problem and of what's happened. With all the tips you learned here, you'll own solid tools to look at your log messages in the way YOU want it.
