Buggy DLNA/UPnP integration?

[chocolateboy]

Hello
Tried v1.71 with same results = Sample.mkv [MEncoder] file can't be played at the first time.
I know MEncoder/tsMuxeR hybrid engine was removed in v1.72 but this problem should apply to any version where UPnP code is maybe buggy?

When I tried to play file inside or outside TRANSCODE folder on the first try, both tries doesn't work. File can't be played.
But when I tried to play it outside folder at the fisrt time (file will not play), file inside works! It seems playing it outside folder fixes playing it inside.
When I tried it in opposite, it doesn't work same way. 1st try inside folder doesn't work, outside still doesn't work but 3rd try inside folder started to work! Again it seems playing file outside TRANSCODE folder unblocked it but playing file inside doesn't unblock file from outside folder immediately. First described method works as a rule but the opposite one sometimes works sometimes not. My tests were not consistent with this opposite direction.

Findings from playing sample.mkv file on Panasonic TV [Time in log - where played - worked?]:

• 14:29,00 - start outside TRANSCODE - doesn't work
• 14:29,10 - start in TRANSCODE folder - works! (this is consistent - always it started to work)
• 14:29,20 - start outside TRANSCODE - doesn't work
• 14:29,30 - start in TRANSCODE folder - works!
• 14:29,40 - start outside TRANSCODE - work! (playing outside is not consistent - other tests started to work much later)
• 14:29,50 - start in TRANSCODE folder - works!
• 14:30,00 - start outside TRANSCODE - work!

Log attached as "debug_out_in.log"

Now the opposite one where behavior is not consistent:

• 14:18,30 - start in TRANSCODE folder - doesn't work
• 14:18,40 - start outside TRANSCODE - doesn't work
• 14:18,50 - start in TRANSCODE folder - works! (again, playing it outside TRANSCODE folder fixed playing it inside!)
• 14:19,00 - start outside TRANSCODE - doesn't work
• 14:19,10 - start in TRANSCODE folder - works!
• 14:19,20 - start outside TRANSCODE - doesn't work
• 14:19,30 - start in TRANSCODE folder - works!

Log attached as "debug_in_out.log"

@Tomeko or someone who knows DLNA specs, please can you help with finding root cause? I also have capture file from MS Network Monitor but I think PMS log includes same info.
I spotted that first try asked for "TimeseekRange" but video failed to play ("Range: bytes=0-" is totally missing):

