[systemd-devel] Antw: [EXT] Re: Why is journalctl -b so slow?
>>> Lennart Poettering schrieb am 19.12.2020 um 13:34 in Nachricht <20201219123435.GJ48346@gardel-login>: > On Fr, 20.11.20 10:39, Ulrich Windl (ulrich.wi...@rz.uni‑regensburg.de) wrote: > >> Hi! >> >> journactl ‑b is quite fast to display the first lines, but when I >> want to see the last lines, it's quite slow. > > How to you jump to the last lines? You are in "less" (i.e. the usual > auto‑paging) and press ? If so, the full journal needs to be I press 'G' ;-) > streamed to less first. That is necessarily slow if you have a lot of > log data, since it all needs to be read into memory, passed to less > which then buffers it again, counts lines and finds the "end" of it). > >> The journal is on BtrFS >> that is on a hardware RAID made from two SSDs, so the _filesystem_ >> should not be the problem (actually it seems the journal is in tmpfs >> actually): > > Performance deteriorates with the number of journal files. There are > some O(n)'isms with the number of journal files currently. These > should be addressable though, but so far noone spent the time on this > (i.e. we can move a tiny bit more information from the file contents > into the file name so that we don't have to even open the files to be > able to know where they belong in the chronology of things) > > btrfs makes things a lot worse btw, since the write pattern we employ > that are very unfriendly to CoW file systems (i.e. we do random > writes; CoW file systems can't really handle anything that aren't > linear writes). In upstream defaults we thus turn off cow for these > files, not sure if your distro undoes that though. At the time being, the journal was in tmpfs only. It seems the problem might be either: Many very similar messages repeating in groups (like A, B, C, A, B, C, ...) Related to Unicode processing (There exists a similar slowness in "wc") Regards, Ulrich > > Lennart > > ‑‑ > Lennart Poettering, Berlin ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel
[systemd-devel] Antw: [EXT] Re: Why is journalctl -b so slow?
>>> Vito Caputo schrieb am 20.11.2020 um 20:09 in Nachricht <20201120190913.4t4dupzxrshon...@shells.gnugeneration.com>: > On Fri, Nov 20, 2020 at 10:39:14AM +0100, Ulrich Windl wrote: >> Hi! >> >> journactl ‑b is quite fast to display the first lines, but when I want to see > the last lines, it's quite slow. The journal is on BtrFS that is on a > hardware RAID made from two SSDs, so the _filesystem_ should not be the > problem (actually it seems the journal is in tmpfs actually): >> >> ### done after being called before, so the file contents should be cached > anyway. >> # time journalctl ‑b |wc ‑l >> 2018589 >> >> real0m21.890s >> user0m19.053s >> sys 0m3.292s >> >> Reading all files to compare: >> # time cat /run/log/journal/e766c8d06f144b1588487221640f55b5/* |wc ‑l >> 3203984 >> >> real0m0.729s >> user0m0.135s >> sys 0m0.962s >> >> # df /run >> Filesystem 1K‑blocksUsed Available Use% Mounted on >> tmpfs 131889480 1664768 130224712 2% /run >> >> systemd‑234‑24.61.1.x86_64 from SLES15 SP2. >> > > How big are the journal files and how many are there? While trying to determine the sizes I made a very interesting observation: While "wc -l" is fast (less than 1 second), "wc" (without "-l") takes more than a minute! # time wc -l /run/log/journal/e766c8d06f144b1588487221640f55b5/* 126016 /run/log/journal/e766c8d06f144b1588487221640f55b5/system.journal 237547 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-0001-0005b3f9b726314e.journal 289220 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-0002626b-0005b3fdddc1ac31.journal 289962 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-0004d777-0005b4052d952b37.journal 267185 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-00074d19-0005b40c7f1e2c5b.journal 333123 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-0009c2ad-0005b413d068abd6.journal 266936 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-000c37d4-0005b41b203c33eb.journal 237000 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-000ead24-0005b42270cb3177.journal 236427 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-00112238-0005b429c0dd2e09.journal 236646 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-001396ea-0005b4310efb31c0.journal 231837 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-00160b9a-0005b4385a2b3033.journal 226417 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-00187e2a-0005b43e6ae73265.journal 226363 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-001af146-0005b443b238b0e1.journal 3204679 total real0m0.314s user0m0.100s sys 0m0.215s # time wc /run/log/journal/e766c8d06f144b1588487221640f55b5/* 126016 831206 92274688 /run/log/journal/e766c8d06f144b1588487221640f55b5/system.journal 2375471275825 134217728 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-0001-0005b3f9b726314e.journal 2892201335438 134217728 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-0002626b-0005b3fdddc1ac31.journal 2899621411322 134217728 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-0004d777-0005b4052d952b37.journal 2671851348136 134217728 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-00074d19-0005b40c7f1e2c5b.journal 3331231602322 134217728 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-0009c2ad-0005b413d068abd6.journal 2669361463014 134217728 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-000c37d4-0005b41b203c33eb.journal 2370001226780 134217728 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-000ead24-0005b42270cb3177.journal 2364271196644 134217728 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-00112238-0005b429c0dd2e09.journal 2366461252991 134217728 /run/log/journal/e766c8d06f144b1588487221640f55b5/system@43da9abd7ab542c1b67267b7b7bddd63-001396ea-0005b4310efb31c0.journal 2318371190868 134217728
