I’m trying to figure out why my CPU throttles well below it’s base frequency.
(I do understand that CPU’s will intentionally under-clock when there not needed or are hot. This is not what is happening.)
I looked at my journactl and dmesg entries exactly when it’s down-clocking but can’t see anything obvious is there somewhere else I can look?
Any help would be really appreciated.
You’ll need to increase the kernel logging level. I think this post describes the procedure well:
Looking through the logs now, just thought I’d show a screenshot of what I’m dealing with. Videos play smoothly using 30% - 80% CPU then inevitably the clock speed drops to around 798MHz and CPU usage goes to 100% and `video plays at about 2 frames a second.
Edit: The video is set to 1080P@30FPS not 4K@60FPS. The same thing happens on 720P though, it will run it smoothly well below 100% CPU then the frequency drop to 798MHz and it’s plays at maybe 5 frames a second.
It drops to 798MHz at approximately 12:03PM , this is the journalctl output for that period with log level 6:
– Logs begin at Mon 2020-04-20 11:53:11 NZST, end at Mon 2020-04-20 12:25:04 NZST. –
Apr 20 11:53:11 ampc systemd-journald[267]: System Journal (/var/log/journal/b845227a28174483b52808f10227c8a3) is 32.0M, max 4.0G, 3.9G free.
Apr 20 11:53:20 ampc chromium.desktop[3516]: [3516:3516:0420/115320.057150:ERROR:gl_surface_presentation_helper.cc(259)] GetVSyncParametersIfAvailable() failed for 5 times!
Apr 20 11:53:20 ampc chromium.desktop[3516]: [3516:3516:0420/115320.071786:ERROR:gl_surface_presentation_helper.cc(259)] GetVSyncParametersIfAvailable() failed for 6 times!
Apr 20 12:03:19 ampc dbus-daemon[743]: [session uid=1000 pid=743] Activating via systemd: service name=‘org.freedesktop.Tracker1’ unit=‘tracker-store.service’ requested by ‘:1.55’ (uid=1000 pid=947 comm=“/usr/lib/tracker-miner-fs “)
Apr 20 12:03:19 ampc systemd[725]: Starting Tracker metadata database store and lookup manager…
Apr 20 12:03:19 ampc dbus-daemon[743]: [session uid=1000 pid=743] Successfully activated service ‘org.freedesktop.Tracker1’
Apr 20 12:03:19 ampc systemd[725]: Started Tracker metadata database store and lookup manager.
Apr 20 12:03:20 ampc dbus-daemon[743]: [session uid=1000 pid=743] Activating via systemd: service name=‘org.freedesktop.Tracker1.Miner.Extract’ unit=‘tracker-extract.service’ requested by ‘:1.55’ (uid=1000 pid=947 comm=”/usr/lib/tracker-miner-fs “)
Apr 20 12:03:20 ampc systemd[725]: Starting Tracker metadata extractor…
Apr 20 12:03:20 ampc tracker-extract[6363]: Set scheduler policy to SCHED_IDLE
Apr 20 12:03:20 ampc tracker-extract[6363]: Setting priority nice level to 19
Apr 20 12:03:21 ampc dbus-daemon[743]: [session uid=1000 pid=743] Successfully activated service ‘org.freedesktop.Tracker1.Miner.Extract’
Apr 20 12:03:21 ampc systemd[725]: Started Tracker metadata extractor.
Apr 20 12:03:21 ampc dbus-daemon[743]: [session uid=1000 pid=743] Activating via systemd: service name=‘org.gtk.vfs.Metadata’ unit=‘gvfs-metadata.service’ requested by ‘:1.127’ (uid=1000 pid=6363 comm=”/usr/lib/tracker-extract “)
Apr 20 12:03:21 ampc systemd[725]: Starting Virtual filesystem metadata service…
Apr 20 12:03:21 ampc dbus-daemon[743]: [session uid=1000 pid=743] Successfully activated service ‘org.gtk.vfs.Metadata’
Apr 20 12:03:21 ampc systemd[725]: Started Virtual filesystem metadata service.
Apr 20 12:03:32 ampc systemd[725]: tracker-extract.service: Succeeded.
Apr 20 12:03:52 ampc tracker-store[6352]: OK
Apr 20 12:03:52 ampc systemd[725]: tracker-store.service: Succeeded.
Apr 20 12:03:53 ampc dbus-daemon[743]: [session uid=1000 pid=743] Activating via systemd: service name=‘org.freedesktop.Tracker1’ unit=‘tracker-store.service’ requested by ‘:1.55’ (uid=1000 pid=947 comm=”/usr/lib/tracker-miner-fs “)
Apr 20 12:03:53 ampc systemd[725]: Starting Tracker metadata database store and lookup manager…
Apr 20 12:03:53 ampc dbus-daemon[743]: [session uid=1000 pid=743] Successfully activated service ‘org.freedesktop.Tracker1’
Apr 20 12:03:53 ampc systemd[725]: Started Tracker metadata database store and lookup manager.
Apr 20 12:03:54 ampc dbus-daemon[743]: [session uid=1000 pid=743] Activating via systemd: service name=‘org.freedesktop.Tracker1.Miner.Extract’ unit=‘tracker-extract.service’ requested by ‘:1.55’ (uid=1000 pid=947 comm=”/usr/lib/tracker-miner-fs “)
Apr 20 12:03:54 ampc systemd[725]: Starting Tracker metadata extractor…
Apr 20 12:03:54 ampc tracker-extract[6523]: Set scheduler policy to SCHED_IDLE
Apr 20 12:03:54 ampc tracker-extract[6523]: Setting priority nice level to 19
Apr 20 12:03:55 ampc dbus-daemon[743]: [session uid=1000 pid=743] Successfully activated service ‘org.freedesktop.Tracker1.Miner.Extract’
Apr 20 12:03:55 ampc systemd[725]: Started Tracker metadata extractor.
Apr 20 12:04:06 ampc systemd[725]: tracker-extract.service: Succeeded.
Apr 20 12:04:23 ampc su[1232]: pam_unix(su:session): session closed for user root
Apr 20 12:04:23 ampc audit[1232]: USER_END pid=1232 uid=1000 auid=1000 ses=3 msg='op=PAM:session_close grantors=pam_unix acct=“root” exe=”/usr/bin/su” hostname=ampc addr=? terminal=pts/0 res=success’
Apr 20 12:04:23 ampc audit[1232]: CRED_DISP pid=1232 uid=1000 auid=1000 ses=3 msg=‘op=PAM:setcred grantors=pam_unix acct=“root” exe=“/usr/bin/su” hostname=ampc addr=? terminal=pts/0 res=success’
Apr 20 12:04:25 ampc systemd[725]: vte-spawn-d0deb716-4350-4d1c-a556-31645ed59d34.scope: Succeeded.
Apr 20 12:04:26 ampc tracker-store[6512]: OK
Apr 20 12:04:26 ampc systemd[725]: tracker-store.service: Succeeded.
Apr 20 12:04:43 ampc systemd[725]: vte-spawn-b803e46c-c71b-4f5b-8db9-d40cada08960.scope: Succeeded.
Apr 20 12:05:15 ampc systemd[725]: gnome-launched-chromium.desktop-3485.scope: Succeeded.
Apr 20 12:05:20 ampc systemd[725]: Started VTE child process 6798 launched by gnome-terminal-server process 1215.
