On Sunday 30 March 2014 11.21:07 Achim Gratz wrote:

Some time ago I had a problem with slow boot. Once that was fixed I started to have the opposite problem, that is long delays with high disk activity during shutdown, getting much worse with time. Again this turns out to be triggered by journald: once the log file had grown past 20MiB or so there would be a noticeable delay when flushing the log to disk and it became unbearable at 80MiB. The time is superlinear with log size: a verify on the current 7MiB journal file takes roughly 1.5s (17s for a loop of 16 verifies), the 114MiB for the old file are already over 30s. The solution (for me) was to set

SystemMaxFileSize=8M

in /etc/systemd/journald.conf so that the active journal file gets rotated much earlier than with the built-in defaults. I have a rather small separate /var, but that file would have grown to about 300MiB. considering that most people probably have probably much larger /var partitions and the superlinear scaling characteristics, I think it would be advisable to provide more sensible defaults with the distribution.

Regards, Achim.

Take into account, that some people will use journald without the rsyslog emulation on (no /var/log/message text flushing) And the default doesn't look that bad systemd-journal[419]: Runtime journal is using 2.7M (max 796.6M, leaving 1.1G of free 7.7G, current limit 796.6M). du total of /var/log/journal = 1.8GB -- Bruno Friedmann Ioda-Net Sàrl www.ioda-net.ch openSUSE Member & Board GPG KEY : D5C9B751C4653227 irc: tigerfoot ~~~~~ Don't take Life too serious. Nobody gets out alive anyway! ~~~~~ -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-factory+owner@opensuse.org

On Monday 31 March 2014 19.59:33 Achim Gratz wrote:

Bruno Friedmann writes:

...

Take into account, that some people will use journald without the rsyslog emulation on (no /var/log/message text flushing) And the default doesn't look that bad

systemd-journal[419]: Runtime journal is using 2.7M (max 796.6M, leaving 1.1G of free 7.7G, current limit 796.6M).

None of this is even remotely related to the problem at hand AFAICS.

...

du total of /var/log/journal = 1.8GB

How many files do you have in that directory and what's the result of

70 files since January 28th 2013.

time journalctl --verify

real 2m20.742s user 2m6.646s sys 0m12.043s

(if you have lots of rotated backups, you can do the verify only on the "open" system and user journals, which seems to be -- at least runtime-wise -- what happens at shutdown).

-- Bruno Friedmann Ioda-Net Sàrl www.ioda-net.ch openSUSE Member & Board GPG KEY : D5C9B751C4653227 irc: tigerfoot ~~~Don't take Life too serious. Nobody gets out alive anyway!~~~ -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-factory+owner@opensuse.org

El 03/04/14 14:57, Achim Gratz escribió:

You obviously have a much speedier system than mine (which doesn't really surprise me as my computer is 11 years old). Is this an SSD? Out of curiosity, how long does it take to just verify the active journal file?

journalctl --verify --system 4.25s user 0.20s system 99% cpu 4.452 total -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-factory+owner@opensuse.org

On Fri, Apr 4, 2014 at 8:38 AM, Bruno Friedmann wrote:

...

...

...

time journalctl --verify

real 2m20.742s user 2m6.646s sys 0m12.043s

You obviously have a much speedier system than mine (which doesn't really surprise me as my computer is 11 years old). Is this an SSD? Out of curiosity, how long does it take to just verify the active journal file?

It's already a old computer 3 years old i7-2nd generation with 16GB Ram and a 480GB Corsair SSD GT-Force3 (6gbs sata)

2 minutes on an SSD? That's completely unworkable for rotating media (they're *orders of magnitude* slower for random access). Can you test that on rotating media please? A great deal of us are still using spinning rust for our storage needs, testing on SSD and calling it representative is probably as wrong as you can get. -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-factory+owner@opensuse.org

On Fri, Apr 4, 2014 at 2:12 PM, Bruno Friedmann wrote:

On Friday 04 April 2014 09.31:38 Claudio Freire wrote:

...

On Fri, Apr 4, 2014 at 8:38 AM, Bruno Friedmann wrote:

...

...

...

...

time journalctl --verify

real 2m20.742s user 2m6.646s sys 0m12.043s

You obviously have a much speedier system than mine (which doesn't really surprise me as my computer is 11 years old). Is this an SSD? Out of curiosity, how long does it take to just verify the active journal file?

It's already a old computer 3 years old i7-2nd generation with 16GB Ram and a 480GB Corsair SSD GT-Force3 (6gbs sata)

2 minutes on an SSD?

That's completely unworkable for rotating media (they're *orders of magnitude* slower for random access). For 2.9GB of logs ?

It depends on whether they're loaded sequentially or randomly, but judging from the OP, it's random, and random is on average 2MB/s on modern rotating rust (resulting in 24.7 minutes runtime for 2.9GB).

...

Can you test that on rotating media please? A great deal of us are still using spinning rust for our storage needs, testing on SSD and calling it representative is probably as wrong as you can get.

Well if only I've still rotating rust for system. I've chosen journald exclusively cause I know some report of being perhaps slow on rust and all system here are now powered on ssd. (Tired of sector defects & co)

Can you not copy into rotating rust and verify the copy? Flush your cache first with: sudo sync sudo sysctl -w vm.drop_caches=3 sudo sysctl -w vm.drop_caches=0

I also have decided to export them to external storage in plain text mode for archiving purpose. Rotating the journal is also a nice way to get perf back. Afterall we also rotate text log files and compress them. .. for example I've rotated my log this morning and now du -sh /var/log/journal/32aed2336d02ef306e8c3ca25103d7ee 3.7M /var/log/journal/32aed2336d02ef306e8c3ca25103d7ee

time journalctl --verify --system PASS: /var/log/journal/32aed2336d02ef306e8c3ca25103d7ee/system.journal

real 0m0.041s user 0m0.035s sys 0m0.006s

Look like there's some good practices to be determined.

Indeed -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-factory+owner@opensuse.org

Am 04.04.2014 14:31, schrieb Claudio Freire:

2 minutes on an SSD?

It's CPU bound, not IO bound (for me, 780MB /var/log/journal => 3 minutes to verify, just reading takes ~3 seconds with SSD)

That's completely unworkable for rotating media (they're *orders of magnitude* slower for random access).

