フォーラム › TuneBrowser › UI issue: timebar’s progress bar display
-
投稿者投稿
-
2024-09-22 21:39 #15491storaid参加者
Hello, Tiki,
I have an issue regarding the progress bar of the timebar when playing via UPnP.
I noticed that usually after playing one track, the timebar’s progress for the next track often freezes and doesn’t move in the UI.
Once this happens, the timebar behaves abnormally.Thanks
2024/09/22 20:25:17,073: UL05644: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:02:02 -> 122.0 / 126.8 sec 2024/09/22 20:25:18,083: UL05646: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:02:03 -> 123.0 / 126.8 sec 2024/09/22 20:25:19,079: UL05648: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:02:04 -> 124.0 / 126.8 sec 2024/09/22 20:25:20,081: UL05650: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:02:05 -> 125.0 / 126.8 sec 2024/09/22 20:25:21,065: UL05652: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:00 -> 0.0 / 126.8 sec 2024/09/22 20:25:21,065: UL05654: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: New URI found: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00016929-RFHD6779BD8.flac] 2024/09/22 20:25:21,065: UL05656: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Track: [Farewell, My Friend] 2024/09/22 20:25:21,065: UL05658: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: UseExDecd mark not found in URI: [DecodeEx:Normal] (FILE) 2024/09/22 20:25:21,065: UL05660: T058a8: UPnP_P: [UPP_MetaUPThread]: MyURI: Yes [http://10.1.1.160:29400/TuneID/00016929-RFHD6779BD8.flac] 2024/09/22 20:25:21,066: UL05662: T058a8: UPnP_P: [ResolveTune]: URI: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00016929-RFHD6779BD8.flac] 2024/09/22 20:25:21,066: UL05664: T058a8: UPnP_P: [ResolveTune]: This is mine. 2024/09/22 20:25:21,066: UL05666: T058a8: UPnP_P: [ResolveTune]: Mine:Yes Managed:Yes Recorded:Yes Local file: [\\10.1.1.127\music\[Hi-Res]TVアニメ「葬送のフリーレン」ORIGINAL SOUNDTRACK/Evan Call\08.Departures.flac] 2024/09/22 20:25:21,066: UL05668: T058a8: UPnP_P: [UPP_MetaUPThread]: Current tune: [\\10.1.1.127\music\[Hi-Res]TVアニメ「葬送のフリーレン」ORIGINAL SOUNDTRACK/Evan Call\08.Departures.flac:0] 2024/09/22 20:25:21,066: UL05670: T058a8: UPnP_P: [UPP_MetaUPThread]: Post PlayerNotify: 444416 [Update] 2024/09/22 20:25:21,066: UL05672: T058a8: UPnP_P: [UPP_MetaUPThread]: Current tune adjusted to sequence position 7. 2024/09/22 20:25:21,066: UL05674: T058a8: UPnP_P: [UPP_MetaUPThread]: Next tune sequence position 7 -> 8. 2024/09/22 20:25:21,066: UL05676: T058a8: UPnP_P: [UPP_MetaUPThread]: Playing tune is updated. Preparing next tune. 2024/09/22 20:25:21,066: UL05678: T058a8: UPnP_P: [UPP_MetaUPThread]: [iFi] is supporting SetNextAVTransportURI. 2024/09/22 20:25:21,066: UL05680: T058a8: UPnP_P: [UPP_MetaUPThread]: Doing SetAVTransportURI: AVTType::NextTune 2024/09/22 20:25:21,066: UL05682: T058a8: UPnP_P: [UPP_MetaUPThread]: Checking ProxyStream for file: [\\10.1.1.127\music\[Hi-Res]TVアニメ「葬送のフリーレン」ORIGINAL SOUNDTRACK/Evan Call\09.Time Flows Ever Onward.flac] 2024/09/22 20:25:21,066: UL05684: T058a8: UPnP_P: CanApplyWPRX=Yes : WavProxyLimitedUse(Yes) && (DSD==No || Subsong==No || HiRes==Yes || CDDA==No ) || !WavProxyLimitedUse(Yes) 2024/09/22 20:25:21,066: UL05686: T058a8: UPnP_P: WavProxy_OK=Yes : UseWavProxy==UseExDecd::IfN && MIME_OK==Yes (audio/wav) && CanApplyWPRX(Yes) 2024/09/22 20:25:21,066: UL05688: T058a8: UPnP_P: AudioL16_OK=No : UseAudioL16==UseExDecd::IfN && MIME_OK==No (audio/L16) 2024/09/22 20:25:21,066: UL05690: T058a8: UPnP_P: WavProxy_Req=No : WavProxy_OK==Yes && (UseWavProxy(UseExDecd::IfN)==UseExDecd::IfP || Tag==No (USE_WAV_PROXY)) 2024/09/22 20:25:21,066: UL05692: T058a8: UPnP_P: AudioL16_Req=No : AudioL16_OK==No && (UseAudioL16(UseExDecd::IfN)==UseExDecd::IfP || Tag==No (USE_AUDIO_L16)) 2024/09/22 20:25:21,066: UL05694: T058a8: UPnP_P: ProxyStream=No : MIME_NG(No ) (audio/flac) || EncType_NG(No ) (FLAC) || Subsong(No ) || CDDA(No ) || WavProxy_Req(No ) || AudioL16_Req(No ) || ExceedSR(No ) || ExceedBit(No ) || GenToFixedDrive(No ) || UseProxyStream(Auto)==Always 2024/09/22 20:25:21,066: UL05696: T058a8: UPnP_P: [UPP_MetaUPThread]: File: 10.1.1.127 [\\10.1.1.127\music\[Hi-Res]TVアニメ「葬送のフリーレン」ORIGINAL SOUNDTRACK/Evan Call\09.Time Flows Ever Onward.flac] 2024/09/22 20:25:21,066: UL05698: T058a8: UPnP_P: [UPP_MetaUPThread]: URI: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00016930-RFH8A4C980A.flac] 2024/09/22 20:25:21,066: UL05700: T058a8: UPnP_P: [UPP_MetaUPThread]: <DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"> 2024/09/22 20:25:21,066: UL05702: T058a8: UPnP_P: [UPP_MetaUPThread]: <item> 2024/09/22 20:25:21,066: UL05704: T058a8: UPnP_P: [UPP_MetaUPThread]: <res protocolInfo="http-get:*:audio/flac:*" duration="0:02:18.067" bitrate="1417820" bitsPerSample="24" nrAudioChannels="2" sampleFrequency="48000" DecodeEx="Normal">http://10.1.1.160:29400/TuneID/00016930-RFH8A4C980A.flac</res> 2024/09/22 20:25:21,066: UL05706: T058a8: UPnP_P: [UPP_MetaUPThread]: <dc:title>Time Flows Ever Onward</dc:title> 2024/09/22 20:25:21,066: UL05708: T058a8: UPnP_P: [UPP_MetaUPThread]: <dc:creator>Evan Call</dc:creator> 2024/09/22 20:25:21,066: UL05710: T058a8: UPnP_P: [UPP_MetaUPThread]: <upnp:originalDiscNumber>1</upnp:originalDiscNumber> 2024/09/22 20:25:21,066: UL05712: T058a8: UPnP_P: [UPP_MetaUPThread]: <upnp:album>TVアニメ『葬送のフリーレン』Original Soundtrack</upnp:album> 2024/09/22 20:25:21,066: UL05714: T058a8: UPnP_P: [UPP_MetaUPThread]: <upnp:artist>Evan Call</upnp:artist> 2024/09/22 20:25:21,066: UL05716: T058a8: UPnP_P: [UPP_MetaUPThread]: <upnp:artist role="AlbumArtist">Evan Call</upnp:artist> 2024/09/22 20:25:21,066: UL05718: T058a8: UPnP_P: [UPP_MetaUPThread]: <upnp:artist role="Composer">Evan Call</upnp:artist> 2024/09/22 20:25:21,066: UL05720: T058a8: UPnP_P: [UPP_MetaUPThread]: <upnp:originalTrackNumber>9</upnp:originalTrackNumber> 2024/09/22 20:25:21,066: UL05722: T058a8: UPnP_P: [UPP_MetaUPThread]: <upnp:albumArtURI>http://10.1.1.160:29400/Image/15170.ae33a808-5fb9-4c01-92ef1cc87c5ada1c.jpg</upnp:albumArtURI> 2024/09/22 20:25:21,066: UL05724: T058a8: UPnP_P: [UPP_MetaUPThread]: <upnp:class>object.item.audioItem.musicTrack</upnp:class> 2024/09/22 20:25:21,066: UL05726: T058a8: UPnP_P: [UPP_MetaUPThread]: </item> 2024/09/22 20:25:21,066: UL05728: T058a8: UPnP_P: [UPP_MetaUPThread]: </DIDL-Lite> 2024/09/22 20:25:21,066: UL05730: T058a8: UPnP_P: [SetNextAVTransportURI]: CommandSOAP: AVTransport:SetNextAVTransportURI 2024/09/22 20:25:21,067: UL05732: T058a8: UPnP_P: [SOAP Request]: SOAP request: [SetNextAVTransportURI ] to: 10.1.1.96 [http://10.1.1.96:49153/ctl/AVTransport] 2024/09/22 20:25:21,104: UL05734: T0bd78: UPnP_P: Proc PlayerNotify: 444416 [Update] 2024/09/22 20:25:21,117: UL05736: T0bd78: UPnP_P: GUI part detected tune change: [\\10.1.1.127\music\[Hi-Res]TVアニメ「葬送のフリーレン」ORIGINAL SOUNDTRACK/Evan Call\08.Departures.flac:0] 2024/09/22 20:25:21,696: UL05745: T058a8: UPnP_P: [SOAP Request]: SOAP request: [SetNextAVTransportURI ] finished. 2024/09/22 20:25:21,697: UL05747: T058a8: UPnP_P: [SetNextAVTransportURI]: [iFi] accepted next tune by SetNextAVTransportURI: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00016930-RFH8A4C980A.flac] 2024/09/22 20:25:22,072: UL05749: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:01 -> 1.0 / 126.8 sec 2024/09/22 20:25:22,073: UL05751: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Updated metadata: [http://10.1.1.160:29400/TuneID/00016929-RFHD6779BD8.flac] 2024/09/22 20:25:22,073: UL05753: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Upd tag: [TITLE ]: 2024/09/22 20:25:22,073: UL05755: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Old: [Farewell, My Friend] 2024/09/22 20:25:22,073: UL05757: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: New: [Departures] 2024/09/22 20:25:22,073: UL05759: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Upd tag: [TRACKNUMBER ]: 2024/09/22 20:25:22,073: UL05761: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Old: [7] 2024/09/22 20:25:22,073: UL05763: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: New: [8] 2024/09/22 20:25:22,073: UL05765: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Upd tag: [X_SAMPLERATE ]: 2024/09/22 20:25:22,073: UL05767: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Old: [48000] 2024/09/22 20:25:22,074: UL05769: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: New: [44100] 2024/09/22 20:25:22,074: UL05771: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Upd tag: [X_DURATION ]: 2024/09/22 20:25:22,074: UL05773: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Old: [126.760] 2024/09/22 20:25:22,074: UL05775: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: New: [0.000] 2024/09/22 20:25:22,074: UL05777: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Updated metadata found. 2024/09/22 20:25:22,074: UL05779: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: Track: [Departures] 2024/09/22 20:25:22,074: UL05781: T0d86c: UPnP_P: [Proc:UriAndMeta] <POL>: UseExDecd mark not found in URI: [DecodeEx:Normal] (FILE) 2024/09/22 20:25:22,074: UL05783: T058a8: UPnP_P: [UPP_MetaUPThread]: MyURI: Yes [http://10.1.1.160:29400/TuneID/00016929-RFHD6779BD8.flac] 2024/09/22 20:25:22,074: UL05785: T058a8: UPnP_P: [ResolveTune]: URI: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00016929-RFHD6779BD8.flac] 2024/09/22 20:25:22,074: UL05787: T058a8: UPnP_P: [ResolveTune]: This is mine. 2024/09/22 20:25:22,074: UL05789: T058a8: UPnP_P: [ResolveTune]: Mine:Yes Managed:Yes Recorded:Yes Local file: [\\10.1.1.127\music\[Hi-Res]TVアニメ「葬送のフリーレン」ORIGINAL SOUNDTRACK/Evan Call\08.Departures.flac] 2024/09/22 20:25:23,072: UL05791: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:02 -> 2.0 / 0.0 sec (Void) 2024/09/22 20:25:24,080: UL05815: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:03 -> 3.0 / 0.0 sec (Void) 2024/09/22 20:25:25,079: UL05817: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:04 -> 4.0 / 0.0 sec (Void) 2024/09/22 20:25:26,068: UL05819: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:05 -> 5.0 / 0.0 sec (Void) (per 5 seconds) 2024/09/22 20:25:26,357: UL05820: T09ca4: HTTPServer: [10.1.1.96 :33836]: Sent 10485760 bytes. 2024/09/22 20:25:27,590: UL05821: T0e0a8: --> 10.1.1.169 :64321 SSDP NOTIFY: ssdp:alive upnp:rootdevice 2024/09/22 20:25:27,600: UL05822: T0e0a8: --> SSDP NOTIFY: ssdp:alive uuid:00000001-0000-1010-8000-083a88d5d66e 2024/09/22 20:25:27,621: UL05823: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:device:MediaServer:1 2024/09/22 20:25:27,641: UL05824: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:service:ContentDirectory:1 2024/09/22 20:25:27,662: UL05825: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:service:ConnectionManager:1 2024/09/22 20:25:27,793: UL05826: T0e0a8: --> SSDP NOTIFY: ssdp:alive upnp:rootdevice 2024/09/22 20:25:27,794: UL05827: T0e0a8: --> SSDP NOTIFY: ssdp:alive uuid:00000001-0000-1010-8000-083a88d5d66e 2024/09/22 20:25:27,803: UL05828: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:device:MediaServer:1 2024/09/22 20:25:27,825: UL05829: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:service:ContentDirectory:1 2024/09/22 20:25:27,846: UL05830: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:service:ConnectionManager:1 2024/09/22 20:25:30,774: UL05832: T0e0a8: --> 10.1.1.169 :54380 SSDP NOTIFY: ssdp:alive upnp:rootdevice 2024/09/22 20:25:30,799: UL05833: T0e0a8: UPnP_M: *** Processing USNID_20 by NOTIFY from: 10.1.1.169 : [uuid:00000000-0000-1010-8000-083a88d5d66e::urn:schemas-upnp-org:device:MediaRenderer:1] 2024/09/22 20:25:30,799: UL05834: T0e0a8: UPnP_M: This is TargetURN: NT: [urn:schemas-upnp-org:device:MediaRenderer:1] 2024/09/22 20:25:30,799: UL05835: T0e0a8: UPnP_M: Friendly name: [HT-A7000] (HT-A7000) 2024/09/22 20:25:30,800: UL05836: T0e0a8: UPnP_M: USNID_20 is already recorded: uuid:00000000-0000-1010-8000-083a88d5d66e::urn:schemas-upnp-org:device:MediaRenderer:1 2024/09/22 20:25:30,803: UL05837: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:device:MediaRenderer:1 2024/09/22 20:25:30,821: UL05838: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:service:RenderingControl:1 2024/09/22 20:25:30,843: UL05839: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:service:ConnectionManager:1 2024/09/22 20:25:30,864: UL05840: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:service:AVTransport:1 2024/09/22 20:25:30,884: UL05841: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-sony-com:service:ScalarWebAPI:1 2024/09/22 20:25:30,985: UL05842: T0e0a8: --> SSDP NOTIFY: ssdp:alive upnp:rootdevice 2024/09/22 20:25:31,005: UL05843: T0e0a8: --> SSDP NOTIFY: ssdp:alive uuid:00000000-0000-1010-8000-083a88d5d66e 2024/09/22 20:25:31,025: UL05844: T0e0a8: UPnP_M: *** Processing USNID_20 by NOTIFY from: 10.1.1.169 : [uuid:00000000-0000-1010-8000-083a88d5d66e::urn:schemas-upnp-org:device:MediaRenderer:1] 2024/09/22 20:25:31,026: UL05845: T0e0a8: UPnP_M: This is TargetURN: NT: [urn:schemas-upnp-org:device:MediaRenderer:1] 2024/09/22 20:25:31,026: UL05846: T0e0a8: UPnP_M: Friendly name: [HT-A7000] (HT-A7000) 2024/09/22 20:25:31,026: UL05847: T0e0a8: UPnP_M: USNID_20 is already recorded: uuid:00000000-0000-1010-8000-083a88d5d66e::urn:schemas-upnp-org:device:MediaRenderer:1 2024/09/22 20:25:31,026: UL05848: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:device:MediaRenderer:1 2024/09/22 20:25:31,067: UL05849: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:service:ConnectionManager:1 2024/09/22 20:25:31,087: UL05851: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:10 -> 10.0 / 0.0 sec (Void) (per 5 seconds) 2024/09/22 20:25:31,088: UL05852: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-upnp-org:service:AVTransport:1 2024/09/22 20:25:31,111: UL05853: T0e0a8: --> SSDP NOTIFY: ssdp:alive urn:schemas-sony-com:service:ScalarWebAPI:1 2024/09/22 20:25:36,079: UL05856: T0d86c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:15 -> 15.0 / 0.0 sec (Void) (per 5 seconds) 2024/09/22 20:25:38,733: UL05857: T09ca4: HTTPServer: [10.1.1.96 :33836]: Sent 12582912 bytes. 2024/09/22 20:25:38,733: UL05858: T09ca4: HTTPServer: [10.1.1.96 :33836]: Detected playback threshold: TX:12582912 TL:11760372 / 23520744 bytes
2024-09-22 22:53 #15492storaid参加者Hi, Tiki
I found that this issue might be caused by the UPnP device.
I may need to contact the manufacturer about this issue…
However, what does the “(Void)” mean when it appears?
“UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:15 -> 15.0 / 0.0 sec (Void) (per 5 seconds)”
Once “(Void)” appears, the timebar’s progress functionality seems to start malfunctioning.
Thanks
2024-09-23 19:35 #15495TikiキーマスターHowever, what does the “(Void)” mean when it appears?
In this case, elapsed time 15 is exceeded duration time 0. Therefore, the time information is determined to be void.
Duration 0 is appeared in your log UL05775. Unfortunately, it is not clear from this log why the duration was determined to be 0 (I’ll add logs in a next release).
2024-09-26 20:07 #15499TikiキーマスターHi,
I have added logs for when invalid data are detected in received metadata.
2024-09-26 20:39 #15500storaid参加者Hi, Tiki
Here is the log(“void” happened) attached.
you can check it!
Thanks
Attachments:
2024-09-28 14:46 #15502storaid参加者weird…
test device: ifi zen stream
there is no “void” issue in v5.5.3 or older…
2024-09-28 20:59 #15503TikiキーマスターI have checked your attached log file. There is no duration info in log. Probably, the duration info that TuneBrowser can recognize did not come in.
2024-09-28 21:06 #15504storaid参加者Hi,
“I have checked your attached log file. There is no duration info in log. Probably, the duration info that TuneBrowser can recognize did not come in.”
I tested previous or earlier versions for a while.
all are working well except v5.6.0
2024-09-28 21:15 #15505TikiキーマスターI’m sorry, but I am not going to revert to the old version of the UPnP feature.
2024-09-28 21:37 #15508TikiキーマスターI have added logs of received DIDL/res info in 1773.
2024-09-28 21:44 #15509storaid参加者Hello, Tiki
about this part, did you make any changes?
I captured the packets using Wireshark, and I don’t see any differences.
TuneBrowser is still using GetPositionInfo to retrieve information.
2024-09-28 21:50 #15510storaid参加者Hi,
“I have added logs of received DIDL/res info in 1773.”
Check log
thanks…
Attachments:
2024-09-28 22:55 #15512storaid参加者TrackMetaData from GetPositionInfoResponse differences??
Tool: whireshark
v5.5.3
<DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"> <item> <res protocolInfo="http-get:*:audio/flac:*" duration="0:03:25.822" bitrate="881753" bitsPerSample="16" nrAudioChannels="2" sampleFrequency="44100" DecodeEx="Normal">http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac</res> <dc:title>曲名</dc:title> <dc:date>2023</dc:date> <dc:creator>西木康治</dc:creator> <dc:publisher>SQUARE ENIX MUSIC</dc:publisher> <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> <upnp:genre>Soundtrack</upnp:genre> <upnp:artist>西木康治</upnp:artist> <upnp:originalTrackNumber>02</upnp:originalTrackNumber> <upnp:albumArtURI>http://10.1.1.160:29400/Image/05625.a5a33f89-dc3e-4c1d-9a489069227fea69.jpg</upnp:albumArtURI> <upnp:class>object.item.audioItem.musicTrack</upnp:class> </item> </DIDL-Lite>
v5.6.0(if the Void issue happened)
<?xml version="1.0" encoding="utf-8"?> <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/"> <item restricted="1"> <orig>mpd</orig> <dc:title>曲名</dc:title> <upnp:class>object.item.audioItem.musicTrack</upnp:class> <dc:creator>西木康治</dc:creator> <upnp:artist>西木康治</upnp:artist> <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> <upnp:genre>Soundtrack</upnp:genre> <upnp:originalTrackNumber>2</upnp:originalTrackNumber> <res duration="0:00:00" sampleFrequency="44100" nrAudioChannels="2" protocolInfo="http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=01700000000000000000000000000000">http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac</res> </item> </DIDL-Lite>
duration=”0:00:00″??? 0_0
2024-09-28 23:09 #15513storaid参加者v5.6.0(without “void” issue)
<DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"> <item> <res protocolInfo="http-get:*:audio/flac:*" duration="0:03:25.822" bitrate="881753" bitsPerSample="16" nrAudioChannels="2" sampleFrequency="44100" DecodeEx="Normal">http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac</res> <dc:title>曲名</dc:title> <dc:date>2023</dc:date> <dc:creator>西木康治</dc:creator> <dc:publisher>SQUARE ENIX MUSIC</dc:publisher> <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> <upnp:genre>Soundtrack</upnp:genre> <upnp:artist>西木康治</upnp:artist> <upnp:originalTrackNumber>02</upnp:originalTrackNumber> <upnp:albumArtURI>http://10.1.1.160:29400/Image/05625.a5a33f89-dc3e-4c1d-9a489069227fea69.jpg</upnp:albumArtURI> <upnp:class>object.item.audioItem.musicTrack</upnp:class> </item> </DIDL-Lite>
2024-09-29 17:17 #15514Tikiキーマスターduration=”0:00:00″???
Yes, the answer to the first question below is that duration=”0:00:00″.I do not know why the device does so.
Duration 0 is appeared in your log UL05775. Unfortunately, it is not clear from this log why the duration was determined to be 0 (I’ll add logs in a next release).
2024-09-29 18:36 #15515storaid参加者Hi, Tiki
“the answer to the first question below is that duration=”0:00:00″.I do not know why the device does so.”
Yeap, that’s a problem.
I’m not sure what you changed something behavior for this in v5.6.0.
but in the previous version, there is no issue such as this by checking packets using the sniffer tool.
the renderer device is working well.
in v5.6.0, there may be something wrong I don’t know.
another error(will trigger the renderer crash)
2024/09/29 17:00:34,882.800: T09704: UPnP_P: PlayImpl: RelTimeEvent: No 2024/09/29 17:00:34,882.810: T09704: UPnP_P: PlayImpl: SyncActive: No 2024/09/29 17:00:34,882.820: T09704: UPnP_P: PlayImpl: Post [Play] 2024/09/29 17:00:34,882.832: T09704: UPnP_P: PlayImpl: CommandSOAP: AVTransport:Play 2024/09/29 17:00:34,883.278: T09704: UPnP_P: [SOAP Request]: SOAP request: [Play ] to: 10.1.1.96 [http://10.1.1.96:49153/ctl/AVTransport] 2024/09/29 17:00:34,916.126: T04818: UPnP_P: Post PlayerNotify: 444416 [SpecUpdate] 2024/09/29 17:00:34,916.621: T04818: UPnP_P: Proc PlayerNotify: 444416 [SpecUpdate] 2024/09/29 17:00:34,926.750: T09704: UPnP_P: [SOAP Request]: SOAP request: [Play ] finished. 2024/09/29 17:00:34,926.855: T09704: UPnP_P: PlayImpl: Waiting for state change in 10000 ms. 2024/09/29 17:00:35,446.687: T09704: UPnP_P: PlayImpl: Device event was not detected. SyncActive turns to on. 2024/09/29 17:00:35,446.740: T09704: UPnP_P: PlayImpl: QuerySOAP: Getting volume from device. 2024/09/29 17:00:35,447.074: T09704: UPnP_P: [SOAP Request]: SOAP request: [GetVolume ] to: 10.1.1.96 [http://10.1.1.96:49153/ctl/RenderingControl] 2024/09/29 17:00:35,450.802: T09704: UPnP_P: [SOAP Request]: SOAP request: [GetVolume ] finished. 2024/09/29 17:00:35,450.973: T09704: UPnP_P: PlayImpl: QuerySOAP: -> Volume: 100 2024/09/29 17:00:35,451.072: T09704: UPnP_P: PlayImpl: QuerySOAP: Getting TransportInfo from device. 2024/09/29 17:00:35,451.935: T09704: UPnP_P: [SOAP Request]: SOAP request: [GetTransportInfo ] to: 10.1.1.96 [http://10.1.1.96:49153/ctl/AVTransport] 2024/09/29 17:00:35,477.191: T09704: UPnP_P: [SOAP Request]: SOAP request: [GetTransportInfo ] finished. 2024/09/29 17:00:35,477.310: T09704: UPnP_P: PlayImpl: QuerySOAP: -> TransportStatus: OK 2024/09/29 17:00:35,477.323: T09704: UPnP_P: PlayImpl: QuerySOAP: -> TransportState: PLAYING 2024/09/29 17:00:35,477.335: T09704: UPnP_P: [Proc:TrState ] <POL>: PlayerUPnP UPState changed [STOPPED ] to [PLAYING ] 2024/09/29 17:00:35,477.350: T09704: UPnP_P: [Proc:TrState ] <POL>: PlayerUPnP PLStatus changed [PlayStatus::Stop ] to [PlayStatus::Playing ] 2024/09/29 17:00:35,477.365: T09704: UPnP_P: [Proc:TrState ] <POL>: PlayerStatus: Playing 2024/09/29 17:00:35,477.378: T09704: UPnP_P: [Proc:TrState ] <POL>: PLTTrace assigned: 02 2024/09/29 17:00:35,477.390: T09704: UPnP_P: [Proc:TrState ] <POL>: Post PlayerNotify: 000002 [Start] 2024/09/29 17:00:35,477.400: T09704: UPnP_P: [Proc:TrState ] <POL>: Post PlayerNotify: 000002 [Started] 2024/09/29 17:00:35,477.407: T09704: UPnP_P: [Proc:TrState ] <POL>: State : PLAYING 2024/09/29 17:00:35,477.421: T09704: UPnP_P: PlayImpl: QuerySOAP: Getting PositionInfo from device. 2024/09/29 17:00:35,477.773: T09704: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] to: 10.1.1.96 [http://10.1.1.96:49153/ctl/AVTransport] 2024/09/29 17:00:35,479.406: T04818: UPnP_P: Proc PlayerNotify: 000002 [Start] 2024/09/29 17:00:35,486.609: T04818: UPnP_P: Proc PlayerNotify: 000002 [Started] 2024/09/29 17:00:35,504.350: T09704: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] finished. 2024/09/29 17:00:35,504.463: T09704: UPnP_P: PlayImpl: QuerySOAP: -> RelTime: 0:00:00 2024/09/29 17:00:35,504.482: T09704: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:00 -> 0.0 / 217.5 sec 2024/09/29 17:00:35,504.489: T09704: UPnP_P: PlayImpl: QuerySOAP: -> TrackURI: http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac 2024/09/29 17:00:35,504.496: T09704: UPnP_P: PlayImpl: QuerySOAP: -> TrackMetaData: <?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/el (...) 2024/09/29 17:00:35,504.706: T09704: UPnP_P: [Proc:UriAndMeta] <POL>: DIDL/res: [http://10.1.1.160:29400/TuneID/00005330-RFH2FFDC25A.flac_WPRX?Subsong=2&DecodeEx=WavProxy] 2024/09/29 17:00:35,504.712: T09704: UPnP_P: [Proc:UriAndMeta] <POL>: - duration:[0:00:00] nrAudioChannels:[2] sampleFrequency:[44100] protocolInfo:[http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=01700000000000000000000000000000] 2024/09/29 17:00:35,504.732: T09704: UPnP_P: [Proc:UriAndMeta] <POL>: New URI found: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/29 17:00:35,504.736: T09704: UPnP_P: [Proc:UriAndMeta] <POL>: UseExDecd mark is pending. 2024/09/29 17:00:35,504.741: T09704: UPnP_P: [Proc:UriAndMeta] <POL>: Track: [Insonnia] 2024/09/29 17:00:35,505.126: T09704: UPnP_P: [Proc:UriAndMeta] <POL>: UseExDecd mark not found in URI: [DecodeEx:Normal] (FILE) 2024/09/29 17:00:35,505.157: T09f00: UPnP_P: [UPP_MetaUPThread]: MyURI: Yes [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/29 17:00:35,505.326: T09f00: UPnP_P: [ResolveTune]: URI: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/29 17:00:35,505.363: T09f00: UPnP_P: [ResolveTune]: This is mine. 2024/09/29 17:00:35,505.373: T09f00: UPnP_P: [ResolveTune]: Mine:Yes Managed:Yes Recorded:Yes Local file: [\\10.1.1.127\music\OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2\DISC 3\Track_02.flac] 2024/09/29 17:00:35,565.521: T09704: UPnP_P: PlayImpl: State change detected. 2024/09/29 17:00:35,565.541: T09704: UPnP_P: PlayImpl: Waiting for state change has done in 639 ms. 2024/09/29 17:00:35,565.553: T09704: UPnP_P: PlayImpl: No seek is required. 2024/09/29 17:00:35,565.561: T09704: UPnP_P: PlayImpl: Setting seek value to void. 2024/09/29 17:00:35,565.568: T09704: UPnP_P: PlayImpl: Preparing next tune by SetNextAVTransportURI. 2024/09/29 17:00:35,565.579: T09704: UPnP_P: PlayImpl: Next tune sequence position 45 -> 46. 2024/09/29 17:00:35,565.591: T09704: UPnP_P: PlayImpl: [IFi] is supporting SetNextAVTransportURI. 2024/09/29 17:00:35,565.610: T09704: UPnP_P: PlayImpl: Procedure has been done. 2024/09/29 17:00:35,565.633: T0222c: UPnP_P: [UPP_TransCThread]: Doing SetAVTransportURI: AVTType::NextTune 2024/09/29 17:00:35,565.648: T09704: UPnP_P: Fade in. 2024/09/29 17:00:35,565.660: T0222c: UPnP_P: [UPP_TransCThread]: Checking ProxyStream for file: [\\10.1.1.127\music\OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2\DISC 3\Track_03.flac] 2024/09/29 17:00:35,565.666: T09704: UPnP_P: Clear fade control. 2024/09/29 17:00:35,565.687: T09704: UPnP_P: Post PlayerNotify: 444417 [Update] 2024/09/29 17:00:35,565.695: T0222c: UPnP_P: CanApplyWPRX=No : WavProxyLimitedUse(Yes) && (DSD==No || Subsong==No || HiRes==No || CDDA==No ) || !WavProxyLimitedUse(Yes) 2024/09/29 17:00:35,565.706: T0222c: UPnP_P: WavProxy_OK=No : UseWavProxy==UseExDecd::IfN && MIME_OK==Yes (audio/wav) && CanApplyWPRX(No ) 2024/09/29 17:00:35,565.717: T0222c: UPnP_P: AudioL16_OK=No : UseAudioL16==UseExDecd::IfN && MIME_OK==No (audio/L16) 2024/09/29 17:00:35,565.726: T0222c: UPnP_P: WavProxy_Req=No : WavProxy_OK==No && (UseWavProxy(UseExDecd::IfN)==UseExDecd::IfP || Tag==No (USE_WAV_PROXY)) 2024/09/29 17:00:35,565.732: T0222c: UPnP_P: AudioL16_Req=No : AudioL16_OK==No && (UseAudioL16(UseExDecd::IfN)==UseExDecd::IfP || Tag==No (USE_AUDIO_L16)) 2024/09/29 17:00:35,565.744: T0222c: UPnP_P: ProxyStream=No : MIME_NG(No ) (audio/flac) || EncType_NG(No ) (FLAC) || Subsong(No ) || CDDA(No ) || WavProxy_Req(No ) || AudioL16_Req(No ) || ExceedSR(No ) || ExceedBit(No ) || GenToFixedDrive(No ) || UseProxyStream(Auto)==Always 2024/09/29 17:00:35,566.308: T0222c: UPnP_P: [UPP_TransCThread]: File: 10.1.1.127 [\\10.1.1.127\music\OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2\DISC 3\Track_03.flac] 2024/09/29 17:00:35,566.318: T0222c: UPnP_P: [UPP_TransCThread]: URI: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00013979-RFH491D8236.flac] 2024/09/29 17:00:35,566.323: T0222c: UPnP_P: [UPP_TransCThread]: -- CreatedMetadata -- { 2024/09/29 17:00:35,566.334: T0222c: UPnP_P: [UPP_TransCThread]: <DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"> 2024/09/29 17:00:35,566.340: T0222c: UPnP_P: [UPP_TransCThread]: <item> 2024/09/29 17:00:35,566.345: T0222c: UPnP_P: [UPP_TransCThread]: <res protocolInfo="http-get:*:audio/flac:*" duration="0:01:08.638" bitrate="905107" bitsPerSample="16" nrAudioChannels="2" sampleFrequency="44100" DecodeEx="Normal">http://10.1.1.160:29400/TuneID/00013979-RFH491D8236.flac</res> 2024/09/29 17:00:35,566.351: T0222c: UPnP_P: [UPP_TransCThread]: <dc:title>絶望を司りし時</dc:title> 2024/09/29 17:00:35,566.355: T0222c: UPnP_P: [UPP_TransCThread]: <dc:date>2023</dc:date> 2024/09/29 17:00:35,566.359: T0222c: UPnP_P: [UPP_TransCThread]: <dc:creator>西木康智</dc:creator> 2024/09/29 17:00:35,566.364: T0222c: UPnP_P: [UPP_TransCThread]: <dc:publisher>SQUARE ENIX MUSIC</dc:publisher> 2024/09/29 17:00:35,566.368: T0222c: UPnP_P: [UPP_TransCThread]: <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> 2024/09/29 17:00:35,566.373: T0222c: UPnP_P: [UPP_TransCThread]: <upnp:genre>Soundtrack</upnp:genre> 2024/09/29 17:00:35,566.378: T0222c: UPnP_P: [UPP_TransCThread]: <upnp:artist>西木康智</upnp:artist> 2024/09/29 17:00:35,566.382: T0222c: UPnP_P: [UPP_TransCThread]: <upnp:originalTrackNumber>03</upnp:originalTrackNumber> 2024/09/29 17:00:35,566.387: T0222c: UPnP_P: [UPP_TransCThread]: <upnp:albumArtURI>http://10.1.1.160:29400/Image/05649.aad5f8a2-706a-4092-b442f063c78c9c6b.jpg</upnp:albumArtURI> 2024/09/29 17:00:35,566.392: T0222c: UPnP_P: [UPP_TransCThread]: <upnp:class>object.item.audioItem.musicTrack</upnp:class> 2024/09/29 17:00:35,566.396: T0222c: UPnP_P: [UPP_TransCThread]: </item> 2024/09/29 17:00:35,566.401: T0222c: UPnP_P: [UPP_TransCThread]: </DIDL-Lite> 2024/09/29 17:00:35,566.411: T0222c: UPnP_P: [UPP_TransCThread]: } -- CreatedMetadata -- 2024/09/29 17:00:35,566.430: T0222c: UPnP_P: [SetNextAVTransportURI]: CommandSOAP: AVTransport:SetNextAVTransportURI 2024/09/29 17:00:35,566.630: T0222c: UPnP_P: [SOAP Request]: SOAP request: [SetNextAVTransportURI ] to: 10.1.1.96 [http://10.1.1.96:49153/ctl/AVTransport] 2024/09/29 17:00:35,572.427: T04818: UPnP_P: Proc PlayerNotify: 444417 [Update] 2024/09/29 17:00:36,178.752: T0222c: UPnP_P: [SOAP Request]: SOAP request: [SetNextAVTransportURI ] finished. 2024/09/29 17:00:36,178.862: T0222c: UPnP_P: [SetNextAVTransportURI]: [IFi] accepted next tune by SetNextAVTransportURI: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00013979-RFH491D8236.flac] 2024/09/29 17:00:36,236.003: T09834: Subscriber: [Event]: Device event is detected. SyncActive turns to off. 2024/09/29 17:00:36,236.084: T09834: Subscriber: [Event]: Received UPnP EVENT: [AVTransport] 2024/09/29 17:00:36,236.117: T09834: Subscriber: - [AVTransport]: Device notification: Node found: [CurrentTrackURI ] : [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/29 17:00:36,236.125: T09834: Subscriber: - [AVTransport]: Device notification: Node found: [CurrentTrackMetaData ] : [<?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/el (...)] 2024/09/29 17:00:36,236.299: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: DIDL/res: [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/29 17:00:36,236.306: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: - duration:[0:00:00] nrAudioChannels:[2] sampleFrequency:[44100] protocolInfo:[http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=01700000000000000000000000000000] 2024/09/29 17:00:36,236.316: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: Metadata was updated on URI: [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/29 17:00:36,236.321: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: -- ReceivedMetadata -- { 2024/09/29 17:00:36,236.338: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: <?xml version="1.0" encoding="utf-8"?> 2024/09/29 17:00:36,236.344: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/"> 2024/09/29 17:00:36,236.349: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: <item restricted="1"> 2024/09/29 17:00:36,236.352: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: <orig>mpd</orig> 2024/09/29 17:00:36,236.356: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: <dc:title>辺獄の深淵</dc:title> 2024/09/29 17:00:36,236.361: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: <upnp:class>object.item.audioItem.musicTrack</upnp:class> 2024/09/29 17:00:36,236.365: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: <dc:creator>西木康智</dc:creator> 2024/09/29 17:00:36,236.368: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: <upnp:artist>西木康智</upnp:artist> 2024/09/29 17:00:36,236.373: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> 2024/09/29 17:00:36,236.377: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: <upnp:originalTrackNumber>02</upnp:originalTrackNumber> 2024/09/29 17:00:36,236.382: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: <res duration="0:00:00" sampleFrequency="44100" nrAudioChannels="2" protocolInfo="http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=01700000000000000000000000000000">http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac</res> 2024/09/29 17:00:36,236.388: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: </item> 2024/09/29 17:00:36,236.393: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: </DIDL-Lite> 2024/09/29 17:00:36,236.398: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: } -- ReceivedMetadata -- 2024/09/29 17:00:36,236.403: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: Upd tag: [TITLE ]: 2024/09/29 17:00:36,236.409: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: Old: [Insonnia] 2024/09/29 17:00:36,236.413: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: New: [辺獄の深淵] 2024/09/29 17:00:36,236.419: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: Upd tag: [ARTIST ]: 2024/09/29 17:00:36,236.423: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: Old: [KOKIA] 2024/09/29 17:00:36,236.427: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: New: [西木康智] 2024/09/29 17:00:36,236.431: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: Upd tag: [ALBUM ]: 2024/09/29 17:00:36,236.436: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: Old: [KOKIA - pieces] 2024/09/29 17:00:36,236.442: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: New: [OCTOPATH TRAVELER - CHAMPIONS (...)] 2024/09/29 17:00:36,236.450: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: Updated metadata found. 2024/09/29 17:00:36,236.454: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: Track: [辺獄の深淵] 2024/09/29 17:00:36,236.729: T09f00: UPnP_P: [UPP_MetaUPThread]: MyURI: Yes [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/29 17:00:36,236.741: T09834: UPnP_P: [Proc:UriAndMeta] <EVT>: UseExDecd mark not found in URI: [DecodeEx:Normal] (FILE) 2024/09/29 17:00:36,236.754: T09834: Subscriber: - [AVTransport]: Device notification: Node found: [TransportState ] : [PLAYING] 2024/09/29 17:00:36,236.869: T09f00: UPnP_P: [ResolveTune]: URI: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/29 17:00:36,236.906: T09f00: UPnP_P: [ResolveTune]: This is mine. 2024/09/29 17:00:36,236.915: T09f00: UPnP_P: [ResolveTune]: Mine:Yes Managed:Yes Recorded:Yes Local file: [\\10.1.1.127\music\OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2\DISC 3\Track_02.flac] 2024/09/29 17:00:36,318.229: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: Getting PositionInfo from device. 2024/09/29 17:00:36,318.550: T02a4c: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] to: 10.1.1.96 [http://10.1.1.96:49153/ctl/AVTransport] 2024/09/29 17:00:36,631.119: T02a4c: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] finished. 2024/09/29 17:00:36,631.232: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> RelTime: 0:00:00 2024/09/29 17:00:36,631.248: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:00 -> 0.0 / 0.0 sec 2024/09/29 17:00:36,631.254: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> TrackURI: http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac 2024/09/29 17:00:36,631.261: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> TrackMetaData: <?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/el (...) 2024/09/29 17:00:37,317.177: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: Getting PositionInfo from device. 2024/09/29 17:00:37,317.532: T02a4c: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] to: 10.1.1.96 [http://10.1.1.96:49153/ctl/AVTransport] 2024/09/29 17:00:37,337.205: T093fc: Subscriber: [Event]: Received UPnP EVENT: [AVTransport] 2024/09/29 17:00:37,337.230: T093fc: Subscriber: - [AVTransport]: Device notification: Node found: [RelativeTimePosition ] : [0:00:01] 2024/09/29 17:00:37,337.247: T093fc: UPnP_P: [Proc:RelTime ] <EVT>: Elapsed: 0:00:01 -> 1.0 / 0.0 sec (Void) 2024/09/29 17:00:37,348.749: T02a4c: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] finished. 2024/09/29 17:00:37,348.890: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> RelTime: 0:00:01 2024/09/29 17:00:37,348.910: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:01 -> 1.0 / 0.0 sec (Void) 2024/09/29 17:00:37,348.918: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> TrackURI: http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac 2024/09/29 17:00:37,348.924: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> TrackMetaData: <?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/el (...) 2024/09/29 17:00:38,315.453: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: Getting PositionInfo from device. 2024/09/29 17:00:38,315.849: T02a4c: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] to: 10.1.1.96 [http://10.1.1.96:49153/ctl/AVTransport] 2024/09/29 17:00:38,353.682: T02a4c: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] finished. 2024/09/29 17:00:38,353.791: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> RelTime: 0:00:02 2024/09/29 17:00:38,353.813: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:02 -> 2.0 / 0.0 sec (Void) 2024/09/29 17:00:38,353.821: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> TrackURI: http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac 2024/09/29 17:00:38,353.828: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> TrackMetaData: <?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/el (...) 2024/09/29 17:00:39,313.938: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: Getting PositionInfo from device. 2024/09/29 17:00:39,314.285: T02a4c: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] to: 10.1.1.96 [http://10.1.1.96:49153/ctl/AVTransport] 2024/09/29 17:00:39,353.899: T02a4c: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] finished. 2024/09/29 17:00:39,354.043: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> RelTime: 0:00:03 2024/09/29 17:00:39,354.061: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:03 -> 3.0 / 0.0 sec (Void) 2024/09/29 17:00:39,354.068: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> TrackURI: http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac 2024/09/29 17:00:39,354.083: T02a4c: UPnP_P: [UPP_WorkerThread]: QuerySOAP: -> TrackMetaData: <?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/el (...) 2024/09/29 17:00:40,314.035: T02a4c: UPnP_P: [UPP_WorkerThread]: Polling SOAP log turns to off. 2024/09/29 17:00:40,353.875: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:04 -> 4.0 / 0.0 sec (Void) 2024/09/29 17:00:41,354.234: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:05 -> 5.0 / 0.0 sec (Void) (per 5 seconds) 2024/09/29 17:00:46,339.559: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:10 -> 10.0 / 0.0 sec (Void) (per 5 seconds) 2024/09/29 17:00:51,336.639: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:15 -> 15.0 / 0.0 sec (Void) (per 5 seconds) 2024/09/29 17:00:56,332.467: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:20 -> 20.0 / 0.0 sec (Void) (per 5 seconds) 2024/09/29 17:01:01,325.072: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:25 -> 25.0 / 0.0 sec (Void) (per 5 seconds) 2024/09/29 17:01:06,325.639: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:30 -> 30.0 / 0.0 sec (Void) (per 10 seconds) 2024/09/29 17:01:16,315.528: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:40 -> 40.0 / 0.0 sec (Void) (per 10 seconds) 2024/09/29 17:01:26,302.414: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:50 -> 50.0 / 0.0 sec (Void) (per 10 seconds) 2024/09/29 17:01:36,292.182: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:01:00 -> 60.0 / 0.0 sec (Void) (per 10 seconds) 2024/09/29 17:01:46,287.018: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:01:10 -> 70.0 / 0.0 sec (Void) (per 10 seconds) 2024/09/29 17:01:56,270.233: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:01:20 -> 80.0 / 0.0 sec (Void) (per 10 seconds) 2024/09/29 17:02:06,260.853: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:01:30 -> 90.0 / 0.0 sec (Void) (per 10 seconds) 2024/09/29 17:02:16,254.792: T02a4c: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:01:40 -> 100.0 / 0.0 sec (Void) (per 10 seconds) 2024/09/29 17:02:26,224.950: T02a4c: Error: UPnP_P: [SOAP Request]: Cannot connect to server: 10.1.1.96 :49153 2024/09/29 17:02:26,224.970: T02a4c: Error: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] was failed. 2024/09/29 17:02:26,224.977: T02a4c: Error: UPnP_P: [SOAP Request]: SOAP request detected error: [ 4] (TFXFWTimeout) 2024/09/29 17:02:26,225.065: T02a4c: UPnP_P: [UPP_WorkerThread]: UnsubscribeAllEvent. 2024/09/29 17:02:26,225.101: T02a4c: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.96 [http://10.1.1.96:49153/evt/OHProduct] 2024/09/29 17:02:29,239.598: T02a4c: Error: Subscriber: [UPP_WorkerThread]: Cannot connect to server: 10.1.1.96 :49153 2024/09/29 17:02:29,239.716: T02a4c: Subscriber: [UPP_WorkerThread]: - Server seems dead: 10.1.1.96 2024/09/29 17:02:29,239.736: T02a4c: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.96 [http://10.1.1.96:49153/evt/OHInfo] 2024/09/29 17:02:29,239.963: T02a4c: Subscriber: [UPP_WorkerThread]: - Server deemed dead: 10.1.1.96 2024/09/29 17:02:29,239.979: T02a4c: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.96 [http://10.1.1.96:49153/evt/OHVolume] 2024/09/29 17:02:29,240.145: T02a4c: Subscriber: [UPP_WorkerThread]: - Server deemed dead: 10.1.1.96 2024/09/29 17:02:29,240.158: T02a4c: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.96 [http://10.1.1.96:49153/evt/OHPlaylist] 2024/09/29 17:02:29,240.280: T02a4c: Subscriber: [UPP_WorkerThread]: - Server deemed dead: 10.1.1.96 2024/09/29 17:02:29,240.290: T02a4c: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.96 [http://10.1.1.96:49153/evt/OHTime] 2024/09/29 17:02:29,240.401: T02a4c: Subscriber: [UPP_WorkerThread]: - Server deemed dead: 10.1.1.96 2024/09/29 17:02:29,240.410: T02a4c: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.96 [http://10.1.1.96:49153/evt/OHRadio] 2024/09/29 17:02:29,240.536: T02a4c: Subscriber: [UPP_WorkerThread]: - Server deemed dead: 10.1.1.96 2024/09/29 17:02:29,240.545: T02a4c: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.96 [http://10.1.1.96:49153/evt/AVTransport] 2024/09/29 17:02:29,240.655: T02a4c: Subscriber: [UPP_WorkerThread]: - Server deemed dead: 10.1.1.96 2024/09/29 17:02:29,240.666: T02a4c: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.96 [http://10.1.1.96:49153/evt/ConnectionManager] 2024/09/29 17:02:29,240.769: T02a4c: Subscriber: [UPP_WorkerThread]: - Server deemed dead: 10.1.1.96 2024/09/29 17:02:29,240.777: T02a4c: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.96 [http://10.1.1.96:49153/evt/RenderingControl] 2024/09/29 17:02:29,240.880: T02a4c: Subscriber: [UPP_WorkerThread]: - Server deemed dead: 10.1.1.96 2024/09/29 17:02:29,240.906: T02a4c: UPnP_P: [UPP_WorkerThread]: Phase 1. 2024/09/29 17:02:29,741.005: T02a4c: UPnP_P: [UPP_InitDevice1] 2: Initialize UPnP info of the Player. 2024/09/29 17:02:29,741.056: T02a4c: UPnP_P: [UPP_InitDevice1] - UPnP is initialized. 2024/09/29 17:02:29,741.079: T02a4c: UPnP_P: [UPP_InitDevice1] - UPnP DeviceInfo: USN:[uuid:188a2caf-c6b7-7fa8-5a9f-cadaebbf02e7::urn:schemas-upnp-org:device:MediaRenderer:1] 2024/09/29 17:02:29,741.094: T02a4c: UPnP_P: [UPP_InitDevice1] - Location: http://10.1.1.96:49153/description.xml 2024/09/29 17:02:29,741.109: T02a4c: UPnP_P: [UPP_InitDevice1] - Name : IFi 2024/09/29 17:02:29,741.125: T02a4c: UPnP_P: [UPP_InitDevice1] - Model : iFi audio 2024/09/29 17:02:29,741.143: T02a4c: UPnP_P: [UPP_InitDevice1] - UPnP Service found: [urn:schemas-upnp-org:service:ConnectionManager:1] 2024/09/29 17:02:29,741.156: T02a4c: UPnP_P: [UPP_InitDevice1] QuerySOAP: Getting ProtocolInfo. 2024/09/29 17:02:29,741.913: T02a4c: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] to: 10.1.1.96 [http://10.1.1.96:49153/ctl/ConnectionManager] 2024/09/29 17:02:32,758.807: T02a4c: Error: UPnP_P: [SOAP Request]: Cannot connect to server: 10.1.1.96 :49153 2024/09/29 17:02:32,758.827: T02a4c: Error: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] was failed. 2024/09/29 17:02:32,758.836: T02a4c: Error: UPnP_P: [SOAP Request]: SOAP request detected error: [ 4] (TFXFWTimeout) 2024/09/29 17:02:32,758.884: T02a4c: Error: UPnP_P: [UPP_InitDevice1] GetProtocolInfo failed. Message: Error: Initializing player failed. Version: 1773
If you need any information from me, please don’t hesitate to let me know.
2024-09-29 19:33 #15516Tikiキーマスターstraid, in Version 5.6.0, the UPnP processing has changed dramatically to meet your needs. The internal processing, which contains temporary statements, has been rearranged, the decoder for HTTP service has been relocated. I have tested that it works on my test devices. There is no going back.
I suspect that the TuneBrowser change is having a negative impact in your environment, but I can’t address it because I don’t know what is wrong with TuneBrowser (if the TuneBrowser is sending UPnP messages that are not compliant with UPnP regulations, please let me know the message. I’ll check it).
2024-09-29 22:48 #15517storaid参加者Hello, Tiki,
It’s a bit difficult to check this issue.
From my packet capture in Wireshark, I found that if the NOTIFY packets are sent later than expected, it might cause the MetaData retrieved by GetPositionInfo to be incorrect.
Additionally, the content of the NOTIFY itself is also incorrect, as shown below:<e:propertyset xmlns:e="urn:schemas-upnp-org:event-1-0"> <e:property> <Metadata><?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/"><item restricted="1"><orig>mpd</orig><dc:title>Road to glory ï½for Dragon Nest White Versionï½</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><dc:creator>KOKIA</dc:creator><upnp:artist>KOKIA</upnp:artist><upnp:album>KOKIA - pieces</upnp:album><upnp:originalTrackNumber>10</upnp:originalTrackNumber><res duration="0:00:00" sampleFrequency="44100" nrAudioChannels="2" protocolInfo="http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=01700000000000000000000000000000">http://10.1.1.160:29400/TuneID/00005338-RFH5959803E.flac_WPRX?Subsong=10&DecodeEx=WavProxy</res></item></DIDL-Lite></Metadata> </e:property> <e:property> <Uri>http://10.1.1.160:29400/TuneID/00005338-RFH5959803E.flac_WPRX?Subsong=10&DecodeEx=WavProxy</Uri> </e:property> <e:property> <TrackCount>91</TrackCount> </e:property> </e:propertyset>
However, I don’t see this issue in v5.5.3.
It’s hard to determine the source of the issue! Orz2024-09-29 23:08 #15518TikiキーマスターIn this case, it seems that your device is recognized flac as “audio/mpeg”. Wouldn’t this be a hint?
2024-09-29 23:40 #15519storaid参加者Hi,
“In this case, it seems that your device is recognized flac as “audio/mpeg”. Wouldn’t this be a hint?”
This issue seems to be related to the entire UPnP processing flow, which makes it difficult to pinpoint the problem.
The following is normal metadata from NOTIFY(when the renderer is getting good work):
Track: 1 TrackDuration: 0:05:15 TrackMetaData: <DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"> <item> <res protocolInfo="http-get:*:audio/wav:*" duration="0:05:14.547" bitsPerSample="24" nrAudioChannels="2" sampleFrequency="44100" DecodeEx="WavProxy">http://10.1.1.160:29400/TuneID/00005329-RFH8454B1D9.flac_WPRX?Subsong=1&DecodeEx=WavProxy</res> <dc:title>KARMA</dc:title> <dc:date>2011</dc:date> <dc:creator>KOKIA</dc:creator> <upnp:album>KOKIA - pieces</upnp:album> <upnp:genre>REM DISCID B10E380D_</upnp:genre> <upnp:artist>KOKIA</upnp:artist> <upnp:originalTrackNumber>01</upnp:originalTrackNumber> <upnp:albumArtURI>http://10.1.1.160:29400/Image/02401.b317751f-2eea-47ca-8d3a3a1bdf66c788.jpg</upnp:albumArtURI> <upnp:class>object.item.audioItem.musicTrack</upnp:class> </item> </DIDL-Lite> TrackURI: http://10.1.1.160:29400/TuneID/00005329-RFH8454B1D9.flac_WPRX?Subsong=1&DecodeEx=WavProxy RelTime: 0:01:17 AbsTime: 0:01:17 RelCount: 0 AbsCount: 0
Did you make any changes to the whole UPnP process flow?
I mean the communication between the Server and the Renderer.
2024-09-29 23:45 #15520TikiキーマスターDid you make any changes to the whole UPnP process flow?
I mean the communication between the Server and the Renderer.
I’m sorry, but I don’t remeber all. But as I said above, there are many changes. What I am interested in is whether or not there is a problem with the current TuneBrowser operation.
2024-09-30 00:49 #15521storaid参加者Hi,
“I’m sorry, but I don’t remeber all. But as I said above, there are many changes. What I am interested in is whether or not there is a problem with the current TuneBrowser operation.”
It’s possible.
How did you get this information??
call GetPositionInfo HTTP API?
2024/09/29 23:44:17,286: UL07322: T06470: Subscriber: [Event]: Received UPnP EVENT: [AVTransport] 2024/09/29 23:44:17,286: UL07324: T06470: Subscriber: - [AVTransport]: Device notification: Node found: [CurrentTrackURI ] : [http://10.1.1.160:29400/TuneID/00005330-RFH2FFDC25A.flac_WPRX?Subsong=2&DecodeEx (...)] 2024/09/29 23:44:17,286: UL07326: T06470: Subscriber: - [AVTransport]: Device notification: Node found: [CurrentTrackMetaData ] : [<?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/el (...)] 2024/09/29 23:44:17,286: UL07328: T06470: UPnP_P: [Proc:UriAndMeta] <EVT>: DIDL/res: [http://10.1.1.160:29400/TuneID/00005330-RFH2FFDC25A.flac_WPRX?Subsong=2&DecodeEx=WavProxy] 2024/09/29 23:44:17,286: UL07330: T06470: UPnP_P: [Proc:UriAndMeta] <EVT>: - duration:[0:00:00] nrAudioChannels:[2] sampleFrequency:[44100] protocolInfo:[http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=01700000000000000000000000000000] 2024/09/29 23:44:17,286: UL07332: T06470: UPnP_P: [Proc:UriAndMeta] <EVT>: New URI found: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00005330-RFH2FFDC25A.flac_WPRX?Subsong=2&DecodeEx=WavProxy] 2024/09/29 23:44:17,286: UL07334: T06470: UPnP_P: [Proc:UriAndMeta] <EVT>: UseExDecd mark is pending. 2024/09/29 23:44:17,286: UL07336: T06470: UPnP_P: [Proc:UriAndMeta] <EVT>: Track: [Insonnia] 2024/09/29 23:44:17,287: UL07338: T06470: UPnP_P: [Proc:UriAndMeta] <EVT>: UseExDecd mark found in URI: [DecodeEx:WavProxy] (WPRX) 2024/09/29 23:44:17,287: UL07340: T06470: UPnP_P: [Proc:UriAndMeta] <EVT>: Post PlayerNotify: 444478 [SpecUpdate]
2024-09-30 01:58 #15522storaid参加者in v.5.6.0, the following is a part of the uPnP process flow with “void” issue:
tool: wireshark
CASE:
[SetAVTransportURI]
<?xml version="1.0" encoding="UTF-8"?> <s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"> <s:Body> <u:SetAVTransportURI xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"> <InstanceID>0</InstanceID> <CurrentURI>http://10.1.1.160:29400/TuneID/00013987-RFH97B535E9.flac</CurrentURI> <CurrentURIMetaData> <DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"> <item> <res protocolInfo="http-get:*:audio/flac:*" duration="0:04:28.516" bitrate="642211" bitsPerSample="16" nrAudioChannels="2" sampleFrequency="44100" DecodeEx="Normal">http://10.1.1.160:29400/TuneID/00013987-RFH97B535E9.flac</res> <dc:title>光の覇</dc:title> <dc:date>2023</dc:date> <dc:creator>西木康智</dc:creator> <dc:publisher>SQUARE ENIX MUSIC</dc:publisher> <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> <upnp:genre>Soundtrack</upnp:genre> <upnp:artist>西木康智</upnp:artist> <upnp:originalTrackNumber>06</upnp:originalTrackNumber> <upnp:albumArtURI>http://10.1.1.160:29400/Image/05651.5b8ee7b5-01a3-4416-97076a1fe6cd6134.jpg</upnp:albumArtURI> <upnp:class>object.item.audioItem.musicTrack</upnp:class> </item> </DIDL-Lite> </CurrentURIMetaData> </u:SetAVTransportURI> </s:Body> </s:Envelope>
|
[RenderingControl:1#GetVolume]
|
[AVTransport:1#GetTransportInfo]
|
[AVTransport:1#Play]
|
(GET /TuneID/00013987-RFH97B535E9.flac HTTP/1.1\r\n)
|
[AVTransport:1#GetPositionInfo]
|<return>
(HTTP/1.1 200 OK)
incorrectly received data<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"> <s:Body> <u:GetPositionInfoResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"> <Track>1</Track> <TrackDuration>0:00:00</TrackDuration> <TrackMetaData> <?xml version="1.0" encoding="utf-8"?> <DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/"> <item restricted="1"> <strong><orig>mpd</orig></strong> <dc:title>光の覇</dc:title> <upnp:class>object.item.audioItem.musicTrack</upnp:class> <dc:creator>西木康智</dc:creator> <upnp:artist>西木康智</upnp:artist> <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> <upnp:originalTrackNumber>06</upnp:originalTrackNumber> <res duration="<strong>0:00:00</strong>" sampleFrequency="44100" nrAudioChannels="2" protocolInfo="<strong>http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=01700000000000000000000000000000</strong>"> [audio src="http://10.1.1.160:29400/TuneID/00013987-RFH97B535E9.flac" /] </res> </item> </DIDL-Lite> </TrackMetaData> <TrackURI>http://10.1.1.160:29400/TuneID/00013987-RFH97B535E9.flac</TrackURI> <RelTime>0:00:00</RelTime> <AbsTime>0:00:00</AbsTime> <RelCount>0</RelCount> <AbsCount>0</AbsCount> </u:GetPositionInfoResponse> </s:Body> </s:Envelope>
The normal received data format is here if no “void” issue occurs.
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"> <s:Body> <u:GetPositionInfoResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"> <Track>1</Track> <TrackDuration>0:04:29</TrackDuration> <TrackMetaData> <DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"> <item> <res<strong> protocolInfo="http-get:*:audio/flac:*" duration="0:04:28.516"</strong> bitrate="642211" bitsPerSample="16" nrAudioChannels="2" sampleFrequency="44100" DecodeEx="Normal">http://10.1.1.160:29400/TuneID/00013987-RFH97B535E9.flac</res> <dc:title>守る者の誓い</dc:title> <dc:date>2023</dc:date> <dc:creator>西木康智</dc:creator> <dc:publisher>SQUARE ENIX MUSIC</dc:publisher> <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> <upnp:genre>Soundtrack</upnp:genre> <upnp:artist>西木康智</upnp:artist> <upnp:originalTrackNumber>06</upnp:originalTrackNumber> <upnp:albumArtURI>http://10.1.1.160:29400/Image/05651.5b8ee7b5-01a3-4416-97076a1fe6cd6134.jpg</upnp:albumArtURI> <upnp:class>object.item.audioItem.musicTrack</upnp:class> </item> </DIDL-Lite> </TrackMetaData> <TrackURI>http://10.1.1.160:29400/TuneID/00013987-RFH97B535E9.flac</TrackURI> <RelTime>0:00:05</RelTime> <AbsTime>0:00:05</AbsTime> <RelCount>0</RelCount> <AbsCount>0</AbsCount> </u:GetPositionInfoResponse> </s:Body> </s:Envelope>
2024-09-30 17:03 #15526storaid参加者Hi,
I have reached out to IFI Audio support to inquire about the issues with the UPnP about returning inconsistent DIDL metadata.
And, waiting for their response.
But don’t expect their efficiency(SLOW).
I’m continuing my investigation to understand what might be causing the inconsistent DIDL metadata. Orz
Thanks
2024-09-30 19:31 #15527Tikiキーマスターin v.5.6.0, the following is a part of the uPnP process flow with “void” issue:
Thank you.
I’ve already checked SetAVTransportURI content in your log.
duration: Normal (SetAVTransportURI)
UL01613: <DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"> UL01615: <item> UL01617: <res protocolInfo="http-get:*:audio/flac:*" duration="0:01:08.638" bitrate="905107" bitsPerSample="16" nrAudioChannels="2" sampleFrequency="44100" DecodeEx="Normal">http://10.1.1.160:29400/TuneID/00013979-RFH491D8236.flac</res> UL01619: <dc:title>絶望を司りし時</dc:title> UL01621: <dc:date>2023</dc:date> UL01623: <dc:creator>西木康智</dc:creator> UL01625: <dc:publisher>SQUARE ENIX MUSIC</dc:publisher> UL01627: <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> UL01629: <upnp:genre>Soundtrack</upnp:genre> UL01631: <upnp:artist>西木康智</upnp:artist> UL01633: <upnp:originalTrackNumber>03</upnp:originalTrackNumber> UL01635: <upnp:albumArtURI>http://10.1.1.160:29400/Image/05649.aad5f8a2-706a-4092-b442f063c78c9c6b.jpg</upnp:albumArtURI> UL01637: <upnp:class>object.item.audioItem.musicTrack</upnp:class> UL01639: </item> UL01641: </DIDL-Lite>
duration: Zero (SetNextAVTransportURI)
UL01783: <DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"> UL01785: <item> UL01787: <res protocolInfo="http-get:*:audio/flac:*" duration="0:06:04.925" bitrate="971356" bitsPerSample="16" nrAudioChannels="2" sampleFrequency="44100" DecodeEx="Normal">http://10.1.1.160:29400/TuneID/00013981-RFHE79A322F.flac</res> UL01789: <dc:title>絶望を授けし者</dc:title> UL01791: <dc:date>2023</dc:date> UL01793: <dc:creator>西木康智</dc:creator> UL01795: <dc:publisher>SQUARE ENIX MUSIC</dc:publisher> UL01797: <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> UL01799: <upnp:genre>Soundtrack</upnp:genre> UL01801: <upnp:artist>西木康智</upnp:artist> UL01803: <upnp:originalTrackNumber>04</upnp:originalTrackNumber> UL01805: <upnp:albumArtURI>http://10.1.1.160:29400/Image/05648.72f755b7-e0fc-428f-8b4a75a7be59e215.jpg</upnp:albumArtURI> UL01807: <upnp:class>object.item.audioItem.musicTrack</upnp:class> UL01809: </item> UL01811: </DIDL-Lite>
There were no problematic differences.
2024-09-30 19:35 #15528TikiキーマスターHow did you get this information??
From subscribing event “AVTransport” or calling GetPositionInfo() API.
2024-09-30 20:51 #15531storaid参加者Hi, Tiki
I have re-checked the UPnP log step by step, and I think the difference is here.
[v5.6.0]-“void” issue
2024/09/30 19:32:28,111: UL17933: T03810: UPnP_P: [SOAP Request]: SOAP request: [Play ] finished. 2024/09/30 19:32:28,111: UL17935: T03810: UPnP_P: PlayImpl: Waiting for state change in 10000 ms. 2024/09/30 19:32:28,631: UL17937: T03810: UPnP_P: PlayImpl: Device event was not detected. SyncActive turns to on. 2024/09/30 19:32:28,632: UL17939: T03810: UPnP_P: PlayImpl: QuerySOAP: Getting volume from device. 2024/09/30 19:32:28,632: UL17941: T03810: UPnP_P: [SOAP Request]: SOAP request: [GetVolume ] to: 10.1.1.96 [http://10.1.1.96:49152/ctl/RenderingControl] 2024/09/30 19:32:28,637: UL17943: T03810: UPnP_P: [SOAP Request]: SOAP request: [GetVolume ] finished. 2024/09/30 19:32:28,637: UL17945: T03810: UPnP_P: PlayImpl: QuerySOAP: -> Volume: 100 2024/09/30 19:32:28,637: UL17947: T03810: UPnP_P: PlayImpl: QuerySOAP: Getting TransportInfo from device. 2024/09/30 19:32:28,637: UL17949: T03810: UPnP_P: [SOAP Request]: SOAP request: [GetTransportInfo ] to: 10.1.1.96 [http://10.1.1.96:49152/ctl/AVTransport] 2024/09/30 19:32:28,666: UL17951: T03810: UPnP_P: [SOAP Request]: SOAP request: [GetTransportInfo ] finished. 2024/09/30 19:32:28,666: UL17953: T03810: UPnP_P: PlayImpl: QuerySOAP: -> TransportStatus: OK 2024/09/30 19:32:28,666: UL17955: T03810: UPnP_P: PlayImpl: QuerySOAP: -> TransportState: PLAYING 2024/09/30 19:32:28,666: UL17957: T03810: UPnP_P: [Proc:TrState ] <POL>: PlayerUPnP UPState changed [STOPPED ] to [PLAYING ] 2024/09/30 19:32:28,666: UL17959: T03810: UPnP_P: [Proc:TrState ] <POL>: PlayerUPnP PLStatus changed [PlayStatus::Stop ] to [PlayStatus::Playing ] 2024/09/30 19:32:28,666: UL17961: T03810: UPnP_P: [Proc:TrState ] <POL>: PlayerStatus: Playing 2024/09/30 19:32:28,666: UL17963: T03810: UPnP_P: [Proc:TrState ] <POL>: PLTTrace assigned: 05 2024/09/30 19:32:28,666: UL17965: T03810: UPnP_P: [Proc:TrState ] <POL>: Post PlayerNotify: 000005 [Start] 2024/09/30 19:32:28,666: UL17967: T03810: UPnP_P: [Proc:TrState ] <POL>: Post PlayerNotify: 000005 [Started] 2024/09/30 19:32:28,666: UL17969: T03810: UPnP_P: [Proc:TrState ] <POL>: State : PLAYING 2024/09/30 19:32:28,666: UL17971: T03810: UPnP_P: PlayImpl: QuerySOAP: Getting PositionInfo from device. 2024/09/30 19:32:28,666: UL17973: T03810: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] to: 10.1.1.96 [http://10.1.1.96:49152/ctl/AVTransport] 2024/09/30 19:32:28,697: UL17975: T03810: UPnP_P: [SOAP Request]: SOAP request: [GetPositionInfo ] finished. 2024/09/30 19:32:28,697: UL17977: T03810: UPnP_P: PlayImpl: QuerySOAP: -> RelTime: 0:00:00 2024/09/30 19:32:28,697: UL17979: T03810: UPnP_P: [Proc:RelTime ] <POL>: Elapsed: 0:00:00 -> 0.0 / 0.0 sec 2024/09/30 19:32:28,697: UL17981: T03810: UPnP_P: PlayImpl: QuerySOAP: -> TrackURI: http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac 2024/09/30 19:32:28,697: UL17983: T03810: UPnP_P: PlayImpl: QuerySOAP: -> TrackMetaData: <?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/el (...) 2024/09/30 19:32:28,697: UL17985: T03810: UPnP_P: [Proc:UriAndMeta] <POL>: DIDL/res: [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/30 19:32:28,697: UL17987: T03810: UPnP_P: [Proc:UriAndMeta] <POL>: - duration:[0:00:00] nrAudioChannels:[2] sampleFrequency:[44100] protocolInfo:[http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=01700000000000000000000000000000] 2024/09/30 19:32:28,697: UL17989: T03810: UPnP_P: [Proc:UriAndMeta] <POL>: New URI found: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/30 19:32:28,698: UL17991: T03810: UPnP_P: [Proc:UriAndMeta] <POL>: UseExDecd mark is pending. 2024/09/30 19:32:28,698: UL17993: T03810: UPnP_P: [Proc:UriAndMeta] <POL>: Track: [辺獄の深淵] 2024/09/30 19:32:28,698: UL17995: T03810: UPnP_P: [Proc:UriAndMeta] <POL>: UseExDecd mark not found in URI: [DecodeEx:Normal] (FILE) 2024/09/30 19:32:28,698: UL17997: T049e0: UPnP_P: [UPP_MetaUPThread]: MyURI: Yes [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/30 19:32:28,698: UL17999: T049e0: UPnP_P: [ResolveTune]: URI: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/30 19:32:28,698: UL18001: T049e0: UPnP_P: [ResolveTune]: This is mine.
[v5.6.0]-normal
2024/09/30 19:34:16,988: UL18829: T03810: UPnP_P: [SOAP Request]: SOAP request: [Play ] finished. 2024/09/30 19:34:16,988: UL18831: T03810: UPnP_P: PlayImpl: Waiting for state change in 10000 ms. 2024/09/30 19:34:17,374: UL18833: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: DIDL/res: [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/30 19:34:17,374: UL18835: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: - protocolInfo:[http-get:*:audio/flac:*] duration:[0:03:25.822] bitsPerSample:[16] 2024/09/30 19:34:17,374: UL18837: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: - bitrate:[881753] sampleFrequency:[44100] nrAudioChannels:[2] DecodeEx:[Normal] 2024/09/30 19:34:17,374: UL18839: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: Metadata was updated on URI: [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/30 19:34:17,374: UL18841: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: -- ReceivedMetadata -- { 2024/09/30 19:34:17,374: UL18843: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"> 2024/09/30 19:34:17,374: UL18845: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <item> 2024/09/30 19:34:17,374: UL18847: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <res protocolInfo="http-get:*:audio/flac:*" duration="0:03:25.822" bitrate="881753" bitsPerSample="16" nrAudioChannels="2" sampleFrequency="44100" DecodeEx="Normal">http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac</res> 2024/09/30 19:34:17,374: UL18849: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <dc:title>辺獄の深淵</dc:title> 2024/09/30 19:34:17,374: UL18851: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <dc:date>2023</dc:date> 2024/09/30 19:34:17,374: UL18853: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <dc:creator>西木康智</dc:creator> 2024/09/30 19:34:17,374: UL18855: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <dc:publisher>SQUARE ENIX MUSIC</dc:publisher> 2024/09/30 19:34:17,374: UL18857: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> 2024/09/30 19:34:17,374: UL18859: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <upnp:genre>Soundtrack</upnp:genre> 2024/09/30 19:34:17,374: UL18861: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <upnp:artist>西木康智</upnp:artist> 2024/09/30 19:34:17,374: UL18863: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <upnp:originalTrackNumber>02</upnp:originalTrackNumber> 2024/09/30 19:34:17,374: UL18865: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <upnp:albumArtURI>http://10.1.1.160:29400/Image/05625.a5a33f89-dc3e-4c1d-9a489069227fea69.jpg</upnp:albumArtURI> 2024/09/30 19:34:17,374: UL18867: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: <upnp:class>object.item.audioItem.musicTrack</upnp:class> 2024/09/30 19:34:17,374: UL18869: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: </item> 2024/09/30 19:34:17,374: UL18871: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: </DIDL-Lite> 2024/09/30 19:34:17,374: UL18873: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: } -- ReceivedMetadata -- 2024/09/30 19:34:17,374: UL18875: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: New tag: [X_CONTEXT_TYPE ]: [Music] 2024/09/30 19:34:17,377: UL18877: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: New tag: [X_ENCODER_TYPE ]: [FLAC] 2024/09/30 19:34:17,377: UL18879: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: New tag: [GENRE ]: [Soundtrack] 2024/09/30 19:34:17,377: UL18881: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: New tag: [X_BITS ]: [16] 2024/09/30 19:34:17,377: UL18883: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: Upd tag: [X_DURATION ]: 2024/09/30 19:34:17,377: UL18885: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: Old: [0.000] 2024/09/30 19:34:17,377: UL18887: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: New: [205.822] 2024/09/30 19:34:17,377: UL18889: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: New tag: [DATE ]: [2023] 2024/09/30 19:34:17,377: UL18891: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: New tag: [X_BITRATE ]: [881753] 2024/09/30 19:34:17,377: UL18893: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: New tag: [ORGANIZATION ]: [SQUARE ENIX MUSIC] 2024/09/30 19:34:17,377: UL18895: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: New tag: [X_IMAGEFILE ]: [http://10.1.1.160:29400/Image/ (...)] 2024/09/30 19:34:17,377: UL18897: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: Updated metadata found. 2024/09/30 19:34:17,377: UL18899: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: UseExDecd mark is pending. 2024/09/30 19:34:17,378: UL18901: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: Track: [辺獄の深淵] 2024/09/30 19:34:17,378: UL18903: T04978: UPnP_P: [Proc:UriAndMeta] <POL>: UseExDecd mark not found in URI: [DecodeEx:Normal] (FILE) 2024/09/30 19:34:17,378: UL18905: T049e0: UPnP_P: [UPP_MetaUPThread]: MyURI: Yes [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/30 19:34:17,378: UL18907: T049e0: UPnP_P: [ResolveTune]: URI: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00013977-RFHF825DADC.flac] 2024/09/30 19:34:17,378: UL18909: T049e0: UPnP_P: [ResolveTune]: This is mine.
[v5.5.3]- no details
2024/09/30 19:35:35,105: UL01748: T05384: UPnP_P: [SOAP Request]: SOAP request: [Play ] to: 10.1.1.96 [http://10.1.1.96:49152/ctl/AVTransport] 2024/09/30 19:35:35,136: UL01749: T044d4: HTTPServer: [10.1.1.96 :41926]: Socket accepted. 2024/09/30 19:35:35,137: UL01750: T08684: HTTPServer: [10.1.1.96 :41926]: Processing [GET] /TuneID/00013977-RFHF825DADC.flac 2024/09/30 19:35:35,137: UL01751: T08684: HTTPServer: [10.1.1.96 :41926]: Tune: 00013977-RFHF825DADC.flac -> 2024/09/30 19:35:35,137: UL01752: T08684: HTTPServer: [10.1.1.96 :41926]: \\10.1.1.127\music\OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2\DISC 3\Track_02.flac 2024/09/30 19:35:35,137: UL01754: T08684: HTTPServer: [10.1.1.96 :41926]: Begin monitoring playback. 2024/09/30 19:35:35,137: UL01756: T06f64: UPnP_P: Post PlayerNotify: 7005 [SpecUpdate] 2024/09/30 19:35:35,138: UL01758: T06f64: UPnP_P: Proc PlayerNotify: 7005 [SpecUpdate] 2024/09/30 19:35:35,146: UL01760: T05384: UPnP_P: [SOAP Request]: SOAP request: [Play ] finished. 2024/09/30 19:35:35,146: UL01762: T05384: UPnP_P: PlayImpl: Post PlayerNotify: 7006 [SpecUpdate] 2024/09/30 19:35:35,146: UL01764: T05384: UPnP_P: PlayImpl: Player is UnderControl. 2024/09/30 19:35:35,146: UL01766: T05384: UPnP_P: PlayImpl: Post PlayerNotify: 7007 [SpecUpdate] 2024/09/30 19:35:35,146: UL01768: T05384: UPnP_P: PlayImpl: Waiting for state change in 10000 ms. 2024/09/30 19:35:35,147: UL01770: T06f64: UPnP_P: Proc PlayerNotify: 7006 [SpecUpdate] 2024/09/30 19:35:35,154: UL01772: T06f64: UPnP_P: Proc PlayerNotify: 7007 [SpecUpdate] 2024/09/30 19:35:35,167: UL01773: T04510: --> 10.1.1.96 :29500 EVENT /SR_AVTransport.notify: uuid:15abc318-7f20-11ef-8099-935d6bcf76b6 2024/09/30 19:35:35,171: UL01775: T04510: Subscriber: [Event]: Received EVENT: [AVTransport] 2024/09/30 19:35:35,171: UL01777: T04510: Subscriber: - [AVTransport]: Device notification: Node found: [TransportState ] : [PLAYING] 2024/09/30 19:35:35,171: UL01779: T04510: UPnP_P: [Proc:TrState ] <EVT>: PlayerUPnP UPState changed [STOPPED ] to [PLAYING ] 2024/09/30 19:35:35,171: UL01781: T04510: UPnP_P: [Proc:TrState ] <EVT>: PlayerUPnP PLStatus changed [PlayStatus::Stop ] to [PlayStatus::Playing ] 2024/09/30 19:35:35,171: UL01783: T04510: UPnP_P: [Proc:TrState ] <EVT>: PlayerStatus: Playing 2024/09/30 19:35:35,171: UL01785: T04510: UPnP_P: [Proc:TrState ] <EVT>: PLTTrace assigned: 01 2024/09/30 19:35:35,171: UL01787: T04510: UPnP_P: [Proc:TrState ] <EVT>: Post PlayerNotify: 0001 [Start] 2024/09/30 19:35:35,171: UL01789: T04510: UPnP_P: [Proc:TrState ] <EVT>: Post PlayerNotify: 0001 [Started] 2024/09/30 19:35:35,171: UL01791: T04510: UPnP_P: [Proc:TrState ] <EVT>: State : PLAYING 2024/09/30 19:35:35,171: UL01793: T04510: Subscriber: - [AVTransport]: Device notification: Node found: [CurrentTrackMetaData ] : [<DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http:/ (...)] 2024/09/30 19:35:35,176: UL01795: T05384: UPnP_P: PlayImpl: State change detected. 2024/09/30 19:35:35,176: UL01797: T05384: UPnP_P: PlayImpl: Waiting for state change has done in 30 ms. 2024/09/30 19:35:35,176: UL01799: T05384: UPnP_P: PlayImpl: Waiting for state change before seek in 10000 ms.
From checking these UPnP logs, I think the problem is still likely that the metadata obtained through SUBSCRIBE Event or GetPositionInfo is inconsistent with the original metadata sent during the SetAVTransportURI call.
Wireshark can at best capture and analyze the packets, but I don’t know exactly what behaviors occur during these processes.
However, there’s only so much I can do.
2024-10-01 12:43 #15533storaid参加者Here is the GPT4o reply I ask..
When the
SetAVTransportURI
command is sent, the Renderer may need some time to complete the internal state updates. If theGetPositionInfo
request is made before this process is fully completed, the DIDL data retrieved may be incomplete or incorrect.Adding a delay between sending the
SetAVTransportURI
command and making theGetPositionInfo
request might help. For example, adding a delay of about 500 milliseconds to 1 second to ensure that the state change is fully processed.2024-10-01 17:36 #15534storaid参加者Hi, Tiki
Here is ifi-audio response
Thank you for getting in touch regarding your ZEN Stream. I don’t know exactly why this would occur, unfortunately. It could be that the metadata containing the current position is temporarily stored in the buffer/cache when it is called for and other times it is not stored at all, then when it is called upon it retrieves the old info which is wrong. I do not know, unfortunately, however, your testing is clear and you have given us some great information so that I can pass this straight on to our development team.
it seems the metadata inconsistency from the upnp renderer might be due to the metadata being temporarily stored in the buffer/cache, leading to retrieval of old or incorrect information during GetPositionInfo calls.
2024-10-01 17:53 #15535storaid参加者possible solutions:
1. Increase Delay: Adding a delay between SetAVTransportURI and GetPositionInfo requests to ensure the Renderer’s internal state is fully updated.
2. Retry Mechanism: Implementing a retry mechanism to re-fetch metadata if the initial retrieval returns incorrect data.
maybe it wouldn’t accidentally retrieve old incorrect data from the buffer/cache.
2024-10-01 19:13 #15536TikiキーマスターI think both are no good. As I explained above, the case in your log occurs on the track set by SetNextAVTransportURI() and cannot be determined to be invalid data, so neither response can be remedied.
20:45:04,600: UL01777: File: 10.1.1.127 [\\10.1.1.127\music\OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2\DISC 3\Track_04.flac] 20:45:04,600: UL01779: URI: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00013981-RFHE79A322F.flac] 20:45:04,600: UL01781: -- CreatedMetadata -- { 20:45:04,600: UL01783: <DIDL-Lite xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/"> 20:45:04,600: UL01785: <item> 20:45:04,600: UL01787: <res protocolInfo="http-get:*:audio/flac:*" duration="0:06:04.925" bitrate="971356" bitsPerSample="16" nrAudioChannels="2" sampleFrequency="44100" DecodeEx="Normal">http://10.1.1.160:29400/TuneID/00013981-RFHE79A322F.flac</res> 20:45:04,600: UL01789: <dc:title>絶望を授けし者</dc:title> 20:45:04,600: UL01791: <dc:date>2023</dc:date> 20:45:04,600: UL01793: <dc:creator>西木康智</dc:creator> 20:45:04,600: UL01795: <dc:publisher>SQUARE ENIX MUSIC</dc:publisher> 20:45:04,600: UL01797: <upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album> 20:45:04,600: UL01799: <upnp:genre>Soundtrack</upnp:genre> 20:45:04,600: UL01801: <upnp:artist>西木康智</upnp:artist> 20:45:04,600: UL01803: <upnp:originalTrackNumber>04</upnp:originalTrackNumber> 20:45:04,600: UL01805: <upnp:albumArtURI>http://10.1.1.160:29400/Image/05648.72f755b7-e0fc-428f-8b4a75a7be59e215.jpg</upnp:albumArtURI> 20:45:04,600: UL01807: <upnp:class>object.item.audioItem.musicTrack</upnp:class> 20:45:04,600: UL01809: </item> 20:45:04,600: UL01811: </DIDL-Lite> 20:45:04,600: UL01813: } -- CreatedMetadata -- 20:45:04,600: UL01815: CommandSOAP: AVTransport:SetNextAVTransportURI 20:45:29,747: UL02905: <POL>: New URI found: 10.1.1.160 [http://10.1.1.160:29400/TuneID/00013981-RFHE79A322F.flac] 20:45:30,492: UL03011: Device notification: Node found: [CurrentTrackURI ] : [http://10.1.1.160:29400/TuneID/00013981-RFHE79A322F.flac] 20:45:30,492: UL03013: Device notification: Node found: [CurrentTrackMetaData ] : [<?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/el (...)] 20:45:30,492: UL03015: <EVT>: DIDL/res: [http://10.1.1.160:29400/TuneID/00013981-RFHE79A322F.flac] 20:45:30,492: UL03017: <EVT>: - duration:[0:00:00] nrAudioChannels:[2] sampleFrequency:[44100] protocolInfo:[http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=01700000000000000000000000000000]
2024-10-01 22:30 #15542storaid参加者Hi, Tiki
I monitored the UPnP renderer (ifi-audio) using the UPnP development tool and found that the same issue exists in v5.6.0 as well.
It seems that the previous version didn’t fully rely on DIDL metadata.Could something have changed in v5.6.0?
v5.5.3
Origin: OpenSource.UPnP.HTTPSession [53760061] Time: 10/1/2024 9:19:27 PM NOTIFY /48e75bf1-ed45-6dbf-cc31-cadaebbf02e7/urn:upnp-org:serviceId:AVTransport HTTP/1.1 NT: upnp:event HOST: 10.1.1.160:51862 NTS: upnp:propchange SID: uuid:65ae5b78-7ff7-11ef-a2b0-c7d69a21891a SEQ: 22 CONTENT-TYPE: text/xml; charset="utf-8" Content-Length: 3826 <e:propertyset xmlns:e="urn:schemas-upnp-org:event-1-0"> <e:property> <LastChange> <Event xmlns="urn:schemas-upnp-org:metadata-1-0/AVT_RCS"> <InstanceID val="0"> <CurrentTrackURI val="http://10.1.1.160:29400/TuneID/00013979-RFH491D8236.flac"/> <TransportState val="PLAYING"/> <CurrentMediaDuration val="0:01:09"/> <CurrentTrackMetaData val="<?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/"><item restricted="1"><orig>mpd</orig><dc:title>絶望を司りし時</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><dc:creator>西木康智</dc:creator><upnp:artist>西木康智</upnp:artist><upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album><upnp:originalTrackNumber>03</upnp:originalTrackNumber><res duration="0:00:00" sampleFrequency="44100" nrAudioChannels="2" protocolInfo="http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=01700000000000000000000000000000">http://10.1.1.160:29400/TuneID/00013979-RFH491D8236.flac</res></item></DIDL-Lite>"/> <CurrentTransportActions val="Next,Previous,Pause,Stop,Seek"/> <AVTransportURI val="http://10.1.1.160:29400/TuneID/00013979-RFH491D8236.flac"/> <AbsoluteTimePosition val="0:00:01"/> <CurrentTrackDuration val="0:01:09"/> <RelativeTimePosition val="0:00:01"/> <AVTransportURIMetaData val="<?xml version="1.0" encoding="utf-8"?><DIDL-Lite xmlns:dc="http://purl.org/dc/elements/1.1/" xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/" xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dlna="urn:schemas-dlna-org:metadata-1-0/"><item restricted="1"><orig>mpd</orig><dc:title>絶望を司りし時</dc:title><upnp:class>object.item.audioItem.musicTrack</upnp:class><dc:creator>西木康智</dc:creator><upnp:artist>西木康智</upnp:artist><upnp:album>OCTOPATH TRAVELER - CHAMPIONS OF THE CONTINENT ORIGINAL SOUNDTRACK vol.2</upnp:album><upnp:originalTrackNumber>03</upnp:originalTrackNumber><res duration="0:00:00" sampleFrequency="44100" nrAudioChannels="2" protocolInfo="http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;DLNA.ORG_CI=0;DLNA.ORG_FLAGS=01700000000000000000000000000000">http://10.1.1.160:29400/TuneID/00013979-RFH491D8236.flac</res></item></DIDL-Lite>"/> <NextAVTransportURI val="http://10.1.1.160:29400/TuneID/00013981-RFHE79A322F.flac"/> <PlaybackStorageMedium val="HDD"/> </InstanceID> </Event> </LastChange> </e:property> </e:propertyset>
2024-10-01 22:48 #15543TikiキーマスターAs I have already said, a lot has changed in 5.6.0 to achieve the new functionality.
2024-10-01 23:03 #15544storaid参加者Hi, Tiki
“As I have already said, a lot has changed in 5.6.0 to make it work.”
I see..
it’s my guess.
In the previous version ,is the total track length retrieved by the UI timebar obtained from the TrackDuration value in GetPositionInfo or the MediaDuration value in GetMediaInfo ?
Starting from v5.6.0, does it completely use DIDL metadata?
2024-10-01 23:09 #15545TikiキーマスターI think the handling of duration has not changed between versions.
2024-10-01 23:18 #15546storaid参加者“I think the handling of duration has not changed between versions.”
Ok
If that is the case, even if the DIDL metadata format obtained from the renderer is incorrect.
I don’t know exactly why the total track length retrieved by the UI timebar function in version v5.5.3 is working well.
2024-10-02 09:11 #15548storaid参加者Hi, Tiki
here is the difference the timebar function is still working in v5.5.3, even if the DIDL metadata is inconsistent.
as you said above, if the handling of duration logic has not changed in v5.6.0, that timebar function should be working the same as with the previous version.
but in fact this is not the case.
also, that’s a question maybe you changed something for timebar function?
thanks
2024-10-02 19:55 #15550TikiキーマスターThank you for testing. I am surprised. Since the days of TuneBrowser v5.5.3, your device was returning duration 0.
Then it is not a problem with the TuneBrowser UPnP sequence, but with the metadata process. It is true that since 5.6.0, metadata changes are checked. Because devices can be controlled by other controllers.
I think that the behavior of v5.5.3 is problematic, and that the behavior of v5.6.0 is correct.
I regret the UPnP improvements in this release and, as I have feared from the beginning, I feel again that UPnP support is very difficult. It is not easy to determine what should I do. Please understand.
2024-10-02 22:01 #15555storaid参加者Hi, Tiki
Thanks for your explanation..
I’ve expanded my testing with other music players.
Foobar2000 and Synology Audio Station both have the same issue.
For the ifi UPnP renderer device, inconsistent metadata should be a bug.
However, interestingly, to keep compatibility with certain brands, they’ve added support for the OpenHome UPnP API.
Since the ifi UPnP renderer natively retains OpenHome API support.
I’ve noticed that Foobar2000 and Synology Audio Station prioritize calling the OpenHome UPnP API, so they are not affected by the inconsistent metadata bug.
I will continue communicating with ifi-audio tech support, hoping to resolve this very basic error.
Thanks
2024-10-02 22:52 #15556TikiキーマスターThanks. I’d close this topic.
-
投稿者投稿
- トピック「UI issue: timebar’s progress bar display」には新しい返信をつけることはできません。