Universalmediaserver: High CPU Usage when Idle

[purevertigo]

CPU Usage is 20% when the app is sitting idle and doing nothing.

Logs here.

https://gist.github.com/purevertigo/3807e396471269f61626d25ef3b3c445

thanks

[valib]

@purevertigo your log is not useful. We need to run the UMS in the TRACE mode. See

How to contribute

In order to help diagnose and fix your issue we often need your "debug information". It's easy to save this information and attach it to a GitHub issue:

• Start UMS.
• Go to the Logs tab.
• Press the Create TRACE logs button which restarts UMS in the "TRACE" mode. If that doesn't work for some reason, either select Trace from the Log Level dropdown at the bottom or set log_level = TRACE in the configuration file and restart UMS manually.
• Reproduce the problem.
• Click Pack debug files on the lower left.
• Click Zip selected files.
• Save the zip file to a location you will remember.
• Attach the zip file to the GitHub issue.

[IntelliMoo]

Also constant network traffic while idle, with a great amount of ports open and closed to itself.

[valib]

@IntelliMoo there must be the network traffic while idle because of DLNA and UPnP specifications. All UPnP devices must send the multicast "ALIVE" message to inform other devices that their are still at the network and running. Other devices than response they received that message. @SubJunk the question is if we still need such agressive implementation and not use the DLNA or UPnP recommendation.

[SubJunk]

From memory, our rate of broadcasting ALIVE messages isn't more than what DLNA say to do. AFAIK they say to do it at random intervals between 5 and 30 seconds or something like that. I may be remembering it wrong though. I compared our main competitors using Wireshark once and they all broadcast as much or more than we do

If a program sending 64 or so bytes every 10-30 seconds is a problem for bandwidth, then the network certainly isn't fast enough to run this program in the first place. Consider that our avatars on this GitHub page are like 3-4 KB, so that's 64 ALIVE messages just for a tiny image. Consider a real full-sized image you would display on a TV then you're talking megabytes, and for videos usually hundreds of megabytes or several gigabytes.

That 20% CPU use is a problem though and we have seen that before, usually with LG TVs because they spam requests to us that we respond to. So we do need those logs to see why that might be happening.

[purevertigo]

OK. I will get them for you as soon as possible.

On Wed, 24 Jun 2020 at 13:06, SubJunk [e-mail] wrote:

From memory, our rate of broadcasting ALIVE messages isn't more than what
DLNA say to do. AFAIK they say to do it at random intervals between 5 and
30 seconds or something like that. I may be remembering it wrong though. I
compared our main competitors using Wireshark once and they all broadcast
as much or more than we do

If a program sending 64 or so bytes every 10-30 seconds is a problem for
bandwidth, then the network certainly isn't fast enough to run this program
in the first place. Consider that our avatars on this GitHub page are like
3-4 KB, so that's 64 ALIVE messages just for a tiny image. Consider a real
full-sized image you would display on a TV then you're talking megabytes,
and for videos usually hundreds of megabytes or several gigabytes.

That 20% CPU use is a problem though and we have seen that before, usually
with LG TVs because they spam requests to us that we respond to. So we do
need those logs to see why that might be happening.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/UniversalMediaServer/UniversalMediaServer/issues/2134#issuecomment-648554794,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/ABRUPXPDDPKVHTRJQVAKJ6LRYFUUBANCNFSM4OFMXY6Q
.

[purevertigo]

Thanks @valib @SubJunk

Logs are attached.

ums_dbg.zip

[valib]

@purevertigo do you have a Sony Xperia Z/ZL/Q/Z1/Z2 TV on your net? It seems like the false detection of the some programme running on your PC. Do you use any UPnP tool running together with the UMS? Maybe Windows UPnP Analyser?

[purevertigo]

Hi @valib That device you are referring to isn't a Sony Xperia but gets displayed as such - it is my DVR in the other room, the one I use is this https://www.fetchtv.com.au/ if that helps.

I use nextPVR and Plex and I don't think those are causing issues.

thanks

[valib]

@purevertigo I am speaking about the response e.g. TRACE 2020-06-24 17:43:05.864 [UPNPHelper] net.pms.network.UPNPHelper Received a NOTIFY from [10.0.0.2:1900] which arrived from the same network address which is used by your PC running the UMS.
Do you have on the net other device with the same network address as your PC?

[purevertigo]

@valib The offending app seems to be Windows Media Player sharing service using that Port. Does that help?

[purevertigo]

Any news on this?

[valib]

