Lost connection/NPE with some renderers

[Raptor399]

Surprisingly got around to it today.

New debug log:
http://pastebin.com/HJy2kwDG

Thanks.

Unfortunately I don't see anything in there that helps me further in tracking down the problem.

Code: Select all

19:21:55.299 [Request Handler] Received on socket: GET /get/0$1$1$2/BBC.Planet.Earth.2of5.Mountains.XviD.MP3.www.MVGroup.org.avi HTTP/1.1
19:21:55.299 [Request Handler] Received on socket: Connection: TE, close
19:21:55.299 [Request Handler] Matched media renderer "Playstation 3" based on address /192.168.1.7
[...]
19:36:19.452 [Request Handler] Opened request handler on socket Socket[addr=/192.168.1.7,port=46161,localport=5001]
19:36:19.452 [Request Handler] Received on socket: SUBSCRIBE /upnp/event/content_directory HTTP/1.1
19:36:19.452 [Request Handler] Received on socket: HOST: 192.168.1.6:5001
19:36:19.452 [Request Handler] Matched media renderer "Playstation 3" based on address /192.168.1.7
19:36:19.452 [Request Handler] Received on socket: SID: uuid:a6e31139-e31e-3c85-84c7-a3be1bb7300f
19:36:19.452 [Request Handler] Received on socket: TIMEOUT: Second-180
19:36:19.452 [Request Handler] Received on socket: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
19:36:19.452 [Request Handler] Received on socket: Content-Length: 0
19:36:19.452 [Request Handler] Recognized media renderer Playstation 3
19:36:19.452 [Request Handler] HTTP: upnp/event/content_directory / 0-0
19:36:19.452 [Request Handler] Close connection

19:36:20.716 [Request Handler] Close connection

19:36:24.725 [StopPlaying Event] renderer: 192.168.1.7, file: D:\Film\Dokumentarer\BBC - Planet Earth\BBC.Planet.Earth.2of5.Mountains.XviD.MP3.www.MVGroup.org.avi

I edited the log a bit for readability.

What strikes me as odd is the SUBSCRIBE request with the strange user agent "AwoX/1.1". The connection for that request is immediately closed.
Then, one second later, there is another "Close connection". At which time DLNAResource.stopPlaying() is fired, because almost exactly 4 seconds later (= STOP_PLAYING_DELAY) the final log message appears.

I would love to tie the appearance of the SUBSCRIBE event to the StopPlaying event, but more than one second between the two Close connections is a lot. If they were related, I would expect them to be milliseconds apart, not more than a second. Still, it is very suspicious that almost 15 minutes have passed without a hickup, then the SUBSCRIBE comes in, and one second later PMS decides to close the connection and stop playing.

[Jarl]

It always happens no matter what I play with PSM but never happens with TVersity, Serviio or WMP. - Nothing new, just reiterating.

Is it unrealistic to track down this bug? That would suck, since PSM is the one DLNA server that fits all my needs (the rest of them always falls short somewhere, but I guess such a disabling bug is another way of falling short).

[Jarl]

Any news about the fate of this bug?

[C4rtm4N]

Similar question from me - my issue is different but has been lumped into the same thread.

My log is a few posts ago but PMS sees my tablet but when the tablet attempts to fetch the contents the connection closes. Lots of timeouts are shown when the initial connection happens but now no error messages are displayed at all. Windows Media Player also doesn't get a list of files but my PS3s are fine

[kvocha]

Same problem here

Code: Select all

INFO  2013-01-15 00:01:35.963 [StartPlaying Event] renderer: 192.168.1.69, file: /Volumes/Seagate Expansion Drive/Kitchen 720p/kitchen_s01e08_h264_720p.mkv
INFO  2013-01-15 00:01:36.866 [New I/O server worker #2-1] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:01:36.893 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:01:37.172 [New I/O server worker #2-3] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:01:37.209 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:01:42.496 [New I/O server worker #2-1] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:16:21.935 [New I/O server worker #2-1] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:16:29.076 [StopPlaying Event] renderer: 192.168.1.69, file: /Volumes/Seagate Expansion Drive/Kitchen 720p/kitchen_s01e08_h264_720p.mkv
INFO  2013-01-15 00:16:34.838 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:16:34.852 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:16:34.877 [New I/O server worker #2-1] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:16:34.921 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:16:34.936 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:16:34.944 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:16:50.937 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:16:50.949 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:16:50.974 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:16:53.952 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:16:57.332 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:17:01.331 [New I/O server worker #2-3] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:17:01.349 [StartPlaying Event] renderer: 192.168.1.69, file: /Volumes/Seagate Expansion Drive/Kitchen 720p/kitchen_s01e08_h264_720p.mkv
INFO  2013-01-15 00:17:02.201 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:17:02.224 [New I/O server worker #2-1] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:17:02.453 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:17:02.488 [New I/O server worker #2-3] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:17:07.151 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:21:05.593 [StopPlaying Event] renderer: 192.168.1.69, file: /Volumes/Seagate Expansion Drive/Kitchen 720p/kitchen_s01e08_h264_720p.mkv
INFO  2013-01-15 00:21:18.144 [UPNPHelper] No IP filter specified, access granted to /192.168.1.57
INFO  2013-01-15 00:21:28.598 [New I/O server worker #2-3] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:21:28.616 [StartPlaying Event] renderer: 192.168.1.69, file: /Volumes/Seagate Expansion Drive/Kitchen 720p/kitchen_s01e09_h264_720p.mkv
INFO  2013-01-15 00:21:29.498 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:21:29.532 [New I/O server worker #2-1] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:21:30.026 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:21:30.099 [New I/O server worker #2-3] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:31:50.957 [New I/O server worker #2-1] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:31:54.058 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:31:54.069 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:31:54.093 [New I/O server worker #2-3] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:31:54.116 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:31:54.122 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:31:54.128 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:31:56.378 [StopPlaying Event] renderer: 192.168.1.69, file: /Volumes/Seagate Expansion Drive/Kitchen 720p/kitchen_s01e09_h264_720p.mkv
INFO  2013-01-15 00:32:03.269 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:32:03.278 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:32:03.298 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:32:05.419 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:32:08.492 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50
INFO  2013-01-15 00:32:13.409 [New I/O server worker #2-1] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:32:13.427 [StartPlaying Event] renderer: 192.168.1.69, file: /Volumes/Seagate Expansion Drive/Kitchen 720p/kitchen_s01e09_h264_720p.mkv
INFO  2013-01-15 00:32:14.295 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:32:14.320 [New I/O server worker #2-3] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:32:14.539 [New I/O server worker #2-4] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:32:14.582 [New I/O server worker #2-1] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers
INFO  2013-01-15 00:32:19.553 [New I/O server worker #2-2] Media renderer was not recognized. Possible identifying HTTP headers: User-Agent: GStreamer neonhttpsrc, icy-metadata: 1, TE: trailers


When appears " User-Agent: AwoX/1.1 UPnP/1.0 DLNADOC/1.50 " my Toshiba Regza looses DLNA server and founds it again after sevral seconds