High CPU Usage [pegs a single core] #1998

tordenflesk · 2022-04-24T21:17:39Z

Nicotine+ version: 3.2.2 (Scoop/portable)
Operating System/Distribution: Windows

High CPU usage occurs (and persists) shortly after starting Nicotine+

Additional context

Screenshots, logs, stacktraces or relevant information.
debug_1650821597.log

tordenflesk · 2022-04-24T21:20:38Z

Startup debug log
debug_1650835125.log

slook · 2022-04-25T06:06:51Z

Thanks for your logs. From having a quick glance over them:

You have a large number of items (1000+) in your Uploads list? Possibly Uploads is the active visible main tab that is open in the foreground? Edit: Actually, this bug can still present even when Nicotine+ is minimized after Uploads was the active tab.
You have [Debug] "Messages" and "Connection" log categories enabled (all the time?) with logging to file, which has a very large performance impact (and does lead to the issue with the stuck timestamps/frozen log pane).

To verify if you are being affected by the above known issues or not, you can clear your Uploads list (you could backup config/uploads.json first if you want) and disable logging. Please let us know if CPU usage returns to normal, or if there is something else consuming resources here.

tordenflesk · 2022-04-25T09:45:14Z

Nicotine+ starts minimized to my tray.
I enabled logging after first experiencing the issue.

CPU usage only appears to increase with active uploads. Setting upload slots to 3 reduces the usage to 8-10% of total CPU (4 core CPU)

slook · 2022-04-25T13:29:34Z

What is your average upload speed, and normally what number of active users do you serve at any one time?

tordenflesk · 2022-04-25T13:34:41Z

Currently, 9 users between 700KB/s and 4MB/s (occasionally 25MB/s depending on the users)
I haven't experienced this before yesterday, and I'm fairly certain nothings changed that should affect N+

slook · 2022-04-25T13:53:23Z

The only situation where I have seen a core being pegged in the way you describe, is when the Uploads history is very large and the the Uploads tab is being viewed on-screen (Edit: Actually, this bug can still present even when Nicotine+ is minimized after Uploads was the active tab.), although this seems unrelated to the problem you are experiencing.

If the issue has suddenly begun, then perhaps there is an erroneous item(s) in your Uploads history. Clearing finished transfers might remedy the problem, if you make a backup of uploads.json first that could help to narrow down the offending item.

tordenflesk · 2022-04-25T14:24:41Z

Looking at ProcMon it looks like I'm getting a lot of buffer overflows reffering to AppData\Roaming\nicotine, some related to uploads.json.
uploads.json only contains [] btw. I'm guessing it's supposed to contain more than that.
I have tried deleting that file a couple of times, but the file's recreated and the issue reappears as soon as the clients reconnect.

mathiascode · 2022-05-13T17:10:49Z

Could you test Nicotine+ 3.2.3.dev1 and see if the issue still occurs? https://github.com/nicotine-plus/nicotine-plus/blob/3.2.x/doc/TESTING.md

tordenflesk · 2022-05-13T17:41:00Z

No change
Logfile.CSV

mathiascode · 2022-05-13T19:14:45Z

I've made a change to only save the upload list to file once every minute, which should rule out any high CPU usage related to it. Try the latest build at the same link again.

slook · 2022-05-26T19:34:38Z

pegs a single core

uploads.json only contains []

The combination of these two symptoms could suggest that possibly the external module responsible for dumping data into the json file has got stuck into an endless loop.

the issue reappears as soon as the clients reconnect

Perhaps the reason why the issue is not immediately present upon startup is because there is nothing to write into uploads.json until there is an Upload item to save into it.

The OP's library versions according to log:

GTK 3.24.33
Python 3.9.10 (main, Mar 14 2022, 18:37:07) [GCC 11.2.0 64 bit (AMD64)]

Please test the latest build https://github.com/nicotine-plus/nicotine-plus/blob/3.2.x/doc/TESTING.md and post with an update if you still need this looking into @tordenflesk

tordenflesk · 2022-05-26T19:41:16Z

No change.

slook · 2022-05-27T05:22:30Z

Thanks, I have a couple of questions:

Could you confirm whether or not your list of queued and finished Uploads are forgotten upon restart of the application? I.e. upon application restart, the Uploads list is empty?
What is the contents of downloads.json when viewed in a text editor? Are your previous Downloads remembered?

Also, please provide:

Your Windows version and build

tordenflesk · 2022-05-27T11:26:24Z

Uploads is empty on restart.
downloads.json is also a 2-byte "empty" file.

Windows 7 w/ current ESU patches

slook · 2022-05-27T18:43:24Z

@tordenflesk Please can you tell us:

