Bug#1065072: packagekit spinning cpu

2024-03-09 Thread Joey Hess
Matthias Klumpp wrote:
> either GNOME Software is wrong (I think it unconditionally has a
> problem, it should never retry a cache refresh at that insane
> frequency), or the APT backend in PackageKit does something wrong and
> emits package changes for blocked packages when it shouldn't do so.
> I guess as soon as your system is up-to-date (with no blocked
> packages), this issue will go away temporarily.

Is there anything I can do while I seem to be able to reproduce this
pretty easily?

-- 
see shy jo


signature.asc
Description: PGP signature


Bug#1065072: packagekit spinning cpu

2024-03-08 Thread Matthias Klumpp
Am Sa., 9. März 2024 um 07:30 Uhr schrieb Joey Hess :
>
> Joey Hess wrote:
> > It may also be relevant somehow that the topmost update was a thinkpad
> > AMD firmware update which "requires restart".
>
> I masked and stopped packagekit again and now in gnome-software, it
> displays only the thinkpad amd firmware update, and it's no longer
> alternating with the loading updates screen.
> This makes me think that firmware update is not related to the problem.
>
> The other updates gnome-software displays when packagekit is running are
> debian package updates. My last upgrade was an apt-get safe-upgrade,
> because dist-upgrade wants to remove several packages, including gnome.
> (I'm tracking unstable, this is typical transient dependency issues I
> suppose. Also I have bluez on hold at an older version due to #1060224)
>
> So maybe gnome-software gets confused in this kind of situation and keeps
> retrying?

That is the current hypothesis, yes - the change that broke this was
introduced by Fedora, and they do not observe this behavior. So,
either GNOME Software is wrong (I think it unconditionally has a
problem, it should never retry a cache refresh at that insane
frequency), or the APT backend in PackageKit does something wrong and
emits package changes for blocked packages when it shouldn't do so.
I guess as soon as your system is up-to-date (with no blocked
packages), this issue will go away temporarily.

TBH, at this point I think there's probably a bug in GS as well as in
PK-Apt, but we haven't found the culprit yet (except for the GS patch
that caused this issue to appear,
https://gitlab.gnome.org/GNOME/gnome-software/-/commit/b8cf52e9c001064eebfe86ce801541ca211e
)

Cheers,
Matthias

-- 
I welcome VSRE emails. See http://vsre.info/



Bug#1065072: packagekit spinning cpu

2024-03-08 Thread Joey Hess
Joey Hess wrote:
> It may also be relevant somehow that the topmost update was a thinkpad
> AMD firmware update which "requires restart". 

I masked and stopped packagekit again and now in gnome-software, it
displays only the thinkpad amd firmware update, and it's no longer
alternating with the loading updates screen. 
This makes me think that firmware update is not related to the problem.

