error in 6.0.0

[quick_dry]

just updated to version 6.0.0 release, and found what seems to be a bug. I didn't have this problem in earlier builds.

If the address/port used by the RemoteWeb interface encounters a bind error, none of the configuration changes made through the UI will save, and the MediaServer won't work.

I also get a javaw.exe still running and holding the port bound, and the only way to kill the instance is a full restart. The port used by the MediaServer not being released has happened with every version of UMS I've run, but previously you could just update the port, quit, restart and all would be good (using "restart server" just hung after showing the "sending BYEBYE" message). This time, it seems like the RemoteWeb interface does this.

I used Python to bind some sockets to the port's I'd set in UMS, and found that the port that is already bound (hanging around from the last run) was the RemoteWeb port (9001). If this binding error happened, the MediaServer port did not get bound.

I don't need the RemoteWeb interface so I just disabled that in conf and UMS seems to be running fine - albeit never releasing any previously used ports. But at least the UI works, and the "Restart" now works without hanging.

Is there a fix for the ports not being released? I'm on the latest version of java (version 8 update 71 build 1.8.0_71-b15) on Win2k12.

the error in the logs is:

Code: Select all

java.net.BindException: Address already in use: bind
	at sun.nio.ch.Net.bind0(Native Method) ~[na:1.8.0_71]
	at sun.nio.ch.Net.bind(Unknown Source) ~[na:1.8.0_71]
	at sun.nio.ch.Net.bind(Unknown Source) ~[na:1.8.0_71]
	at sun.nio.ch.ServerSocketChannelImpl.bind(Unknown Source) ~[na:1.8.0_71]
	at sun.nio.ch.ServerSocketAdaptor.bind(Unknown Source) ~[na:1.8.0_71]
	at sun.net.httpserver.ServerImpl.<init>(Unknown Source) ~[na:1.8.0_71]
	at sun.net.httpserver.HttpServerImpl.<init>(Unknown Source) ~[na:1.8.0_71]
	at sun.net.httpserver.DefaultHttpServerProvider.createHttpServer(Unknown Source) ~[na:1.8.0_71]
	at com.sun.net.httpserver.HttpServer.create(Unknown Source) ~[na:1.8.0_71]
	at net.pms.remote.RemoteWeb.<init>(RemoteWeb.java:90) ~[ums.jar:6.0.0]
	at net.pms.PMS.init(PMS.java:586) [ums.jar:6.0.0]
	at net.pms.PMS.createInstance(PMS.java:1068) [ums.jar:6.0.0]
	at net.pms.PMS.main(PMS.java:1226) [ums.jar:6.0.0]

[Nadahar]

The bind failure has probably been there all the time, but a recent change in UMS means that the error now gets through. A better handling of this is planned, but there's no surprise that it behaves like it does now.

The part about not releasing the ports I've heard before, but never been able to reproduce. It seems this is something that's happening to a few but I have no idea of what criterias must be in place for this to happen.

I'm not sure if I understand you correct, are you saying that UMS is still hanging on port 9001 even after you've disabled the web interface?

Some of the cases with "non releasing ports" have been because the user has been running UMS both as a service and an application. Please check that UMS is not installed as a service, run "services.msc" and look for "Universal Media Server". It should not be in the list.

[quick_dry]

I'm not sure if I understand you correct, are you saying that UMS is still hanging on port 9001 even after you've disabled the web interface?

correct.

The port was still bound from a previous instance of UMS running.

I'll timeline it:
start UMS (media: 5001, web: 9001)
quit UMS
change UMS to use port 5002 (previous versions this change would be enough to restart UMS and have it work)
start UMS (media: 5002, web 9001)
UMS starts, but logs show a bind error, won't find any renderers and will not save any changes made in UI.
quit UMS
test binding a socket to port 9001 shows as still bound.
turn off web UI in config file, change media port to 5003
start UMS (media: 5003, web: disabled)
UMS runs properly, UI changes will save, find renderers, etc.
test binding a socket to port 9001 shows as still bound - but doesn't matter as web UI isn't being used.
quit UMS
re-enable web interface in config file.
start UMS (media: 5004, web: 9001)
starts UI, but won't save changes, won't find renderers, trace log shows same bind error as earlier.
quit UMS.
disable web, change media port
start UMS (media: 5005, web: disabled)
UMS runs properly

Some of the cases with "non releasing ports" have been because the user has been running UMS both as a service and an application. Please check that UMS is not installed as a service, run "services.msc" and look for "Universal Media Server". It should not be in the list.

there are no instances running as a service.

Basically the problem is just that UMS / java never releases the ports - I don't know whether this is a java resource deadlocking during the quit and so it never can exit until restart. I always end up with a javaw.exe instance running that cannot be killed (even with administrator rights), and when it does encounter a failure to bind, that presents a UI that you can click and make changes in - but nothing will persist.

I don't know whether previous versions also failed to release the RemoteWeb port.

[Nadahar]

I don't know whether previous versions also failed to release the RemoteWeb port.

