Wrong processes monitoring

[podhorsky-ksj]

Explain what happens

Cockpit shows different processes than top. E.g.:
cockpit shows:

top shows:

gitea is ok, but journalctl is not sshd.

It is not the first time I have seen it. Sometimes cockpit doesn't show the high cpu process at all. From where are you taking the processes info?

Version of Cockpit

315

Where is the problem in Cockpit?

Overview

Server operating system

Arch Linux

Server operating system version

latest

What browsers are you using?

Other

System log

No response

[jelly]

We use cgroups for measuring CPU usage of processes, are you executing journalctl in an ssh session? That might explain it?

[podhorsky-ksj]

yes, for connection to server, I'm using ssh. but this is not only one case, only the latest. Sometimes the cpu is very high in top, but the cockpit shows no process with higher cpu than 1%. I have noticed these behavior a lot of times.

[podhorsky-ksj]

It is still the same:

Cpu is running on full capacity, but no process with huge load is visible. Will there be some fix for this?

[martinpitt]

Note that these are services, not processes. But if that journalctl is running in your user session, the corresponding cgroup/systemd service shuold be something like user@1000.service. In such a case, can you please check systemctl status PID or systemctl --user status PID with a PID of the CPU-hungry process? That should tell you the cgroup/service it's running in. Thanks!

[podhorsky-ksj]

In this case the journalctl processes was run directly by cockpit. I was logged in as user and tried to reproduce issue with web logs #20355 and cockpit started a lot of processes, what I understand is error.

I don't know If I should create separate ticket for that.

I'm not sure how cockpit run these processes, if they are under cockpit or disowned, that should be in code of cockpit.

[jelly]

Leftover journalctl's seems bad, if we can reproduce this we should the leftover processes.

[jelly]

I can't reproduce the journalctl issue here, can you post the full output of ps aux | grep journalctl so we can see with what arguments journalctl is spawned.

[podhorsky-ksj]

Here it is:

ksj        28118 16.7  0.6 883856 50468 ?        R    12:55   0:14 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28133  0.0  0.0  10372  5432 ?        S    12:55   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28135 13.7  0.5 883856 46904 ?        R    12:55   0:11 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28138  0.0  0.0  10372  5456 ?        S    12:55   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28140 13.8  0.5 883856 46888 ?        R    12:55   0:11 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28165  0.0  0.0  10372  5472 ?        S    12:55   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28167 10.2  0.5 883856 43700 ?        R    12:55   0:07 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28170  0.0  0.0  10372  5408 ?        S    12:55   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28172  0.0  0.0  10372  5348 ?        S    12:55   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28173 10.3  0.5 883856 43784 ?        R    12:55   0:07 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28177  9.8  0.5 883856 43680 ?        R    12:55   0:07 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28201  0.0  0.0  10372  5344 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28203  9.4  0.5 883856 43060 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28206  0.0  0.0  10372  5428 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28208  9.5  0.5 883856 43040 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28211  0.0  0.0  10372  5440 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28213  9.4  0.5 883856 42912 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28216  0.0  0.0  10372  5500 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28218  9.5  0.5 883856 43040 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28222  0.0  0.0  10372  5336 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28224  9.6  1.0 883540 87264 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --priority=notice --reverse --
ksj        28227  0.0  0.0  10372  5452 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28229  9.5  1.0 883540 87376 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --priority=notice --reverse --
ksj        28232  0.0  0.0  10372  5412 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28234  9.4  1.0 883540 87256 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --priority=notice --reverse --
ksj        28237  0.0  0.0  10372  5284 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28239  9.2  1.0 883540 87016 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --priority=notice --reverse --
ksj        28242  0.0  0.0  10372  5304 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28244  9.3  1.0 883540 86712 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --priority=notice --reverse --
ksj        28274  0.0  0.0  10372  5332 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28276  9.0  0.5 883856 42288 ?        R    12:56   0:05 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28279  0.0  0.0  10372  5344 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28281  9.2  0.5 883856 42548 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28284  0.0  0.0  10372  5492 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28286  9.3  0.5 883856 42556 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28289  0.0  0.0  10372  5404 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28291  9.1  0.5 883856 42140 ?        R    12:56   0:06 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28332  0.0  0.0  10372  5396 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28334  8.8  1.0 883540 83576 ?        R    12:56   0:05 journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse --
ksj        28337  0.0  0.0  10372  5436 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28340  8.4  1.0 883540 82740 ?        R    12:56   0:05 journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse --
ksj        28344  0.0  0.0  10372  5292 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28346  0.0  0.0  10372  5384 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28347  8.6  1.0 883540 83256 ?        R    12:56   0:05 journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse --
ksj        28351  8.5  1.0 883540 83184 ?        R    12:56   0:05 journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse --
ksj        28354  0.0  0.0  10372  5392 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28356  8.9  1.0 883540 83764 ?        R    12:56   0:05 journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse --
ksj        28359  0.0  0.0  10372  5164 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28361  8.8  1.0 883540 83020 ?        R    12:56   0:05 journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse --
ksj        28479  0.0  0.0  10372  5452 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28481  8.7  0.5 875664 41368 ?        R    12:56   0:04 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28485  0.0  0.0  10372  5468 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28486  8.7  0.5 875664 41248 ?        R    12:56   0:04 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28490  0.0  0.0  10372  5444 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28492  8.6  0.5 875664 41356 ?        R    12:56   0:04 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28495  0.0  0.0  10372  5492 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-24hours --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28497  8.5  0.5 875664 41240 ?        R    12:56   0:04 journalctl -q --no-tail --output=verbose --since=-24hours --reverse --
ksj        28505  0.0  0.0  10372  5412 ?        S    12:56   0:00 /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-7days --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
ksj        28507  8.5  0.5 875664 41096 ?        R    12:56   0:04 journalctl -q --no-tail --output=verbose --since=-7days --reverse --
ksj        28549  0.0  0.6 891732 50392 ?        S    12:56   0:00 journalctl -q --no-tail --output=json --cursor=s=0dcef4ab9d7d430a930778d97414b736;i=b196d3;b=6edda4d294404d77a6dadf9258935670;m=3c2f5c562;t=6173a1adfc7d9;x=2cc57257a0622f11 --priority=err --follow --
ksj        28550  0.0  0.6 891732 50364 ?        S    12:56   0:00 journalctl -q --no-tail --output=json --cursor=s=0dcef4ab9d7d430a930778d97414b736;i=b196d3;b=6edda4d294404d77a6dadf9258935670;m=3c2f5c562;t=6173a1adfc7d9;x=2cc57257a0622f11 --priority=err --follow --
ksj        28565  0.0  0.0   9460  4164 pts/0    S+   12:57   0:00 grep --color=auto journalctl

