Bug 1215540 - Improve responsiveness for module “Systemd Journal”
Summary: Improve responsiveness for module “Systemd Journal”
Status: RESOLVED WONTFIX
Alias: None
Product: openSUSE Tumbleweed
Classification: openSUSE
Component: YaST2 (show other bugs)
Version: Current
Hardware: x86-64 openSUSE Tumbleweed
: P5 - None : Enhancement (vote)
Target Milestone: ---
Assignee: E-mail List
QA Contact: Jiri Srain
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2023-09-20 19:42 UTC by Markus Elfring
Modified: 2023-09-23 11:26 UTC (History)
1 user (show)

See Also:
Found By: ---
Services Priority:
Business Priority:
Blocker: ---
Marketing QA Status: ---
IT Deployment: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Markus Elfring 2023-09-20 19:42:09 UTC
I would occasionally also like to use the YaST2 module “Systemd Journal” more often.
Unfortunately, I got the impression that its run time characteristics are so special (at the moment) that I do not get an usable selection interface within a time range which I would tolerate.
Comment 1 Stefan Hundhammer 2023-09-21 08:40:30 UTC
That's too generic. Please describe in what situation you consider the performance too bad: Directly upon startup? When you enter a search term in the search box at the top? When applying a filter? (Which one?)

I just started it on my Leap 15.5, and the performance was great. But then, I don't leave my machine running for days and weeks; I shut it down at the end of each work day and reboot it the next morning. I also don't have an excessive number of log entries in the journal. So I don't know how comparable your and my situations are.

Also, please be aware that since this is using interpreted Ruby and a generic widget of the YaST UI toolkit (libyui), of course it has limitations when it comes to performance. It's more meant for the casual user who doesn't want to deal with the complexities of the 'journalctl' command.