Never ever put the persistant journal onto rotating rust. Just use syslog. Due to the genius design, the files fragment heavily and thrash the disk. Even plain "systemctl status foo.service" which looks into journal for logs will take 30+ seconds with journal on non-SSD.

Can you test that on rotating media please? A great deal of us are still using spinning rust for our storage needs, testing on SSD and calling it representative is probably as wrong as you can get.

Putting the journal on anything but SSD or RAM is as wrong as you can get :-) -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-factory+owner@opensuse.org

On Fri, Apr 4, 2014 at 6:16 PM, Stefan Seyfried wrote:

...

That's completely unworkable for rotating media (they're *orders of magnitude* slower for random access).

Never ever put the persistant journal onto rotating rust. Just use syslog. Due to the genius design, the files fragment heavily and thrash the disk. Even plain "systemctl status foo.service" which looks into journal for logs will take 30+ seconds with journal on non-SSD.

...

Can you test that on rotating media please? A great deal of us are still using spinning rust for our storage needs, testing on SSD and calling it representative is probably as wrong as you can get.

Putting the journal on anything but SSD or RAM is as wrong as you can get :-)

Why not preallocate the space? That would get rid of fragmentation, and it should be a mostly-oneliner patch (call to posix_fallocate). For reading, posix_fadvise (or madvise) could read it whole (to avoid reading it in random fashion). Has this been tried? -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-factory+owner@opensuse.org

Am 04.04.2014 23:28, schrieb Claudio Freire:

Why not preallocate the space?

Because the genius did not think of this?

That would get rid of fragmentation, and it should be a mostly-oneliner patch (call to posix_fallocate).

For reading, posix_fadvise (or madvise) could read it whole (to avoid reading it in random fashion).

Has this been tried?

a676e66535e12458ea6d366a653f8dd60f982504 seems to do this: + /* Increase the file size a bit further than this, so that we + * we can create larger memory maps to cache */ + file_size = ((new_size+FILE_SIZE_INCREASE-1) / FILE_SIZE_INCREASE) * FILE_SIZE_INCREASE; + if (file_size > (uint64_t) f->last_stat.st_size) { + if (file_size > new_size) + ftruncate(f->fd, file_size); + + if (fstat(f->fd, &f->last_stat) < 0) + return -errno; + } FILE_SIZE_INCREASE is 8MB. And since this patch is ported back to opensuse, fragmentation is much better: Files with mtime 2014-02-13: ... 1420 extents found ... 786 extents found later files: ... 12 extents found system.journal: 20 extents found So it should be better nowadays. -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-factory+owner@opensuse.org

Hi Bruno, Am 07.04.2014 09:26, schrieb Bruno Friedmann:

Upstream have always promise that the journal has not problem, just the parser. So I keep them ;-)

I keep the messages-$DATE.xz, I know that I can read them without relying on someone else :-) Journal is just for "fun" (well, strange values of "fun") for now and the foreseeable future.

I'm using a poor dirty man hack rotate way. I've no formal code but my hack follow the idea of

Find journal storage D=$(journalctl --header --system | grep "Machine ID" | awk '{print $3}') R=${D}_$(date --utc "+%F_%H%M%S") $B="/var/log/journal"

systemctl stop systemd-journald.service mv ${B}/${D} ${B}/${R} systemctl start systemd-journald.service

That's cool. I'll keep that for reference :-)

Journal is recreated and old one are still accessible with journalctl --directory=PATH could be exported to another host etc...

Not that ideal as you can see, but I know that I don't have 100 lines of incoming logs when the rotate happen.

IMO you should be able to just move the directory and then restart journald, since the FDs will stay open during move, so you'll only have a very short outage? -- Stefan Seyfried "For a successful technology, reality must take precedence over public relations, for nature cannot be fooled." -- Richard Feynman -- To unsubscribe, e-mail: opensuse-factory+unsubscribe@opensuse.org To contact the owner, e-mail: opensuse-factory+owner@opensuse.org