UMS not being detected after PC woken up from sleep #2334

Mik-S-UMS · 2021-01-05T04:49:06Z

Something I have noticed the past few days is that when I go to watch something on my PS3, UMS is not getting detected. A quick server restart fixes it so just ignored it.

I happened again today so thought I should look into it and see what the logs say.

The only thing I could see at the end of the log was just "Sending ALIVE..." messages for hours, up till when the computer was woken up.

Just after waking up was this:
[cling-1246] Ignoring remote device: InternetGatewayDevice (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:31383735-3239-3600-0000-400d10b6e4ad, Descriptor: http://192.168.1.1:5000/rootDesc.xml, Root: true
[cling-1246] Ignoring embedded device: urn:schemas-upnp-org:device:WANDevice:1 (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:31383735-3239-3600-0000-400d10b6e4ae, Descriptor: http://192.168.1.1:5000/rootDesc.xml, Root: false

192.168.1.1 is the wireless connection I use for internet (Neighbours router used with permission) and is not the interface UMS should be using which I have forced to use wired.

I think in 10.0.0-a1 UMS is not using the right network interface when it is woken up from sleep for some reason.

ums_dbg_2021-01-05-04-16.zip

SubJunk · 2021-01-05T22:33:47Z

Would you please try an older version like v9.7? We did some refactoring recently in 9.8+ that may have affected this and it would be good to know if that was the cause

Mik-S-UMS · 2021-01-05T22:57:27Z

I have been using the latest versions as they have been released, but this has only been happening since trying the alpha version.
I was on 9.8.2 before then skipped 9.8.3 to try 10.0.0-a1

SubJunk · 2021-01-05T23:09:33Z

@Mik-S-UMS I can't think of anything in v10 that would cause that, so would you please check with 9.8.3?

Mik-S-UMS · 2021-01-05T23:21:58Z

OK I give it a try next time

Mik-S-UMS · 2021-01-07T07:32:15Z

OK tried with 9.8.3 with same result which I guess is no surprise if it was due to some refactoring in 9.8+
ums_dbg_2021-01-07-06-50.zip

I'll try again with 9.8.2, I'm sure that didn't have the problem.

SubJunk · 2021-01-08T04:09:57Z

Ok great, I'll wait to hear from you about that

Mik-S-UMS · 2021-01-08T15:48:09Z

9.8.2 was the same.
ums_dbg_2021-01-08-03-40.zip

I skipped back a few versions to 9.7.2 and that is working correctly.
ums_dbg_2021-01-08-05-12.zip

Instead of just alive messages I see.
DEBUG 2021-01-08 15:40:07.188 [UPNP-AliveMessageSender] Sending ALIVE... TRACE 2021-01-08 15:40:07.188 [UPNP-AliveMessageSender] Setting SSDP network interface: name:eth5 (Realtek PCIe GBE Family Controller)

Although just scanning that log now I saw this
WARN 2021-01-08 13:25:05.977 [UPNP-AliveMessageSender] Setting SSDP network interface failed: {} java.net.SocketException: The requested address is not valid in its context (Error setting socket option) at java.base/java.net.TwoStacksPlainDatagramSocketImpl.socketNativeSetOption(Native Method) at java.base/java.net.TwoStacksPlainDatagramSocketImpl.socketSetOption(Unknown Source) at java.base/java.net.AbstractPlainDatagramSocketImpl.setOption(Unknown Source) at java.base/java.net.MulticastSocket.setNetworkInterface(Unknown Source) at net.pms.network.UPNPHelper.getNewMulticastSocket(UPNPHelper.java:284) at net.pms.network.UPNPHelper.sendAlive(UPNPHelper.java:221) at net.pms.network.UPNPHelper$1.run(UPNPHelper.java:415) at java.base/java.lang.Thread.run(Unknown Source)

There has been something else missing in newer versions that is in this log but I'll make a separate issue

SubJunk · 2021-01-09T01:05:07Z

I suspect this might be related to ad850a8 @valib any ideas?

Mik-S-UMS · 2021-01-09T03:01:12Z

a bit of weirdness with 9.8.0. possibly due to me installing wireshark.
Putting my PC to sleep then waking it up straight away, the IP for my Ethernet connection changed to 192.254.14.48 for some reason.
then UMS started giving this

DEBUG 2021-01-09 02:41:19.281 [UPNP-AliveMessageSender] Sending ALIVE...
TRACE 2021-01-09 02:41:19.281 [UPNP-AliveMessageSender] Setting SSDP network interface: name:eth4 (Realtek PCIe GBE Family Controller)
WARN  2021-01-09 02:41:19.281 [UPNP-AliveMessageSender] Setting SSDP network interface failed: {}
java.net.SocketException: The requested address is not valid in its context (Error setting socket option)
	at java.base/java.net.TwoStacksPlainDatagramSocketImpl.socketNativeSetOption(Native Method)
	at java.base/java.net.TwoStacksPlainDatagramSocketImpl.socketSetOption(Unknown Source)
	at java.base/java.net.AbstractPlainDatagramSocketImpl.setOption(Unknown Source)
	at java.base/java.net.MulticastSocket.setNetworkInterface(Unknown Source)
	at net.pms.network.UPNPHelper.getNewMulticastSocket(UPNPHelper.java:284)
	at net.pms.network.UPNPHelper.sendAlive(UPNPHelper.java:221)
	at net.pms.network.UPNPHelper$1.run(UPNPHelper.java:415)
	at java.base/java.lang.Thread.run(Unknown Source)

Disabling then re-enabling the network adaptor in windows fixed the IP and UMS was detected without restarting the server.
I think this is down to something wireshark did but uninstalling it hasn't fixed it, no clue how to undo it.

Nadahar · 2021-01-09T21:33:58Z

@valib I don't think you can run Movian on Windows. Also, it this causes problems that itself is a new bug. I've always ran renderer software on the same computer when testing (Kodi, VLC, foobar2000 etc). I've never had issues caused by the fact that they're on the same computer.

valib · 2021-01-09T21:35:20Z

@Nadahar I edited my comment because I think that he set the same IP address for the PC and alo for the PS3.

EDIT: sorry my mistake. The IP addresses are different. This is not the problem.

valib · 2021-01-09T21:59:10Z

Putting my PC to sleep then waking it up straight away, the IP for my Ethernet connection changed to 192.254.14.48 for some reason

Yes this could be the reason why the UMS fails. We should check if it happens. I will check the code.

Mik-S-UMS · 2021-01-09T22:47:17Z

@Nadahar There is a Movian plug-in for chrome, not tried that version though as I use Firefox.
https://chrome.google.com/webstore/detail/movian/nmgfcbigejokjgholnnnipegblickgnp

Nadahar · 2021-01-09T22:58:06Z

@Mik-S-UMS Nice to know I guess, although I stay as far away from Chrome as possible, the surveillance tool that can also be used to browse web pages.

Mik-S-UMS · 2021-01-09T23:21:29Z

@Nadahar yeah me too LOL

I can confirm that it was wireshark changing the IP. I used Autoruns from the SysinternalsSuite to see if anything had been left behind when uninstalling. npcap and USBPcap services were still running so I turned them both off.

Unfortunately turning off USBPcap stopped all my USB ports from working. Had to hunt down an old PS/2 mouse to login and turn it back on.

With npcap off it is back to normal.

Maybe the the cause of this is a delay in windows identifying networks when waking up causing UMS to pick an invalid one?

Mik-S-UMS · 2021-01-10T18:07:10Z

I've found the version where this started happening. 9.8.1 is the first version with this problem.

SubJunk · 2021-01-10T21:03:13Z

@Mik-S-UMS are you able to test #2339 ? If not I can upload a build for you

Mik-S-UMS · 2021-01-10T21:05:04Z

could you upload a build for me? not set up to build it myself anymore.

SubJunk · 2021-01-11T05:51:03Z

No problem, here https://www.universalmediaserver.com/uploads/UMS-update_the_network_interface_checking-4dfabc6.exe

valib · 2021-01-11T22:10:14Z

@Nadahar There is a Movian plug-in for chrome, not tried that version though as I use Firefox.
https://chrome.google.com/webstore/detail/movian/nmgfcbigejokjgholnnnipegblickgnp

I installed this version on my PC and the Android version on my phone. The result is the same. The Movian UPnP implementation fails. This was my first feeling when this issue was created. I also tested the previous UMS versions like 9.7.0 and 9.8.0 with the same result. The UMS works with thousands renderers without any problems and only this SW fails. I also used the UPnP Tool on my phone to check responses of the Movian and it fails again.

valib · 2021-01-11T23:26:42Z

@SubJunk the Movian seems to have a problem with the UPnP implementation but it uses the "themoviedb.org" to obtain the info about the video media. It is implemented to get the info about the video in the preffered language the user set. Pleae try Movian to see it and maybe we can implement this feature.

Mik-S-UMS · 2021-01-12T00:26:34Z

@SubJunk Unfortunately that didn't do the trick, I still have restart the server after waking up PC for my TV or Movian to detect UMS. I know my network setup is probably an edge case (Off-line wired network on one interface and wireless internet on another) but someone else is bound to have something similar.

ums_dbg_2021-01-11-23-52.zip

@valib I tried the chrome version myself, I thought it would be something like UMS's web interface. Surprised that it is the full app that runs separately from chrome (using parts of chrome I guess?)

I did have trouble connecting to UMS when using it on the same machine, maybe due to the conf I cobbled together for the PS3.
It did detect that it was also running on my PS3 and was able to control it seamlessly on the PC as if it was on the PS3.

one of the plug-ins called Xperience is a new skin that shows off some of info it can get similar to UMS v10 does.

Looks like Movian has been abandoned now since last update was 3 years ago. It is open source though and on GitHub so it could give you some ideas to add to UMS. If it ran on a web page like I thought, I was going to suggest you could use it as a video player for the web interface but looks like that isn't an option.

Mik-S-UMS · 2021-01-12T04:52:28Z

@valib Just remembered one thing about Movian, media servers won't appear on the home screen until they are enabled in the settings. At the bottom of the settings is "Discovered media sources" and in each option you can turn them on.

valib · 2021-01-12T15:13:19Z

@Mik-S-UMS myabe my comment was too short. Generaly the Movian works. It found the UMS, browses folders and plays media. But e.g. the GetProtocolInfo doesn't respond even if this feature is offered (tested also with the UPnP tool). The same is for GetPositionInfo.

Mik-S-UMS · 2021-01-12T19:24:37Z

@valib np, I have very little knowledge about the protocols so can't really comment on if Movian follows them correctly.

AFAICR I don't remember any reply from Movian to GetProtocolInfo in the logs but is only recently in the last few versions of UMS that GetPositionInfo has caused errors like no response

ERROR 2021-01-12 02:08:34.269 [UPNP-PS3 Movian] Failed to send action "GetPositionInfo" to PS3 Movian: Error: Current state of service prevents invoking that action. Connection error or no response received.
TRACE 2021-01-12 02:08:34.269 [UPNP-PS3 Movian] 
org.fourthline.cling.model.action.ActionException: Current state of service prevents invoking that action. Connection error or no response received.
	at org.fourthline.cling.protocol.sync.SendingAction.invokeRemote(SendingAction.java:77)
	at org.fourthline.cling.protocol.sync.SendingAction.executeSync(SendingAction.java:63)
	at org.fourthline.cling.protocol.sync.SendingAction.executeSync(SendingAction.java:51)
	at org.fourthline.cling.protocol.SendingSync.execute(SendingSync.java:54)
	at org.fourthline.cling.protocol.SendingAsync.run(SendingAsync.java:54)
	at org.fourthline.cling.controlpoint.ActionCallback.run(ActionCallback.java:151)
	at net.pms.network.UPNPControl.send(UPNPControl.java:737)
	at net.pms.network.UPNPControl.getPositionInfo(UPNPControl.java:882)
	at net.pms.network.UPNPControl$Renderer.lambda$monitor$0(UPNPControl.java:205)
	at java.base/java.lang.Thread.run(Unknown Source)

and bad request

ERROR 2021-01-12 02:08:49.117 [UPNP-PS3 Movian] Failed to send action "GetPositionInfo" to PS3 Movian: Error: Current state of service prevents invoking that action. Non-recoverable remote execution failure: 400 Bad request. (HTTP response was: 400 Bad request)
TRACE 2021-01-12 02:08:49.118 [UPNP-PS3 Movian] 
org.fourthline.cling.model.action.ActionException: Current state of service prevents invoking that action. Non-recoverable remote execution failure: 400 Bad request.
	at org.fourthline.cling.protocol.sync.SendingAction.invokeRemote(SendingAction.java:86)
	at org.fourthline.cling.protocol.sync.SendingAction.executeSync(SendingAction.java:63)
	at org.fourthline.cling.protocol.sync.SendingAction.executeSync(SendingAction.java:51)
	at org.fourthline.cling.protocol.SendingSync.execute(SendingSync.java:54)
	at org.fourthline.cling.protocol.SendingAsync.run(SendingAsync.java:54)
	at org.fourthline.cling.controlpoint.ActionCallback.run(ActionCallback.java:151)
	at net.pms.network.UPNPControl.send(UPNPControl.java:737)
	at net.pms.network.UPNPControl.getPositionInfo(UPNPControl.java:882)
	at net.pms.network.UPNPControl$Renderer.lambda$monitor$0(UPNPControl.java:205)
	at java.base/java.lang.Thread.run(Unknown Source)

I'm guessing that GetPositionInfo is the current time of the file being played?

valib · 2021-01-12T22:17:52Z

@Mik-S-UMS yes it is true and other renderers respond with 00:00:00 when the media is not playing only Movian sends "Bad request" even if I add check to recognize if the media is playing. It seems to me that this feature is simply in the Movian not implemented or implemented in a wrong way and we are trying to fix their problem.

SubJunk · 2021-01-13T22:17:29Z

9.8.1 is the first version with this problem.

@valib We merged that refactor of UPnPHelper in 9.8.1 so that is the likely cause. That happened in #2112

valib · 2021-01-13T23:05:01Z

@SubJunk why the #2112 is working on other renderers but not only on Movian? As I wrote in this issue I tested the Movian on the PC and Android phone with the same result. I tested UMS versions before the 9.8.1 and the result is the same. Can you also test it to confirm it?
EDIT: in this PR I tried not only to update the deprecated method but I also tried to avoid to slows down the UMS responds when you implemented the M-SEARCH for every network devices. I know that you tried to speed up renderers recognition but this was a little bit contraproductive.

Mik-S-UMS · 2021-01-13T23:49:02Z

@valib It's not just Movian, but my Samsung TV too. Must have something to do with how my PC is connected to the internet is stopping it seeing the local network?

valib · 2021-01-14T00:12:23Z

@Mik-S-UMS I have two Samsung renderers like Q9 TV and sound bar connected to my PC and those work without any problems. It seems to me that you have a poblem with your PC e.g. changing the IP address of the network interface is strange. I also had a problem to open your log zips when my PC says that those files are corrupted. Can you check your PC for viruses?

Nadahar · 2021-01-14T00:32:44Z

@valib You seem to miss the fact that this applies only after waking the PC from sleep. It's not necessarily reproducible on all computer systems either, because NIC drivers seems to vary somewhat as to how they handle "wake up".

That said, there was a thread on the forum not long ago about basically the same issue as far as I can remember, but as I wasn't aware that you had changed anything related to UPnP, I told him it was probably related to his hardware and/or OS. I believe that case was on Linux.

SubJunk · 2021-01-14T02:42:49Z

I can't reproduce it on my machine - my computer goes to sleep frequently, after 10 mins of inactivity, so it is constantly going to sleep and waking up, but I never restart UMS unless I need to for testing/development

@valib do you have any ideas for other fixes? If not I can try to come up with something to test

Nadahar · 2021-01-14T02:52:58Z

It's important to note that there are "different levels of sleep". In some setups, the screen might be shut of and the computer going to a "low power mode" while still having the system running. This is unlikely to cause any problems as the drivers aren't actually stopped. It's only when the NIC's are actually powered down (and the drivers stopped) the issues when resuming is likely.

My laptop seems to use both - it first go to "light sleep", from which is wakes up quickly and everything is as it was. If left alone for a longer period, it actually shuts down NICs etc, waking up takes some 20 seconds or so and the network must reconnect.

Mik-S-UMS · 2021-01-14T03:00:49Z

@valib the IP changing was my fault trying wireshark, thought it might give me some indication if there are any problems with the communication between them. I don't know what I'm doing with it and it had changed the expected outcome of my test so I removed it.

which log is corrupted? Just scanned all my local copies and nothing is out of the ordinary. Maybe one didn't upload correctly?

I just had another thought, being that I am using a usb Wifi dongle I think it is set to turn off when not in use. Maybe when it is turned on after the PC wakes up it alters the order of network adaptors? I'll give that a test later and see if disabling that in power management makes any difference.

Nadahar · 2021-01-14T03:05:41Z

@Mik-S-UMS If you make sure that all network adapters are kept powered on during "sleep" I doubt you will have any issues. But, that doesn't really change the fact that this works with older versions of UMS...?

SubJunk · 2021-01-14T03:48:39Z

@Mik-S-UMS please try https://www.universalmediaserver.com/uploads/UMS-fix-sleep-connection-abdd839.exe
It is not a fix but a partial reversion, so if it works it will narrow down how we can fix it

Mik-S-UMS · 2021-01-14T04:25:54Z

OK. Got a few ideas myself to test with my setup to see if I can narrow down what is different for me. Will report back later.

SubJunk · 2021-01-14T20:05:42Z

In my opinion it is better to leave your setup at least until we can fix this regression. It would be a shame if we lost the ability to reproduce this bug

valib · 2021-01-14T20:43:00Z

which log is corrupted? Just scanned all my local copies and nothing is out of the ordinary. Maybe one didn't upload correctly?

@Mik-S-UMS in fact I saw this warning for the first time and it could be the Firefox warning. I have no idea. I open those zips and inside is all OK. I only tried to warn you.

Mik-S-UMS · 2021-01-14T23:09:47Z

@SubJunk oops, I had already tried a few things and now it is no longer happening. Tried putting everything back the way it was but cannot reproduce the bug :( on the plus side I think I have found the cause of the other issue but will post about that in that thread.

I'll go though what I tried and see if anything makes sense to you.

I disabled "allow the computer to off this device to save power" for the network adaptors in device manager. -> no change
Removed the wifi dongle to test with only local network. ->no change
To make my computer to use the wifi instead of using my router as the internet gateway I had altered the "interface metric" from auto in "advanced TCP/IP settings" for both adaptors to give priority to the wifi dongle (10 for local, 2 for wifi). I changed this back to auto for the wired connection. -> no change

Then I tried the build with partial reversion but that gave errors while trying to connect

ERROR 2021-01-14 04:43:59.550 [main] A serious error occurred during Universal Media Server initialization: Cannot invoke "java.net.DatagramSocket.send(java.net.DatagramPacket)" because "socket" is null
DEBUG 2021-01-14 04:43:59.551 [main] 
java.lang.NullPointerException: Cannot invoke "java.net.DatagramSocket.send(java.net.DatagramPacket)" because "socket" is null
	at net.pms.network.UPNPHelper.sendMessage(UPNPHelper.java:387)
	at net.pms.network.UPNPHelper.sendByeBye(UPNPHelper.java:327)
	at net.pms.PMS.init(PMS.java:735)
	at net.pms.PMS.createInstance(PMS.java:878)
	at net.pms.PMS.main(PMS.java:1044)

ums_dbg_2021-01-14-04-51.zip

So I then reinstalled v10 and it is now not happening. I've been back tracking to see if I can find what did it but I'm stumped.

@valib no problem, always good to be cautious and I did a scan anyway to be on the safe side.

SubJunk · 2021-01-15T03:40:57Z

Closing the issue, feel free to open it again if anyone reproduces it

valib · 2021-01-15T22:32:21Z

Just for record. The Firefox recognized the zip file like corrupted because the full URL is
https://github-production-repository-file-5c1aeb.s3.amazonaws.com/4591214/5768154?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKIAIWNJYAX4CSVEH53A%2F20210110%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20210110T224255Z&X-Amz-Expires=300&X-Amz-Signature=2d90b6d359412ca52ed7826891a023f4f344021d93f76d494ab54ccff3cdf028&X-Amz-SignedHeaders=host&actor_id=1472678&key_id=0&repo_id=4591214&response-content-disposition=attachment%3Bfilename%3Dums_dbg_2021-01-05-04-16.zip&response-content-type=application%2Fx-zip-compressed

And the part https://github-production-repository-file-5c1aeb.s3.amazonaws.com seems to confuse the Firefox which it recognised like a runnable file.

Mik-S-UMS mentioned this issue Jan 8, 2021

GetProtocolInfo not being recieved #2338

Closed

valib mentioned this issue Jan 9, 2021

Add the network interface updating #2339

Closed

SubJunk closed this as completed Jan 15, 2021

Mik-S-UMS mentioned this issue Feb 20, 2022

Restart server when network interface becomes available #2615

Closed

UMS not being detected after PC woken up from sleep #2334

UMS not being detected after PC woken up from sleep #2334

Comments

Mik-S-UMS commented Jan 5, 2021

SubJunk commented Jan 5, 2021

Mik-S-UMS commented Jan 5, 2021

SubJunk commented Jan 5, 2021

Mik-S-UMS commented Jan 5, 2021

Mik-S-UMS commented Jan 7, 2021

SubJunk commented Jan 8, 2021

Mik-S-UMS commented Jan 8, 2021

SubJunk commented Jan 9, 2021

Mik-S-UMS commented Jan 9, 2021

Nadahar commented Jan 9, 2021

valib commented Jan 9, 2021 • edited

valib commented Jan 9, 2021

Mik-S-UMS commented Jan 9, 2021

Nadahar commented Jan 9, 2021

Mik-S-UMS commented Jan 9, 2021

Mik-S-UMS commented Jan 10, 2021

SubJunk commented Jan 10, 2021

Mik-S-UMS commented Jan 10, 2021

SubJunk commented Jan 11, 2021

valib commented Jan 11, 2021 • edited

valib commented Jan 11, 2021 • edited

Mik-S-UMS commented Jan 12, 2021

Mik-S-UMS commented Jan 12, 2021

valib commented Jan 12, 2021

Mik-S-UMS commented Jan 12, 2021

valib commented Jan 12, 2021 • edited

SubJunk commented Jan 13, 2021

valib commented Jan 13, 2021 • edited

Mik-S-UMS commented Jan 13, 2021

valib commented Jan 14, 2021 • edited

Nadahar commented Jan 14, 2021

SubJunk commented Jan 14, 2021

Nadahar commented Jan 14, 2021

Mik-S-UMS commented Jan 14, 2021

Nadahar commented Jan 14, 2021

SubJunk commented Jan 14, 2021

Mik-S-UMS commented Jan 14, 2021

SubJunk commented Jan 14, 2021

valib commented Jan 14, 2021

Mik-S-UMS commented Jan 14, 2021

SubJunk commented Jan 15, 2021

valib commented Jan 15, 2021 • edited

valib commented Jan 9, 2021 •

edited

valib commented Jan 11, 2021 •

edited

valib commented Jan 11, 2021 •

edited

valib commented Jan 12, 2021 •

edited

valib commented Jan 13, 2021 •

edited

valib commented Jan 14, 2021 •

edited

valib commented Jan 15, 2021 •

edited