What is the setting of Preferences > Uploads > "Autoclear finished/cancelled uploads from transfers" checkbox (On or Off)?
Does toggling the checkbox to the opposite setting resolve the problem? (perhaps after restarting the program)
Do any "Finished" uploads appear and remain visible in the list of Uploads until the remainder of the session, or does the list only ever contain active transfers with the "Transferring" status shown in the list?

tordenflesk · 2022-05-27T22:29:43Z

It's on. toggling it with a restart made no change.
Only Transferring or queued in the list. Very occasionally will there be a few finished.

slook · 2022-05-27T22:43:15Z

@tordenflesk A promising fix for a very similar CPU thrashing issue has been pushed to the master branch. Please can you switch to Nicotine+ 3.3.0dev1 (master branch) to test it on your machine and let us know if this makes a difference for you or not, link:

https://github.com/nicotine-plus/nicotine-plus/blob/master/doc/TESTING.md#windows

By the way, I was mistaken before (see above) about how the known CPU usage bug presents itself:

Is Uploads is the active visible main tab that is open in the foreground?

Nicotine+ starts minimized to my tray.

Actually, it didn't matter if the application is hidden or was on-screen in the foreground, infact if 'Uploads' was the active (or remembered) tab then the CPU was thrashed (at 100%) during transfers on certain affected systems even when minimized, but was fine (at <5%) when another tab was selected.

That particular issue has now been resolved in master with commit 2e0fc99. Hopefully this addresses the same issue as yours (however I can see that turning Autoclear > off will fix your forgotten uploads.json history, that's unrelated to this bug anyway).

Please test Nicotine 3.3.0dev1 (not 3.2.3) at link:
https://github.com/nicotine-plus/nicotine-plus/blob/master/doc/TESTING.md#windows

tordenflesk · 2022-05-28T08:34:11Z

Yes

slook · 2022-05-28T08:39:59Z

Alright cool! @mathiascode please can you push 2e0fc99 to the 3.2.x branch to close this issue, because this is an 'Important' fix for legacy users.

Affected systems:

Linux Debian 9 Stretch LTS (Long-Term Support)
Windows 7 SP1 ESU (Extended Service Updates)

.

@tordenflesk Thank you for this bug report.

mathiascode · 2022-05-28T11:55:34Z

I'm a bit skeptical about 2e0fc99 actually fixing the issue, and not some other commit present in master. I've cherry-picked the commit to the 3.2.x, can you compare the master and 3.2.x branches and confirm that it's actually fixed in 3.2.3rc1?

3.2.3rc1: https://nicotine-plus.org/doc/TESTING.html
3.3.0.dev1: https://github.com/nicotine-plus/nicotine-plus/blob/master/doc/TESTING.md

tordenflesk · 2022-05-28T12:11:55Z

Rc1: Not fixed
Dev1: Fixed

slook · 2022-05-28T13:58:44Z

My mistake, sorry I hadn't realized any specific effort had been put in so I have avoided the Uploads tab without testing it for a while.

mathiascode · 2022-05-28T14:11:19Z

I believe the issue was originally fixed in f1930fa for master. ee6fa92 should do the same for 3.2.x.

@tordenflesk A new 3.2.3rc1 build should be ready in about 15 minutes. Could you test it and check if the issue is fixed?

From the GTK docs: "Columns resize to be the optimal size everytime the model changes. Please note that Gtk.TreeViewColumnSizing.AUTOSIZE are inefficient for large views, and can make columns appear choppy."

slook · 2022-05-29T08:24:14Z

should do the same for 3.2.x

It does fix the issue in Nicotine+ 3.2.3rc1 on Linux Debian 9 Stretch LTS with Python 3.5 and GTK 3.22.11

@tordenflesk How is it now in the latest 3.2.3rc1 build on your Windows machine? https://nicotine-plus.org/doc/TESTING

tordenflesk · 2022-05-29T08:33:22Z

Seems fine now.

slook · 2022-05-29T11:10:34Z

Thanks for your help @tordenflesk :) if you notice any further issues please let us know!

TL'DR: it didn't matter if the application is hidden or was on-screen in the foreground, infact if 'Uploads' was the active (or remembered) tab then the CPU was thrashed (pegged at 100%) during transfers on certain affected systems even when minimized, but was fine (at <5%) when another tab was selected.

Affected systems (confirmed):

Linux Debian 9 Stretch LTS (Long-Term Support) with Python 3.5 and GTK 3.22.11 (Autoclear Off)
Windows 7 SP1 ESU (Extended Service Updates) with Python 3.9 and GTK 3.24.33 (Autoclear On)
(maybe others)