They must have done, nothing is changed in that regard. The only thing that's actually new here is that the failure to bind the web interface is exposed, and it's a intermittent solution as the plan is to allow this port to be changed from the GUI as well - behaving like "port 5001".

The only real issue I see here is that javaw.exe is hanging around. As long as that process is left there, the ports are locked and the same goes for the configuration file. The question is why this happens on some installations. A problem with the normal debug files (following the red text on top) is that we don't get the shutdown log. It will only save the log from the current startup and until the files are packed. That means that we seldom see the trace log from the shutdown itself. Also, the very last part isn't logged as logging is also being shut down.

You haven't posted debug files so I don't know what OS you're using, but assuming it's Windows (since Windows users are most likely to take it for granted) you can find the log file here by default:

Code: Select all

%programdata%\UMS\debug.log

Please go to the "Logs" tab and set log level (on the bottom line) to Trace and then quit UMS and either kill all javaw.exe if you're able or reboot so that nothing is locked. Start UMS, test using a renderer or whatever it takes to make this hanging javaw process manifest itself and then quit UMS. After that, please attach the log file as an attachement here. That way I'm hoping we can capture the shutdown sequence to see if there's any hints of what goes wrong during shutdown.

[infidel]

Basically the problem is just that UMS / java never releases the ports... I always end up with a javaw.exe instance running that cannot be killed (even with administrator rights)

quick_dry, can you please confirm whether it's really 'never' or maybe 3-6 minutes before the unkillable lingering javaw.exe process exits. Your report is very similar to previous reports, where shutdown actually completed but only after a really long wait. See here for a brief description of that issue, with related/relevant links.

[quick_dry]

You haven't posted debug files so I don't know what OS you're using, but assuming it's Windows (since Windows users are most likely to take it for granted) you can find the log file here by default:

the configuration file isn't locked, you can make changes to that - you just can't make changes through the UI.

As I said in the first post, java version 8 update 71 build 1.8.0_71-b15 on Win2k12.

I didn't post logs before since they didn't seem to capture anything different to successful operation (and I was really posting initially about the Remote Web UI as that was a difference from previous versions) - the only difference was the log file fragment that I posted in the first post showing the java BindException and where the code fails.

Unfortunately I'm not at home to be able to run the test, but from memory it did not generate anything further in the log after the BindException. I'll be home in a week and will post the logs then.

quick_dry, can you please confirm whether it's really 'never' or maybe 3-6 minutes before the unkillable lingering javaw.exe process exits. Your report is very similar to previous reports, where shutdown actually completed but only after a really long wait. See here for a brief description of that issue, with related/relevant links.

It seems to be waiting till reboot, I'd tried a few times to set it back to 5001 after a few days of running on different ports and it still failed saying the port was already bound.

I understand the need for the RemoteWeb UI to be on a defined port, but could the option be added to allow UMS to pick a random port if it can't bind to a defined port? (or just pick a random port within a range)

[Nadahar]

I understand the need for the RemoteWeb UI to be on a defined port, but could the option be added to allow UMS to pick a random port if it can't bind to a defined port? (or just pick a random port within a range)

That would be a pretty useless band-aid. To connect to it you need to know the port (which you have to add to the address in your web browser), temporarily disabling it when bind fails is much more useful and how I've planned to do it.

But, the RemoteWeb issue isn't really the issue here, the real issue is why previous instances are hanging. In your case disabling the web interface reverses the issue back to how you used to have it, but IMO it's still not anything close to a "solution". I'm not sure if the logs will show anything, it very well be that this isn't logged at all, but I'd like to see a log of the shutdown sequence nonetheless.

[quick_dry]

That would be a pretty useless band-aid. To connect to it you need to know the port (which you have to add to the address in your web browser), temporarily disabling it when bind fails is much more useful and how I've planned to do it.

sorry, I wasn't clear - I meant that I understand why RemoteUI must be on a pre-defined port, but the UMS media server port (default 5001) could automagically jump to a different port if it found 5001 (or other) port was bound already when it starts up - though this won't prevent the problem and enough UMS restarts would eventually gobble up all your free ports until they were released.

But, the RemoteWeb issue isn't really the issue here, the real issue is why previous instances are hanging. In your case disabling the web interface reverses the issue back to how you used to have it, but IMO it's still not anything close to a "solution". I'm not sure if the logs will show anything, it very well be that this isn't logged at all, but I'd like to see a log of the shutdown sequence nonetheless.

I can't see anything that stands out in the log but have attached it.

The last instance of UMS was 'quit' 20 minutes ago after creating that debug.log, and I have 10 instances of javaw.exe hanging around still (can't be killed either) - I took process dumps and checked the dump to confirm each one is an instance of UMS hanging around (memory size ranges from 815MB, to 29MB with a median size of 115MB).

[Nadahar]

There is no trace of a shutdown sequence there at all - but it was a large blank part that shouldn't be there. I don't know what's going on with UMS on your computer, but it sure isn't like it should. It seems like several instances is writing to the same logfile to me.

[quick_dry]

they could well be writing to the log, but this behaviour hasn't changed even with a full removal of UMS and Java, then a clean install of both. Still same javaw zombies