@purevertigo is that problem still persit? It seems that it was done by the scanning the shared folders which is running on background. For me the UMS in the idle consumes something between 0,5 to 3% of the CPU power.

[purevertigo]

@valib yes the problem still exists, right now I am hovering around 15-20%. Definitely a bug here.

[SubJunk]

Can you attach your current logs as it's hovering? I'll have a look

[SubJunk]

I looked at the other logs in the meantime and I can see Ethan's Smart TV, what's that? It's sending requests across the network

[purevertigo]

OK. I will monitor and upload as soon as I can.

Ethan's Smart TV is my main television. What is happening here @SubJunk ?

[SubJunk]

I'm not sure why it is consuming so many resources at the moment but there is a lot happening in the logs, mostly some incoming spam like:

TRACE 2020-06-24 23:27:51.627 [UPNPHelper] net.pms.network.UPNPHelper Received a NOTIFY from [10.0.0.2:1900]
TRACE 2020-06-24 23:27:52.625 [UPNPHelper] net.pms.network.UPNPHelper Received a M-SEARCH from [10.0.0.2:58809]: M-SEARCH * HTTP/1.1

TRACE 2020-06-24 23:27:52.649 [UPNPHelper] net.pms.network.UPNPHelper Received a NOTIFY from [10.0.0.2:1900]
TRACE 2020-06-24 23:27:53.626 [UPNPHelper] net.pms.network.UPNPHelper Received a M-SEARCH from [10.0.0.2:58809]: M-SEARCH * HTTP/1.1

I also see:

Marking renderer "Ethan's Smart TV" at 10.0.0.23 as unrecognized

and it sends us a URN:SCHEMAS-UPNP-ORG:SERVICE:CONTENTDIRECTORY:1#GETSYSTEMUPDATEID every 60 seconds

So it's a fairly busy network with questions and answers happening behind the scenes for no reason. It's possible that our broadcasting of ALIVE messages is causing this flurry of activity as certain things on the network keep responding. I'm not sure why that would use a lot of CPU though, I wouldn't expect that to be an expensive operation.

If you can upload new logs when there is no human activity happening on any devices but the CPU use is high, and let me know the time the CPU was going so I can look at that time in the logs, it might help clarify. Then I will try to reproduce that situation on my machine for fixing.

[valib]

@SubJunk yes it seems that this TV has realy stupid implementation of the UPnP/DLNA. @purevertigo can you swith off this your main device and check if the UMS has still 15-20% usage of the CPU?

[purevertigo]

@valib I have switched off the TV wifi.

[valib]

@purevertigo and what was the result?

[purevertigo]

@valib I'm going to keep monitoring and get back to you. Does that mean that I will never be able to use my smartTV?

[valib]

@purevertigo no we should find the solution but we need to know what do it and how it is caused

[purevertigo]

@valib Monitored today, seems to be hovering around <1%. Not sure if that is because I switched off the Smart TV though?

What happens now?

[purevertigo]

OK @valib @SubJunk that made no difference what so ever. The CPU is back up to 20% use when doing nothing and the Smart TV was off the entire time.
I have attached new logs.

ums_dbg_2020-07-06-20-41.zip

[rocky7x]

I have the same problem since upgrade to 9.7.1 on Linux Manjaro. Process java is constantly taking around 10-12% of CPU when in IDLE, without any Renderer connected or detected. It is making my laptop perceivably hotter.

[rocky7x]

After downgrading the UMS on Linux to version 9.6.2, the high CPU at IDLE is gone, it is sitting at 0% now, even with a renderer connected.

[purevertigo]

I don't want to downgrade but have had to stop using UMS for the time being as 20% CPU is just too much at the moment.

[SubJunk]

@purevertigo from your logs it appears the Panasonic ST60 is sending regular network requests to UMS, it is trying to introduce itself even though we replied to say "hi TV, we are UMS". Then two Google Chrome instances (macOS and Windows) send search requests. There is just this loop of events happening.

USER-AGENT: Google Chrome/83.0.4103.116 Mac OS X
USER-AGENT: Google Chrome/83.0.4103.116 Windows

Is there a version of UMS that does not have that bug? @rocky7x suggested 9.6.2 and I see your first logs were made with 9.7.0, can you please try 9.6.2 and let us know?

Edit: I just had a look at the changes between 9.7.0 and 9.6.2 and nothing jumps out that might cause that, you can see those at the following link if you want https://github.com/UniversalMediaServer/UniversalMediaServer/compare/9.6.2...9.7.0
However if that testing shows it doesn't happen in 9.6.2 I'll have a closer look