The 'journalctl' command line OTOH is very powerful; it can do at least all the things that the YaST journal module does, probably a lot more. If you have very advanced needs for analyzing your machine's journal, you are probably better off with that command line. And it uses a pager which greatly improves its usability.
Comment 2 Markus Elfring 2023-09-21 11:31:17 UTC
(In reply to Stefan Hundhammer from comment #1)
> … Directly upon startup?

This can happen here (at the moment).

Can it be measured how long it would take to present the desired graphical user interface (if at all)?


> Also, please be aware that since this is using interpreted Ruby and a
> generic widget of the YaST UI toolkit (libyui), of course it has limitations
> when it comes to performance.

Can any more usage experiences be compared in this area?

* Software package “yast2-journal 4.6.0-1.1”

* https://github.com/yast/yast-journal
Comment 3 Markus Elfring 2023-09-21 11:57:23 UTC
Can further clarification of questionable software behaviour become more interesting also according to information like the following?

top - 13:52:32 up  1:55,  2 users,  load average: 3,94, 4,27, 4,10
Tasks: 309 total,   4 running, 305 sleeping,   0 stopped,   0 zombie
%CPU(s): 38,8 us, 37,0 sy,  2,1 ni, 21,0 id,  0,5 wa,  0,0 hi,  0,6 si,  0,0 st
MiB Spch: 15981,98+total,  148,574 free, 13422,15+used, 9740,641 buff/cache
MiB Swap: 36867,45+total, 35561,60+free, 1305,852 used. 2559,828 avail Spch

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     ZEIT+ BEFEHL                                                                                                                                                           
 8348 root      20   0  581016  68960  67936 R 98,42 0,421  51:23.56 journalctl                                                                                                                                                       
…
  669 root      20   0  153760  58688  57116 S 35,44 0,359  45:48.56 systemd-journal                                                                                                                                                  
…
 2277 root      20   0  292504   6740   3328 S 13,06 0,041  21:01.03 rsyslogd                                                                                                                                                         
 8346 root      20   0  427952  31260   1152 R 4,908 0,191   2:40.36 y2start                                                                                                                                                          
…
Comment 4 Markus Elfring 2023-09-21 12:21:16 UTC
Will the following data excerpt trigger further software development considerations?

top - 14:12:30 up  2:15,  2 users,  load average: 4,94, 5,75, 4,96
Tasks: 304 total,   3 running, 301 sleeping,   0 stopped,   0 zombie
%CPU(s): 25,4 us, 34,7 sy,  2,7 ni, 23,0 id, 12,3 wa,  0,0 hi,  1,8 si,  0,0 st
MiB Spch: 15981,98+total,  188,438 free, 15721,67+used,  649,379 buff/cache
MiB Swap: 36867,45+total, 23928,19+free, 12939,26+used.  260,309 avail Spch

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     ZEIT+ BEFEHL                                                                                                                                                           
…
 8335 root      20   0 16,210g 0,013t   3376 D 8,153 82,06   1:34.23 y2start                                                                                                                                                          
…
Comment 5 Stefan Hundhammer 2023-09-21 13:20:39 UTC
AFAICS your system has 16 GiB RAM, just like mine. The kernel making good use of otherwise unused RAM for I/O buffers is also quite normal. Okay so far.

In the "top" output, you have the 'journalctl' command using 98 %CPU. This is probably the YaST journal module calling it as an external program, and it's entirely plausible and expected; at least for a very short time.

If it takes excessively long, your journal might be very long, and that might be what eats the performance. You can check how many lines your journal has with

  sudo journalctl | wc -l

On my machine, the result is 2875. I might have configured systemd / journalctl not to keep that many journal lines; there are various options how long you might want to go back in the journal.

You could also check how long the 'journalctl' command takes when you call it manually, with or without extra filter options. For sure it will take longer with a longer journal.


For measuring startup times, using a stopwatch (a real one or one as a smartphone app) comes to mind: Measure the time between clicking on the module in the YaST control center and content appearing in the YaST journal module.
Comment 6 Stefan Hundhammer 2023-09-21 13:27:35 UTC
In bash, you can also emulate a stopwatch with

  time read         <-- start the stopwatch

  
  [Return]          <-- stop the stopwatch


real	0m3.122s    <-- elapsed clock time
user	0m0.000s    <-- CPU time in user space (irrelevant here)
sys	0m0.000s    <-- CPU time in kernel space (irrelevant here)
Comment 7 Markus Elfring 2023-09-21 15:57:04 UTC
(In reply to Stefan Hundhammer from comment #5)
> In the "top" output, you have the 'journalctl' command using 98 %CPU. This
> is probably the YaST journal module calling it as an external program, and
> it's entirely plausible and expected; at least for a very short time.

I hope that further improvements can be achieved also based on another data representation variant after a system reboot.

Sonne:~ # yast2 journal


top - 16:35:58 up 27 min,  2 users,  load average: 3.61, 3.24, 2.62
Tasks: 307 total,   3 running, 304 sleeping,   0 stopped,   0 zombie
%Cpu(s): 36.8 us, 38.0 sy,  2.1 ni, 22.2 id,  0.1 wa,  0.0 hi,  0.7 si,  0.0 st
MiB Mem : 15981.99+total, 7003.898 free, 5211.109 used, 5000.547 buff/cache
MiB Swap: 36867.45+total, 36867.45+free,    0.000 used. 10770.88+avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND                                                                                                                                                          
…
 3256 root      20   0   18684   7348   6196 S 0.000 0.045   0:00.02              `- /usr/bin/su -                                                                                                                                    
 7715 root      20   0    9884   5844   3412 S 0.000 0.036   0:00.04                  `- -bash                                                                                                                                        
 7760 root      20   0    4996   3156   2772 S 0.000 0.019   0:00.00                      `- /bin/bash /sbin/yast2 journal                                                                                                            
 7791 root      20   0  427964  76308  46328 S 0.000 0.466   0:00.49                          `- /usr/bin/ruby.ruby3.2 --encoding=utf-8 /usr/lib/YaST2/bin/y2start journal qt -name YaST2 -icon yast                                  
 7797 root      20   0  427964  31272   1152 S 3.574 0.191   0:09.23                              `- /usr/bin/ruby.ruby3.2 --encoding=utf-8 /usr/lib/YaST2/bin/y2start journal qt -name YaST2 -icon yast                              
 7798 root      20   0  427964  31016    896 S 0.000 0.190   0:00.00                                  `- /usr/bin/ruby.ruby3.2 --encoding=utf-8 /usr/lib/YaST2/bin/y2start journal qt -name YaST2 -icon yast                          
 7799 root      20   0  581512  23240  22344 R 98.34 0.142   3:56.82                                      `- /usr/bin/journalctl --since=2023-09-20 16:31:58 --until=2023-09-21 16:31:58 --no-pager --output=json                     
…


> You could also check how long the 'journalctl' command takes when you call
> it manually, with or without extra filter options.

Sonne:~ # XX=$(date) && time echo "$(journalctl --since today | wc -l) lines" && YY=$(date) && echo "$XX | $YY"
9457662 lines

real    15m18.590s
user    7m5.664s
sys     8m2.985s
Thu Sep 21 17:21:35 CEST 2023 | Thu Sep 21 17:36:54 CEST 2023
Comment 8 Stefan Hundhammer 2023-09-21 16:22:18 UTC
> Sonne:~ # XX=$(date) && time echo "$(journalctl --since today | wc -l)
> lines" && YY=$(date) && echo "$XX | $YY"
> 9457662 lines
> 
> real    15m18.590s
> user    7m5.664s
> sys     8m2.985s
> Thu Sep 21 17:21:35 CEST 2023 | Thu Sep 21 17:36:54 CEST 2023

That's 9.5 million lines in the journal just for today. Without that filter, it's certainly a lot more.

Since the pure 'journalctl' command alone already takes 15 minutes 18.6 seconds, it doesn't surprise me that you experience very poor performance for that YaST journal module. How long that command takes is already a lower limit. And adding that many lines to that widget in the GUI will also take some time; it's simply not made with that amount of data in mind. Frankly, I am surprised that it doesn't simply crash with an out of memory or some kind of overflow.

To make this possible, this would need a whole new interface to the journal; more RDBMS-like, and probably not using 'journalctl' as an external command because of the poor performance that we see here. But then, maybe there is a mode like "give me the first 500 or 1000 (or so) lines".

But it continues with the GUI. This would need to be written directly on the Qt level, probably in C++, using Qt's model/view classes that can make intelligent use of concepts like "fetch more" and partial display (showing only the first 500 or 1000 lines and fetching more if the user scrolls beyond those first 500 or 1000 lines).

So in short, this is not realistic on the level of such a YaST module, even if we had time to dive deep into this topic (which we don't) and didn't have any other, much more urgent tasks.

As I wrote before, this YaST journal module is intended for casual users, and for systems that have a reasonable amount of data in their journal. What you need is a power user solution for large datasets.

So sorry, I have to tell you that you reached the limits of that module. Please use either the 'journalctl' command directly, or check if there is a better solution out there that suits your needs better.

Maybe check out QJournalctl (I never used it, I have to admit). Maybe there are other similar projects that make the systemd journal better accessible with a nice GUI.

Sorry to disappoint you.
Comment 10 Markus Elfring 2023-09-22 06:52:51 UTC
(In reply to Stefan Hundhammer from comment #8)
* Can a basic input form work also without triggering a call of a program like “journalctl --output=json …” (at the beginning)?

* Will the chances grow to extend support for the cursor concept according to more desirable data analysis applications?

* Would you like to construct more advanced time series queries on demand anyhow?
Comment 11 Markus Elfring 2023-09-23 06:34:21 UTC
(In reply to Stefan Hundhammer from comment #8)
> But then, maybe there is a mode like "give me the first 500 or 1000 (or so) lines".

Please take another look also at the program parameter “--lines”.
https://www.freedesktop.org/software/systemd/man/journalctl.html#-n

It is applied by the program “KSystemlog 23.08.1” (for example).
https://apps.kde.org/de/ksystemlog/


> But it continues with the GUI. This would need to be written directly on the
> Qt level, probably in C++, using Qt's model/view classes that can make
> intelligent use of concepts like "fetch more" and partial display …

Would you like to take any more related information sources better into account?
https://api.rubyonrails.org/
Comment 12 Stefan Hundhammer 2023-09-23 11:26:15 UTC
There is a limit how much time we can spend on issues such as this. After all those lengthy explanations, I expect, no, I DEMAND that our decisions are respected. Restoring the old resolution.

Feel free to start your own Open Source project where you can implement all your ideas. Maybe there are like-minded people who wish to contribute. But don't forget the neverending maintenance work that is not only a constant drain of your time, but also on life energy.