FIXED in Nicotine+ 3.2.3

tordenflesk · 2022-08-05T17:40:34Z

Updated to 3.2.3, and this issue(or similar) seems to have returned.
Downloads tab selected ~2% CPU
Uploads tab selected 8-16% CPU
A dozen active Uploads.

mathiascode · 2022-08-05T23:05:43Z

Can you check if it's any better in 3.2.4rc1? https://github.com/nicotine-plus/nicotine-plus/blob/3.2.x/doc/TESTING.md

mathiascode · 2022-08-06T00:30:58Z

A new build with more improvements should be available at the link above in about 20 minutes.

tordenflesk · 2022-08-06T07:43:10Z

Working well now

tordenflesk added the bug label Apr 24, 2022

slook referenced this issue May 27, 2022

transfers.py: save transfers to file every one minute

10d5713

slook referenced this issue May 28, 2022

transfers.py: remove redundant code

2e0fc99

slook referenced this issue May 28, 2022

treeview.py: simplify width handling

f1930fa

slook closed this as completed May 29, 2022

mathiascode reopened this Aug 5, 2022

mathiascode closed this as completed Aug 6, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

High CPU Usage [pegs a single core] #1998

High CPU Usage [pegs a single core] #1998

tordenflesk commented Apr 24, 2022

tordenflesk commented Apr 24, 2022

slook commented Apr 25, 2022 •

edited

tordenflesk commented Apr 25, 2022

slook commented Apr 25, 2022 •

edited

tordenflesk commented Apr 25, 2022

slook commented Apr 25, 2022 •

edited

tordenflesk commented Apr 25, 2022 •

edited

mathiascode commented May 13, 2022

tordenflesk commented May 13, 2022 •

edited

mathiascode commented May 13, 2022

slook commented May 26, 2022 •

edited

tordenflesk commented May 26, 2022

slook commented May 27, 2022 •

edited

tordenflesk commented May 27, 2022

slook commented May 27, 2022 •

edited

tordenflesk commented May 27, 2022

slook commented May 27, 2022 •

edited

tordenflesk commented May 28, 2022

slook commented May 28, 2022 •

edited

mathiascode commented May 28, 2022

tordenflesk commented May 28, 2022 •

edited

slook commented May 28, 2022 •

edited

mathiascode commented May 28, 2022

slook commented May 29, 2022

tordenflesk commented May 29, 2022

slook commented May 29, 2022 •

edited

tordenflesk commented Aug 5, 2022

mathiascode commented Aug 5, 2022

mathiascode commented Aug 6, 2022

tordenflesk commented Aug 6, 2022

High CPU Usage [pegs a single core] #1998

High CPU Usage [pegs a single core] #1998

Comments

tordenflesk commented Apr 24, 2022

Additional context

tordenflesk commented Apr 24, 2022

slook commented Apr 25, 2022 • edited

tordenflesk commented Apr 25, 2022

slook commented Apr 25, 2022 • edited

tordenflesk commented Apr 25, 2022

slook commented Apr 25, 2022 • edited

tordenflesk commented Apr 25, 2022 • edited

mathiascode commented May 13, 2022

tordenflesk commented May 13, 2022 • edited

mathiascode commented May 13, 2022

slook commented May 26, 2022 • edited

tordenflesk commented May 26, 2022

slook commented May 27, 2022 • edited

tordenflesk commented May 27, 2022

slook commented May 27, 2022 • edited

tordenflesk commented May 27, 2022

slook commented May 27, 2022 • edited

tordenflesk commented May 28, 2022

slook commented May 28, 2022 • edited

mathiascode commented May 28, 2022

tordenflesk commented May 28, 2022 • edited

slook commented May 28, 2022 • edited

mathiascode commented May 28, 2022

slook commented May 29, 2022

tordenflesk commented May 29, 2022

slook commented May 29, 2022 • edited

tordenflesk commented Aug 5, 2022

mathiascode commented Aug 5, 2022

mathiascode commented Aug 6, 2022

tordenflesk commented Aug 6, 2022

slook commented Apr 25, 2022 •

edited

slook commented Apr 25, 2022 •

edited

slook commented Apr 25, 2022 •

edited

tordenflesk commented Apr 25, 2022 •

edited

tordenflesk commented May 13, 2022 •

edited

slook commented May 26, 2022 •

edited

slook commented May 27, 2022 •

edited

slook commented May 27, 2022 •

edited

slook commented May 27, 2022 •

edited

slook commented May 28, 2022 •

edited

tordenflesk commented May 28, 2022 •

edited

slook commented May 28, 2022 •

edited

slook commented May 29, 2022 •

edited