フォーラム › TuneBrowser › UI issue: Intermittent initialization failed player error
-
投稿者投稿
-
2024-10-05 18:31 #15573storaid参加者
Hi, Tiki
I sometimes encounter this strange error..
2024/10/05 17:09:06,150.327: T0b7b8: Error: UPnP_P: [SOAP Request]: Cannot connect to server: 10.1.1.97 :49152 2024/10/05 17:09:06,150.349: T0b7b8: Error: UPnP_P: [SOAP Request]: SOAP request: [GetVolume ] was failed. 2024/10/05 17:09:06,150.356: T0b7b8: Error: UPnP_P: [SOAP Request]: SOAP request detected error: [ 4] (TFXFWTimeout) 2024/10/05 17:09:06,150.447: T0b7b8: UPnP_P: [UPP_WorkerThread]: UnsubscribeAllEvent. 2024/10/05 17:09:06,150.487: T0b7b8: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.97 [http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/evt-urn-schemas-upnp-org-service-AVTransport-1] 2024/10/05 17:09:09,164.218: T0b7b8: Subscriber: [UPP_WorkerThread]: - Server seems dead: 10.1.1.97 2024/10/05 17:09:09,164.250: T0b7b8: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.97 [http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/evt-urn-schemas-upnp-org-service-ConnectionManager-1] 2024/10/05 17:09:09,164.554: T0b7b8: Subscriber: [UPP_WorkerThread]: - Server deemed dead: 10.1.1.97 2024/10/05 17:09:09,164.571: T0b7b8: Subscriber: [UPP_WorkerThread]: UnsubscribeEvent: 10.1.1.97 [http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/evt-urn-schemas-upnp-org-service-RenderingControl-1] 2024/10/05 17:09:09,164.716: T0b7b8: Subscriber: [UPP_WorkerThread]: - Server deemed dead: 10.1.1.97 2024/10/05 17:09:09,164.752: T0b7b8: UPnP_P: [UPP_WorkerThread]: Phase 1. 2024/10/05 17:09:09,664.748: T0b7b8: UPnP_P: [UPP_InitDevice1] 2: Initialize UPnP info of the Player. 2024/10/05 17:09:09,664.771: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP is initialized. 2024/10/05 17:09:09,664.785: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP DeviceInfo: USN:[uuid:87f1e18e-7e24-b992-8383-d83adde83eaf::urn:schemas-upnp-org:device:MediaRenderer:1] 2024/10/05 17:09:09,664.797: T0b7b8: UPnP_P: [UPP_InitDevice1] - Location: http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/description.xml 2024/10/05 17:09:09,664.806: T0b7b8: UPnP_P: [UPP_InitDevice1] - Name : Red_10.1.1.97-UPnP/AV 2024/10/05 17:09:09,664.815: T0b7b8: UPnP_P: [UPP_InitDevice1] - Model : UpMPD 2024/10/05 17:09:09,664.828: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP Service found: [urn:schemas-upnp-org:service:ConnectionManager:1] 2024/10/05 17:09:09,664.836: T0b7b8: UPnP_P: [UPP_InitDevice1] QuerySOAP: Getting ProtocolInfo. 2024/10/05 17:09:09,665.313: T0b7b8: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] to: 10.1.1.97 [http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/ctl-urn-schemas-upnp-org-service-ConnectionManager-1] 2024/10/05 17:09:12,677.949: T0b7b8: Error: UPnP_P: [SOAP Request]: Cannot connect to server: 10.1.1.97 :49152 2024/10/05 17:09:12,677.970: T0b7b8: Error: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] was failed. 2024/10/05 17:09:12,677.979: T0b7b8: Error: UPnP_P: [SOAP Request]: SOAP request detected error: [ 4] (TFXFWTimeout) 2024/10/05 17:09:12,678.005: T0b7b8: Error: UPnP_P: [UPP_InitDevice1] GetProtocolInfo failed.
You can see the connection failure issue in the log above…
Even so, TuneBrowser eventually manages to connect to the UPnP Renderer successfully.
Apparently, it has a retry feature.
Could the error message only appear after the retry limit is reached?
I think displaying this message prematurely might cause confusion…
Thanks
2024-10-05 20:06 #15577TikiキーマスターIt seems that SOAP call is failing. Then it is an error. There is no retry for SOAP call. I think it just succeeds on the next SOAP call.
2024-10-05 20:23 #15579storaid参加者Hi, Tiki,
Sorry, I may not have explained clearly enough.
2024/10/05 17:09:09,164: UL13826: T0b7b8: UPnP_P: [UPP_WorkerThread]: Phase 1. 2024/10/05 17:09:09,664: UL13828: T0b7b8: UPnP_P: [UPP_InitDevice1] 2: Initialize UPnP info of the Player. 2024/10/05 17:09:09,664: UL13830: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP is initialized. 2024/10/05 17:09:09,664: UL13832: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP DeviceInfo: USN:[uuid:87f1e18e-7e24-b992-8383-d83adde83eaf::urn:schemas-upnp-org:device:MediaRenderer:1] 2024/10/05 17:09:09,664: UL13834: T0b7b8: UPnP_P: [UPP_InitDevice1] - Location: http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/description.xml 2024/10/05 17:09:09,664: UL13836: T0b7b8: UPnP_P: [UPP_InitDevice1] - Name : Red_10.1.1.97-UPnP/AV 2024/10/05 17:09:09,664: UL13838: T0b7b8: UPnP_P: [UPP_InitDevice1] - Model : UpMPD 2024/10/05 17:09:09,664: UL13840: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP Service found: [urn:schemas-upnp-org:service:ConnectionManager:1] 2024/10/05 17:09:09,664: UL13842: T0b7b8: UPnP_P: [UPP_InitDevice1] QuerySOAP: Getting ProtocolInfo. 2024/10/05 17:09:09,665: UL13844: T0b7b8: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] to: 10.1.1.97 [http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/ctl-urn-schemas-upnp-org-service-ConnectionManager-1] 2024/10/05 17:09:12,677: UL13868: T0b7b8: Error: UPnP_P: [SOAP Request]: Cannot connect to server: 10.1.1.97 :49152 2024/10/05 17:09:12,677: UL13870: T0b7b8: Error: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] was failed. 2024/10/05 17:09:12,677: UL13872: T0b7b8: Error: UPnP_P: [SOAP Request]: SOAP request detected error: [ 4] (TFXFWTimeout) 2024/10/05 17:09:12,678: UL13874: T0b7b8: Error: UPnP_P: [UPP_InitDevice1] GetProtocolInfo failed. 2024/10/05 17:09:12,778: UL13877: T0b7b8: UPnP_P: [UPP_InitDevice1] 3: Initialize UPnP info of the Player. 2024/10/05 17:09:12,778: UL13879: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP is initialized. 2024/10/05 17:09:12,778: UL13881: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP DeviceInfo: USN:[uuid:87f1e18e-7e24-b992-8383-d83adde83eaf::urn:schemas-upnp-org:device:MediaRenderer:1] 2024/10/05 17:09:12,778: UL13883: T0b7b8: UPnP_P: [UPP_InitDevice1] - Location: http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/description.xml 2024/10/05 17:09:12,778: UL13885: T0b7b8: UPnP_P: [UPP_InitDevice1] - Name : Red_10.1.1.97-UPnP/AV 2024/10/05 17:09:12,778: UL13887: T0b7b8: UPnP_P: [UPP_InitDevice1] - Model : UpMPD 2024/10/05 17:09:12,778: UL13889: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP Service found: [urn:schemas-upnp-org:service:ConnectionManager:1] 2024/10/05 17:09:12,778: UL13891: T0b7b8: UPnP_P: [UPP_InitDevice1] QuerySOAP: Getting ProtocolInfo. 2024/10/05 17:09:12,779: UL13893: T0b7b8: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] to: 10.1.1.97 [http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/ctl-urn-schemas-upnp-org-service-ConnectionManager-1] 2024/10/05 17:09:15,794: UL13895: T0b7b8: Error: UPnP_P: [SOAP Request]: Cannot connect to server: 10.1.1.97 :49152 2024/10/05 17:09:15,794: UL13897: T0b7b8: Error: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] was failed. 2024/10/05 17:09:15,794: UL13899: T0b7b8: Error: UPnP_P: [SOAP Request]: SOAP request detected error: [ 4] (TFXFWTimeout) 2024/10/05 17:09:15,794: UL13901: T0b7b8: Error: UPnP_P: [UPP_InitDevice1] GetProtocolInfo failed. 2024/10/05 17:09:15,894: UL13903: T0b7b8: UPnP_P: [UPP_InitDevice1] 4: Initialize UPnP info of the Player. 2024/10/05 17:09:15,894: UL13905: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP is initialized. 2024/10/05 17:09:15,894: UL13907: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP DeviceInfo: USN:[uuid:87f1e18e-7e24-b992-8383-d83adde83eaf::urn:schemas-upnp-org:device:MediaRenderer:1] 2024/10/05 17:09:15,894: UL13909: T0b7b8: UPnP_P: [UPP_InitDevice1] - Location: http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/description.xml 2024/10/05 17:09:15,894: UL13911: T0b7b8: UPnP_P: [UPP_InitDevice1] - Name : Red_10.1.1.97-UPnP/AV 2024/10/05 17:09:15,894: UL13913: T0b7b8: UPnP_P: [UPP_InitDevice1] - Model : UpMPD 2024/10/05 17:09:15,894: UL13915: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP Service found: [urn:schemas-upnp-org:service:ConnectionManager:1] 2024/10/05 17:09:15,894: UL13917: T0b7b8: UPnP_P: [UPP_InitDevice1] QuerySOAP: Getting ProtocolInfo. 2024/10/05 17:09:15,895: UL13919: T0b7b8: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] to: 10.1.1.97 [http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/ctl-urn-schemas-upnp-org-service-ConnectionManager-1] 2024/10/05 17:09:18,905: UL13922: T0b7b8: Error: UPnP_P: [SOAP Request]: Cannot connect to server: 10.1.1.97 :49152 2024/10/05 17:09:18,905: UL13924: T0b7b8: Error: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] was failed. 2024/10/05 17:09:18,905: UL13926: T0b7b8: Error: UPnP_P: [SOAP Request]: SOAP request detected error: [ 4] (TFXFWTimeout) 2024/10/05 17:09:18,906: UL13928: T0b7b8: Error: UPnP_P: [UPP_InitDevice1] GetProtocolInfo failed. 2024/10/05 17:09:19,006: UL13930: T0b7b8: UPnP_P: [UPP_InitDevice1] 5: Initialize UPnP info of the Player. 2024/10/05 17:09:19,006: UL13932: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP is initialized. 2024/10/05 17:09:19,006: UL13934: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP DeviceInfo: USN:[uuid:87f1e18e-7e24-b992-8383-d83adde83eaf::urn:schemas-upnp-org:device:MediaRenderer:1] 2024/10/05 17:09:19,006: UL13936: T0b7b8: UPnP_P: [UPP_InitDevice1] - Location: http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/description.xml 2024/10/05 17:09:19,006: UL13938: T0b7b8: UPnP_P: [UPP_InitDevice1] - Name : Red_10.1.1.97-UPnP/AV 2024/10/05 17:09:19,006: UL13940: T0b7b8: UPnP_P: [UPP_InitDevice1] - Model : UpMPD 2024/10/05 17:09:19,006: UL13942: T0b7b8: UPnP_P: [UPP_InitDevice1] - UPnP Service found: [urn:schemas-upnp-org:service:ConnectionManager:1] 2024/10/05 17:09:19,006: UL13944: T0b7b8: UPnP_P: [UPP_InitDevice1] QuerySOAP: Getting ProtocolInfo. 2024/10/05 17:09:19,010: UL13946: T0b7b8: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] to: 10.1.1.97 [http://10.1.1.97:49152/uuid-87f1e18e-7e24-b992-8383-d83adde83eaf/ctl-urn-schemas-upnp-org-service-ConnectionManager-1] 2024/10/05 17:09:22,544: UL13951: T0b7b8: UPnP_P: [SOAP Request]: SOAP request: [GetProtocolInfo ] finished.
From the log, it looks very similar to a retry operation.
However, my key point is that unless the connection completely fails,
I think the following error message should not appear, as it might cause confusion…
2024-10-06 07:52 #15582TikiキーマスターIn this case, logs show that initializing is continuing. There is no reason to stop the initialization other than to exit TuneBrowser or change the playback device.
An error in GetProtocolInfo means that the SOAP call has failed after SSDP has confirmed that the device is alive, so it is judged to be an error.
I understand your feeling that the error message is annoying, but I think the device is actually behaving strangely, and since other users may not be the ones looking at the logs as you are, TuneBrowser is notifying you of the situation.
2024-10-06 11:07 #15587storaid参加者Hi, Tiki
If the log isn’t checked, seeing an error message pop-up in the UI might cause some misunderstanding, since the device might eventually connect successfully.
Therefore, I think the error message pop-up should be suppressed in the UI unless the device completely fails to connect.
Thanks
2024-10-06 19:37 #15597TikiキーマスターI’ll make the timeout value adjustable in the next release. If the timeout is extended, the error will probably not be detected in your case.
2024-10-11 18:14 #15620TikiキーマスターHello.
I’ve released 1776.
– TreeItem: Basic – Network
– Property: OpenHome/UPnP – UPnPSOAP – Connet timeout (ms)Try to increase this value like 30000 (30sec).
2024-10-11 22:55 #15627storaid参加者Hello, Tiki
I’ve been testing for a few hours now, and it looks like the random message pop-up is not showing up anymore.
Thanks
and, a simple question
Does the term “Connet timeout” mean “Connection timeout”?
If so, I think “Connection timeout” is the better term.
2024-10-12 07:37 #15629TikiキーマスターThank you for confirmation.
Sorry for the messy English. I will fix it in the next release.
2024-10-18 20:29 #15646TikiキーマスターHi,
I’m fixed my messy English. Thanks for your notification.
-
投稿者投稿
- トピック「UI issue: Intermittent initialization failed player error」には新しい返信をつけることはできません。