It is easy to reproduce. Just run it under cockpit under user (i don't know if that is necessary), user has journalctl priviledges, and play with the log settings in cockpit, scroll, show detail log etc. On my server (intel i5 notebook) it will do this.

[jelly]

I can't reproduce this. Does journalctl hang when you run this as user?

/bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u

In what groups is your user?

[podhorsky-ksj]

Nope. It takes few seconds:

[ksj@server-ksj ~]$ /bin/bash -ec set -o pipefail; journalctl -q --no-tail --output=verbose --since=-7days --priority=notice --reverse -- | grep SYSLOG_IDENTIFIER= | sort -u
BASH=/bin/bash
BASHOPTS=checkwinsize:cmdhist:complete_fullquote:extquote:force_fignore:globasciiranges:globskipdots:hostcomplete:interactive_comments:patsub_replacement:progcomp:promptvars:sourcepath
BASH_ALIASES=()
BASH_ARGC=()
BASH_ARGV=()
BASH_CMDS=()
BASH_EXECUTION_STRING=set
BASH_LINENO=()
BASH_LOADABLES_PATH=/usr/local/lib/bash:/usr/lib/bash:/opt/local/lib/bash:/usr/pkg/lib/bash:/opt/pkg/lib/bash:.
BASH_SOURCE=()
BASH_VERSINFO=([0]="5" [1]="2" [2]="26" [3]="1" [4]="release" [5]="x86_64-pc-linux-gnu")
BASH_VERSION='5.2.26(1)-release'
COCKPIT_REMOTE_PEER=::1
DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
DIRSTACK=()
EUID=1000
GROUPS=()
HOME=/home/ksj
HOSTNAME=server-ksj
HOSTTYPE=x86_64
IFS=$' \t\n'
LC_CTYPE=C.UTF-8
MACHTYPE=x86_64-pc-linux-gnu
MAIL=/var/spool/mail/ksj
MOTD_SHOWN=pam
OPTERR=1
OPTIND=1
OSTYPE=linux-gnu
PATH=/usr/local/sbin:/usr/local/bin:/usr/bin
PPID=14106
PS4='+ '
PWD=/home/ksj
SHELL=/usr/bin/bash
SHELLOPTS=braceexpand:errexit:hashall:interactive-comments
SHLVL=2
SSH_AUTH_SOCK=/tmp/ssh-XXXXXXenXNtH/agent.13976
TERM=xterm-256color
UID=1000
USER=ksj
XDG_RUNTIME_DIR=/run/user/1000
XDG_SESSION_CLASS=user
XDG_SESSION_ID=3
XDG_SESSION_TYPE=web
_=/bin/bash


    SYSLOG_IDENTIFIER=(jellyfin)
    SYSLOG_IDENTIFIER=(sd-pam)
    SYSLOG_IDENTIFIER=(systemd)
    SYSLOG_IDENTIFIER=PackageKit
    SYSLOG_IDENTIFIER=agetty
    SYSLOG_IDENTIFIER=backup.bash
    SYSLOG_IDENTIFIER=cockpit-session
    SYSLOG_IDENTIFIER=dbus-broker-launch
    SYSLOG_IDENTIFIER=kernel
    SYSLOG_IDENTIFIER=ntpd
    SYSLOG_IDENTIFIER=polkitd
    SYSLOG_IDENTIFIER=sshd
    SYSLOG_IDENTIFIER=su
    SYSLOG_IDENTIFIER=systemd
    SYSLOG_IDENTIFIER=systemd-logind
    SYSLOG_IDENTIFIER=systemd-modules-load
    SYSLOG_IDENTIFIER=systemd-resolved
    SYSLOG_IDENTIFIER=unix_chkpwd
[ksj@server-ksj ~]$

I'm putting all users on server to minimal privileges, it is not even in wheel, just systemd-journal:

[ksj@server-ksj ~]$ groups ksj
systemd-journal ksj