The other updates gnome-software displays when packagekit is running are
debian package updates. My last upgrade was an apt-get safe-upgrade,
because dist-upgrade wants to remove several packages, including gnome.
(I'm tracking unstable, this is typical transient dependency issues I
suppose. Also I have bluez on hold at an older version due to #1060224)

So maybe gnome-software gets confused in this kind of situation and keeps
retrying?

-- 
see shy jo


signature.asc
Description: PGP signature


Bug#1065072: packagekit spinning cpu

2024-03-08 Thread Joey Hess
Below is a pkmon while the problem is occurring.

Since it points at gnome-software causing the activity, I tried opening
that. I noticed that the updates tab had an indicator that there were
updates. Switching to it, I saw it continuously alternate between
"Loading updates" with a spinner and a list of updates.  Each transition
back to "Loading updates" corresponds to more pkmon activity.

It may also be relevant somehow that the topmost update was a thinkpad
AMD firmware update which "requires restart". 

Transactions:
 [none]
daemon connected=1
network status=online
Transactions:
 1  /15795_aacdccdd
/15795_aacdccdd allow_cancel 1
/15795_aacdccdd percentage   -1
/15795_aacdccdd role get-updates
/15795_aacdccdd sender   /usr/bin/gnome-software
/15795_aacdccdd status   setup

(pkmon:3985472): GLib-GIO-CRITICAL **: 02:02:25.371: GTask 0x556f0677f540 
(source object: 0x556f0677c360, source tag: 0x7f08eae881c0) finalized without 
ever returning (using g_task_return_*()). This potentially indicates a bug in 
the program.
Transactions:
 1  /15795_aacdccdd
 2  /15796_cadeddaa
/15796_cadeddaa allow_cancel 1
/15796_cadeddaa percentage   -1
/15796_cadeddaa role get-updates
/15796_cadeddaa sender   /usr/bin/gnome-software
/15796_cadeddaa status   wait

(pkmon:3985472): GLib-GIO-CRITICAL **: 02:02:25.442: GTask 0x556f06783290 
(source object: 0x556f0677c360, source tag: 0x7f08eae881c0) finalized without 
ever returning (using g_task_return_*()). This potentially indicates a bug in 
the program.
Transactions:
 1  /15796_cadeddaa
Transactions:
 [none]
Transactions:
 1  /15797_cbbadaab
Transactions:
 1  /15797_cbbadaab
 2  /15798_ceeaaabb
/15797_cbbadaab allow_cancel 1
/15797_cbbadaab percentage   -1
/15797_cbbadaab role get-details
/15797_cbbadaab sender   /usr/bin/gnome-software
/15797_cbbadaab status   setup

(pkmon:3985472): GLib-GIO-CRITICAL **: 02:02:27.100: GTask 0x556f06783390 
(source object: 0x556f0677c360, source tag: 0x7f08eae881c0) finalized without 
ever returning (using g_task_return_*()). This potentially indicates a bug in 
the program.
/15798_ceeaaabb allow_cancel 1
/15798_ceeaaabb percentage   -1
/15798_ceeaaabb role get-updates
/15798_ceeaaabb sender   /usr/bin/gnome-software
/15798_ceeaaabb status   wait

(pkmon:3985472): GLib-GIO-CRITICAL **: 02:02:27.100: GTask 0x556f06784f30 
(source object: 0x556f0677c360, source tag: 0x7f08eae881c0) finalized without 
ever returning (using g_task_return_*()). This potentially indicates a bug in 
the program.
Transactions:
 1  /15798_ceeaaabb
Transactions:
 [none]
Transactions:
 1  /15799_eebaebcb
/15799_eebaebcb allow_cancel 1
/15799_eebaebcb percentage   -1
/15799_eebaebcb role get-updates
/15799_eebaebcb sender   /usr/bin/gnome-software
/15799_eebaebcb status   setup

(pkmon:3985472): GLib-GIO-CRITICAL **: 02:02:31.374: GTask 0x556f06788660 
(source object: 0x556f0677c360, source tag: 0x7f08eae881c0) finalized without 
ever returning (using g_task_return_*()). This potentially indicates a bug in 
the program.
Transactions:
 1  /15799_eebaebcb
 2  /15800_caeadeca
/15800_caeadeca allow_cancel 1
/15800_caeadeca percentage   -1
/15800_caeadeca role get-updates
/15800_caeadeca sender   /usr/bin/gnome-software
/15800_caeadeca status   wait

(pkmon:3985472): GLib-GIO-CRITICAL **: 02:02:31.448: GTask 0x556f06783f90 
(source object: 0x556f0677c360, source tag: 0x7f08eae881c0) finalized without 
ever returning (using g_task_return_*()). This potentially indicates a bug in 
the program.
Transactions:
 1  /15800_caeadeca
Transactions:
 [none]
Transactions:
 1  /15801_dceaeeeb
Transactions:
 1  /15801_dceaeeeb
 2  /15802_cbacedec
/15801_dceaeeeb allow_cancel 1
/15801_dceaeeeb percentage   -1
/15801_dceaeeeb role get-details
/15801_dceaeeeb sender   /usr/bin/gnome-software
/15801_dceaeeeb status   setup

(pkmon:3985472): GLib-GIO-CRITICAL **: 02:02:33.169: GTask 0x556f0677ee00 
(source object: 0x556f0677c360, source tag: 0x7f08eae881c0) finalized without 
ever returning (using g_task_return_*()). This potentially indicates a bug in 
the program.
/15802_cbacedec allow_cancel 1
/15802_cbacedec percentage   -1
/15802_cbacedec role get-updates
/15802_cbacedec sender   /usr/bin/gnome-software
/15802_cbacedec status   wait

(pkmon:3985472): GLib-GIO-CRITICAL **: 02:02:33.170: GTask 0x556f06788750 
(source object: 0x556f0677c360, source tag: 0x7f08eae881c0) finalized without 
ever returning (using g_task_return_*()). This potentially indicates a bug in 
the program.
Transactions:
 1  /15802_cbacedec
Transactions:
 [none]
Transactions:
 1  /15803_ecbdcdcd
/15803_ecbdcdcd allow_cancel 1
/15803_ecbdcdcd percentage   -1
/15803_ecbdcdcd role get-updates
/15803_ecbdcdcd sender   /usr/bin/gnome-software
/15803_ecbdcdcd status   setup

(pkmon:3985472): GLib-GIO-CRITICAL **: 

Bug#1065072: packagekit spinning cpu

2024-03-08 Thread Matthias Klumpp
Hi!

Am Sa., 9. März 2024 um 04:09 Uhr schrieb Joey Hess :
>
> I'm confident I saw this same problem today, with packagekit repeatedly
> updating and spinning a CPU for 10 minutes. It only stopped at that
> point because I stopped and masked it. (Stopping it was not enough,
> something was restarting the service every time I stopped it.) See
> attached log.
>
> I did not capture the trigger for that pkmon, but just before it started I
> had used window+s in gnome and typed in "paperwm", before remembering that
> doesn't find anything and pressing escape.
>
> When I repeat that with pkmon open, I see it does trigger packagekit:
>
> root@darkstar:/home/joey>pkmon
> Transactions:
>  [none]
> daemon connected=1
> network status=online
> Transactions:
>  1  /14317_cdeeebeb
> /14317_cdeeebeb allow_cancel 1
> /14317_cdeeebeb percentage   -1
> /14317_cdeeebeb role resolve
> /14317_cdeeebeb sender   /usr/bin/gnome-software
> /14317_cdeeebeb status   setup

Unfortunately there isn't much we can do - this is GNOME Software
polling PackageKit again and again, and other than adding more rate
limitations, we can't fix that in PK and PK is behaving correctly.
The real solution would be to make the tool that is causing this stop
its behavior and not ask PackageKit to update the cache every second.

I reassigned it to GS, which already had a bug describing this issue exactly.

Cheers,
Matthias

-- 
I welcome VSRE emails. See http://vsre.info/



Bug#1065072: packagekit spinning cpu

2024-03-08 Thread Joey Hess
I'm confident I saw this same problem today, with packagekit repeatedly
updating and spinning a CPU for 10 minutes. It only stopped at that
point because I stopped and masked it. (Stopping it was not enough,
something was restarting the service every time I stopped it.) See
attached log.

I did not capture the trigger for that pkmon, but just before it started I
had used window+s in gnome and typed in "paperwm", before remembering that
doesn't find anything and pressing escape. 

When I repeat that with pkmon open, I see it does trigger packagekit:

root@darkstar:/home/joey>pkmon
Transactions:
 [none]
daemon connected=1
network status=online
Transactions:
 1  /14317_cdeeebeb
/14317_cdeeebeb allow_cancel 1
/14317_cdeeebeb percentage   -1
/14317_cdeeebeb role resolve
/14317_cdeeebeb sender   /usr/bin/gnome-software
/14317_cdeeebeb status   setup

(pkmon:3940508): GLib-GIO-CRITICAL **: 22:40:26.794: GTask 0x5621e2846510 
(source object: 0x5621e2843330, source tag: 0x7fc2bdc121c0) finalized without 
ever returning (using g_task_return_*()). This potentially indicates a bug in 
the program.
Transactions:
 [none]

I found similar bug reports filed on fedora, upstream, etc. Going back years.

Also looking back through the journal, it's been doing this on my system
for months, every week or two, generally with only a few minutes cpu
time wasted per indicent.

Also, I notice that when packagekit is masked, it makes apt-get update display
a message to that effect. Since this bug makes masking packagekit very
appealing, that is not very nice either.

-- 
see shy jo


log.gz
Description: application/gzip


signature.asc
Description: PGP signature