TRACE 2012-11-25 14:04:20.574 [New I/O server worker #1-1] Received on socket: TimeSeekRange.dlna.org: npt=00:00:00.000-
TRACE 2012-11-25 14:04:20.574 [New I/O server worker #1-1] Received on socket: transferMode.dlna.org: Streaming
TRACE 2012-11-25 14:04:20.575 [New I/O server worker #1-1] Recognized media renderer Panasonic
TRACE 2012-11-25 14:04:20.575 [New I/O server worker #1-1] HTTP: get/0$1$1/sample.mkv / 0-0
TRACE 2012-11-25 14:04:20.576 [New I/O server worker #1-1] Asked stream chunk : TimeRange [start=0.0, end=null] of sample.mkv and player MEncoder

Second try inside TRANSCODE folder works - "Range: bytes=0-" was asked but later also TimeseekRange was asked and now file was played!:

TRACE 2012-11-25 14:04:30.541 [New I/O server worker #1-4] Received on socket: Range: bytes=0-
TRACE 2012-11-25 14:04:30.541 [New I/O server worker #1-4] Received on socket: transferMode.dlna.org: Streaming
TRACE 2012-11-25 14:04:30.541 [New I/O server worker #1-4] Recognized media renderer Panasonic
TRACE 2012-11-25 14:04:30.541 [New I/O server worker #1-4] HTTP: get/0$1$2$1$1/sample.mkv / 0--1
TRACE 2012-11-25 14:04:30.542 [New I/O server worker #1-4] Asked stream chunk : TimeRange [start=null, end=null] of sample.mkv and player MEncoder

Please can someone narrow it down?
Also have to say that I edited Panasonif.conf file this way (needed when someone will try to reproduce this problem!):

SeekByTime=true
DLNALocalizationRequired=false
#CBRVideoBitrate=37000
#ByteToTimeseekRewindSeconds=0

This config now shows actual time, you can FF/RW independently, transcoding to VBR instead of CBR is 3x faster....only one bug I mentioned above

Many thanks for help
ExSport

[chocolateboy]

Is it related to this?

Digging in the log and found some differences and maybe also DLNA violations.
---------------------------------------------------------------
[New I/O server worker #1-8] TRACE 15:01:29.072 HTTP: get/0$0$0/Test_FF_RW.avi / 0--1
[New I/O server worker #1-8] TRACE 15:01:29.073 Asked stream chunk : TimeRange [start=null, end=null] of Test_FF_RW.avi and player null
[New I/O server worker #1-8] TRACE 15:01:29.074 Sending 743440384 bytes.
[New I/O server worker #1-8] TRACE 15:01:29.076 Sent to socket: Content-Length: 743440384
[New I/O server worker #1-8] TRACE 15:01:29.077 Sent to socket: Content-Range: bytes 0-743440383/743440384

If so, a new issue report on Google Code (with a link added from the old issue to the new) is probably the best place to discuss it.

[ExSport]

I am not sure it has anything to do with it. This was totally different problem but maybe fix introduced some flaws spotted now...
Adding ChunkedTransfer = true has no infuence on it.
Also I tried to force default renderer to panasonic and when I tried to unfreeze it on e.g. Android or in XBMC (playing file outside folder) and then I tried to play it on Panasonic TV at the first time (inside folder), it worked!
So it is not something with TV but something with PMS. I thought it is some caching on TV but this test redirected to PMS itself.
I also found that Android.conf file need to have "ChunkedTransfer = true" defined.
Depending on player (not DLNA renderer), it doesn't work without it (e.g. in MX Player) but has no influence on other players (built-in in Android)
I know this is not good place to mentioned it but better then to forget it.

[chocolateboy]

Also have to say that I edited Panasonif.conf file this way:

SeekByTime=true
DLNALocalizationRequired=false
#CBRVideoBitrate=37000
#ByteToTimeseekRewindSeconds=0

This config now shows actual time, you can FF/RW independently, transcoding to VBR instead of CBR is 3x faster....

What does that have to do with this issue? If you're proposing a change to the built-in Panasonic.conf, make a pull request.

[chocolateboy]

I also found that Android.conf file need to have "ChunkedTransfer = true" defined.

make a pull request

[ExSport]

When somebody will try to reporduce it, you need to change these lines.
Without it PMS does totally different things (CBR/VBR, seekbytime change)
When this will be fixed, sure, next thing will be new Panasonic.conf file pull request.
Edit:
About the android, yes sir. I have it in to do list with other things I spotted during test weekend.

[chocolateboy]

I spotted that first try asked for "TimeseekRange" but video failed to play ("Range: bytes=0-" is totally missing):

The use of these headers by the renderer is dependent on the the SeekByTime renderer.conf option and the DLNA.ORG_OP flags set by PMS.

[ExSport]

I understand but why it once works this way and when some specific file is played it started to behave differently?
It seems when PMS received request to play file, it does something but file is not played.
But now PMS has something stored in cache that influence next try of playing similar file, in way that file started to work.
When PMS is restarted, you need to start procedure from beginning but when correct file is played so file inside TRANSCODE folder works, next restart of TV or playing it on different PanTV, file works immediately.
So it seems weird behavior is on PMS and not on PanTV side.
Any thoughts? Specs to DLNA/UPnP is a nightmare for me
EDIT:
In network capture I see only: DLNA.ORG_OP=11 if it helps to somebody.

[chocolateboy]

But now PMS has something stored in cache that influence next try of playing similar file

There's no hidden cache in PMS, just the media metadata cache that can easily be disabled. The kind of caching you're describing is more likely to be a renderer "feature" than a PMS bug, particularly if it only occurs with one type of renderer.

In network capture I see only: DLNA.ORG_OP=11

First of all, can you test PMS 1.60.0 to see if this is a regression in the DLNA.ORG_OP cleanup?

Failing that: what happens if you checkout the latest source and force DLNA.ORG_OP=11 -> DLNA.ORG_OP=10 in DLNAResource.java as is currently done for the PS3?

Code: Select all

-    if (mediaRenderer.isPS3()) {
+    if (true) { // XXX temp
         flags = "DLNA.ORG_OP=10";
     } else {
         flags = "DLNA.ORG_OP=11";
     }


[ExSport]

[There's no hidden cache in PMS, just the media metadata cache that can easily be disabled. The kind of caching you're describing is more likely to be a renderer "feature" than a PMS bug, particularly if it only occurs with one type of renderer.

I know but I tried to somehow describe it with my poor English
If it will be renderer side, I think that restarting renderer will make playing file inside TRANS folder impossible. But it is not true.
Only restarting PMS will jump again to beginning so file can't be played at the first play. Restarting renderer doesn't influence this behavior in any manner.
Will try to force PS3 OP value (don't have "development" pc in hands so will try to force it in PMS directly) and let you know.