[purevertigo]

@SubJunk I will do a downgrade install as soon as I can.

In regards to the Panasonic TV, it doesn't seem like a do-able thing to turn off yet another smart TV and with Google Chrome that isn't do-able either as I use both regularly.

[SubJunk]

@purevertigo another thing to try is adding ALIVE_delay = 60000 to your UMS.conf, and that might make those actions from the other devices happen less often. If that works we will know it's related to that at least

[purevertigo]

@SubJunk I have downgraded. Do you want me to upgrade again and add 'alive delay' or continue to monitor 7.6.2?

[pipin77]

I have the same problem with my Samsung TVs. And TVs were off as I saw CPU usage around 10 to 12 % for UMS.

Downgrade to 9.6.1 solved the problem.

Testing 9.6.2 now.

Edit:

9.6.2 isnt affected

[SubJunk]

@purevertigo it seems it is really a problem introduced in 9.7.0 and we didn't change the alive delay in that version, so I would recommend continuing to use 7.6.2 until we have fixed this. I will have another look at the changes in 9.7.0 and put together a test file for the people in this thread soon

@pipin77 thanks for your input too

[SubJunk]

One guess I have is that when we did the improvements to browsing speed it exposed this existing problem. In versions before 9.7.0 we were only letting one database read happen at a time, which will have slowed down request rates and therefore limited CPU spikes, but now we allow multiple reads at a time and that would let the CPU be utilized more. So I'll make some comparison builds to test that guess.

[SubJunk]

Those comparisons are here, please let me know which of these has the high CPU problem as I don't seem to be able to reproduce it.

Windows:
https://www.universalmediaserver.com/uploads/UMS-54bad8f.exe
https://www.universalmediaserver.com/uploads/UMS-064705c.exe

Linux:
https://www.universalmediaserver.com/uploads/UMS-54bad8f-x86_64.tgz
https://www.universalmediaserver.com/uploads/UMS-064705c-x86_64.tgz

[purevertigo]

@SubJunk confirmed that a downgrade to 7.6.2 has fixed the CPU usage problem. As per your instructions, I will continue to use this version until a fix can be released.

[pipin77]

Those comparisons are here, please let me know which of these has the high CPU problem as I don't seem to be able to reproduce it.

Windows:
https://www.universalmediaserver.com/uploads/UMS-54bad8f.exe
https://www.universalmediaserver.com/uploads/UMS-064705c.exe

Can't test both version cause they are stuck with the Universal Media Server Auto Update
Says "Connecting to server" and nothing else, can't close the window or even the task in the task manager.

Maybe a timeout span should be added?

[SubJunk]

@pipin77 that sounds like an annoying bug. We should fix that. In the meantime you could disable automatic update checking on the general tab

[pipin77]

Those comparisons are here, please let me know which of these has the high CPU problem as I don't seem to be able to reproduce it.

Windows:
https://www.universalmediaserver.com/uploads/UMS-54bad8f.exe

This version doesnt have high cpu usage.

I'm testing further.

[SubJunk]

I have reproduced this problem in 9.7.1, but not 9.7.0. I have fixed the cause of the problem I reproduced but I'm not sure if that is the same as your one, so please test the fix here https://www.universalmediaserver.com/uploads/UMS-FixHighCPU-511d0e3.exe

[pipin77]

I have reproduced this problem in 9.7.1, but not 9.7.0. I have fixed the cause of the problem I reproduced but I'm not sure if that is the same as your one, so please test the fix here https://www.universalmediaserver.com/uploads/UMS-FixHighCPU-511d0e3.exe

Hm, i'm testing. At first cpu usage for the "Microsoft Compatibility Telemetry" was very high.
At the moment all is fine. Will be monotoring it for a few hours.

Seems fine after a few hours. No spikes in cpu usage any more.

[SubJunk]

Thanks for reporting. I'm releasing the fix now. If this still happens for anyone after 9.7.2 please comment and we can reopen the issue

[lupinx]

Hello,
i was facing the exact same issue,
i am using both: UMS 9.8.1 and the Old PMS 1.90.1
i have noticed that something is triggering the "javaw.exe" continuous CPU spike for both applications at almost the same moment, and they remain like that till i restart them.

After thorough investigation, i found out the culprit;
in my case, it was the "HTTPDebugger v9.9" _Service_

i disabled it , and now everything are just fine.

[SubJunk]

Thanks for letting us know. It makes sense that an external debugging program would increase CPU use in some programs, and often those debugging and profiling tools have warnings about that.