journalctl issues

HalJordan · 2012-12-01 01:51:59

For the past week or two, I've noticed that systemctl will work, but if I use systemctl status <anything>, it will show the status at the top, then hang for a minute. I didn't realize what was missing was the few lines from the journal.

Now I've realized that for some reason, journalctl takes longer than I have patience for, to display anything.

I'm looking at the config, and see that I never set a max filesize, I'm setting all those to 200M now, and restarting systemd-journald.

In case this doesn't fix it, has anyone else run into this?

loafer · 2012-12-01 10:17:00

In my case it "journalctl status ..." takes a split second longer to display the very first time I issue a command but the next time I run the same command it is instant. The delay the first time really is a split second and is not a problem at all.

What is the delay you are seeing with journalctl as I do not see that at all.

berbae · 2012-12-01 15:45:14

@HalJordan: Maybe you have too much files in the /var/log/journal/.../ directory.
What is the output of the command:

journalctl --disk-usage

Do you really need such a high value of 200M?

cfr · 2012-12-01 23:07:44

Try journalctl --verify, too.

ataraxia · 2012-12-02 01:48:46

journalctl (as well as some other things) was very slow for me on btrfs (spinning hdd, not ssd). After going back to ext4, it's just as fast as it always used to be. What filesystem are you on?

HalJordan · 2012-12-03 14:11:01

Sorry, it's been a busy weekend. I'm running --verify now. I am on btrfs, but everything else has been moving faster since I made the switch. Dunno why the journal would take longer. I was tempted to move /var to reiserfs, but noticed that it's no longer fully supported. It looks like I have something wrong in my journal. It's not done, but I got this...

Invalid object contents at 93117416█████████████████████████████████████████████████████░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░  49%
File corruption detected at /var/log/journal/2dd5724e1e1542fc9a4aa75dec6cb750/system@f0868a2cd24344648a0bbe3a801ead66-000000000001b5d4-0004cfd1dbb89d38.journal:93117416 (of 93118464, 99%).
FAIL: /var/log/journal/2dd5724e1e1542fc9a4aa75dec6cb750/system@f0868a2cd24344648a0bbe3a801ead66-000000000001b5d4-0004cfd1dbb89d38.journal (Bad message)
Invalid object contents at 104535240████████████████████████████████████████████████████░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░  49%
File corruption detected at /var/log/journal/2dd5724e1e1542fc9a4aa75dec6cb750/system@f0868a2cd24344648a0bbe3a801ead66-0000000000035a33-0004cfd5f37271e4.journal:104535240 (of 104538112, 99%).
FAIL: /var/log/journal/2dd5724e1e1542fc9a4aa75dec6cb750/system@f0868a2cd24344648a0bbe3a801ead66-0000000000035a33-0004cfd5f37271e4.journal (Bad message)

We'll see when it's finished...

{EDIT}
And as far as the filesize, I figured 200M wouldn't be nearly as large as the +/-3G that it was... X)

Last edited by HalJordan (2012-12-03 14:14:03)

smudge · 2012-12-07 03:47:17

I haven't got the hanging/slowdown issues you describe but did have the same "journalctl --verify" errors. For me it started once the journal hit the "SystemMaxUse" set in /etc/systemd/journald.conf.

I'd set it to 25M and a few days ago, when "journalctl --disk-usage" was about 18M there was no problem. As soon as it hit 25M, --verify began to fail.

Try deleting all the journal files, worked for me

HalJordan · 2012-12-07 14:10:20

Yeah, that worked, but there are two major caveats to that imo...

1) I lose all my log data that was in journald... not a good thing imo...
2) The problem returns when it reaches max capacity...

Is there some reason journald wouldn't rotate the logs itself when they reach that size? Shouldn't it rotate those out, and start on new empty log files when the old ones reach the size I have set?

berbae · 2012-12-07 16:04:47

smudge wrote:

I'd set it to 25M and a few days ago, when "journalctl --disk-usage" was about 18M there was no problem. As soon as it hit 25M, --verify began to fail.

How do you know the two facts are linked? Maybe something else corrupted the journal files.
Is it only the last journal file which is corrupted or old rotated ones in the directory are affected too?
And you didn't clearly say if the cleanup operates well with the corrupted files, or if all the cleanup process is prevented by the corrupted files.

Try deleting all the journal files, worked for me

Only the corrupted files can be deleted, even if that results in holes in the log messages; it's better than losing everything.

smudge · 2012-12-07 23:26:06

HalJordan wrote:

Is there some reason journald wouldn't rotate the logs itself when they reach that size?

According to "man journal.conf" it's meant to. I (we) maybe doing something wrong of course but we're not the only ones: https://bbs.archlinux.org/viewtopic.php?id=150052

berbae wrote:

How do you know the two facts are linked? Maybe something else corrupted the journal files.

I don't and maybe. You're quite right, it's just a hunch, I could be completely wrong.

Is it only the last journal file which is corrupted or old rotated ones in the directory are affected too?

It was about 50% (maybe less) of the old journal files that alternated between PASS and FAIL in the output of "journalctl --verify".

And you didn't clearly say if the cleanup operates well with the corrupted files, or if all the cleanup process is prevented by the corrupted files.

I used mc to delete the /var/log/journal/xxxxxxx-dbus-session-id-xxxxxxxx directory and rebooted so not really an issue.

And you're both right, deleting isn't ideal.

HalJordan · 2012-12-17 17:06:28

For now, I have a dirty hack of a script running to forcibly rotate the logs, it means i'm missing some of my logs from journald, but I can at least see todays.
Are you using compression in /etc/systemd/journald.conf? I am.

smudge · 2012-12-18 05:01:38

My hunch about --verify failing when SystemMaxUse is reached was wrong, been getting the same problem ever since my last post. Got a couple of new hunches though.

Boot time kernel panics (after systemd-journal has started presumably) and crashing processes trying to put their coredumps into the journal.

Again, can't prove it and not sure what to do about it

HalJordan wrote:

Are you using compression in /etc/systemd/journald.conf? I am.

I left it default so yes.

sano · 2012-12-18 08:06:15

I have the same problem with corrupted journal files. I don't know if it is connected, but sometimes I see a systemd or journald error about "too many arguments" flashing past during shutdown.
I am gonna look into a way to preserve those messages (they don't show up in the journal).

Changaco · 2013-05-22 17:38:51

I have the same problem of slow journalctl. Moreover, Firefox sometimes slows down my system with IO tasks. The problem only seems to appear when using these programs on btrfs partitions. Disabling copy-on-write https://wiki.archlinux.org/index.php/Bt … _.28CoW.29 in the adequate directories may help fix the problem.

Last edited by Changaco (2013-08-25 13:12:02)

Arch Linux

#1 2012-12-01 01:51:59

journalctl issues

#2 2012-12-01 10:17:00

Re: journalctl issues

#3 2012-12-01 15:45:14

Re: journalctl issues

#4 2012-12-01 23:07:44

Re: journalctl issues

#5 2012-12-02 01:48:46

Re: journalctl issues

#6 2012-12-03 14:11:01

Re: journalctl issues

#7 2012-12-07 03:47:17

Re: journalctl issues

#8 2012-12-07 14:10:20

Re: journalctl issues

#9 2012-12-07 16:04:47

Re: journalctl issues

#10 2012-12-07 23:26:06

Re: journalctl issues

#11 2012-12-17 17:06:28

Re: journalctl issues

#12 2012-12-18 05:01:38

Re: journalctl issues

#13 2012-12-18 08:06:15

Re: journalctl issues

#14 2013-05-22 17:38:51

Re: journalctl issues

Board footer