philippe44 / LMS-uPnP

Integrate UPnP players with LogitechMediaServer
108 stars 17 forks source link

HDMI Connection Causes Crash #37

Closed PilotFlying closed 4 years ago

PilotFlying commented 4 years ago

Windows 10 64-bit, latest patches:

On connecting my TV to the PC via HDMI, squeeze2upnp-win.exe crashes with XMLGetFirstDocumentItem:176 (BUG) ixmlNode_getFirstChild(tmpNode) returned NULL (full log attached).

If I disconnect the HDMI cable (or turn off the TV) squeeze2upnp succeeds in restarting.

The TV does present a soundcard to windows. I tried disabling it in the windows audio control panel but it didn't help (squeeze2upnp keeps crashing until either the TV is off or the HDMI cable is disconnected).

As a sidenote, the HDMI/TV soundcard is unrelated to the whole playback chain (which is spotty -> LMS -> LMS-to-uPnp -> foobar2000 -> other soundcard).

Many thanks for this really useful plugin!

> Starting Squeeze2upnp: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -f C:\ProgramData\Squeezebox\Logs\upnpbridge.log -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml
> [12:17:25.323] main:1685 Starting squeeze2upnp version: v1.25.1 (Dec 21 2019 @ 13:41:22)
> [12:17:25.338] output_init:603 success loading FLAC encoder
> [12:17:25.348] Start:1452 Binding to 192.168.1.14:49152
> [12:17:28.514] AddMRDevice:1343 [004C1960]: adding renderer (foobar2000 Renderer (username) [PCNAME])
> [12:17:28.567] MasterHandler:1001 [004C1960]: subscribe success
> [12:17:28.762] slimproto:855 squeezelite [0050C580] <=> player [004C1960]
> [12:17:28.762] slimproto:856 [0050C580] connecting to 169.254.217.168:3483
> [12:17:28.762] slimproto:886 [0050C580] connected
> [12:17:28.762] sendHELO:133 [0050C580] cap: CanHTTPS=1,Model=squeezelite,ModelName=SqueezeLite,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=48000,aac,ogg,flc,alc,aif,pcm,mp3
> [12:17:28.771] process_strm:235 [0050C580] strm command s
> [12:17:28.771] process_strm:304 [0050C580], strm s autostart: 1 transition period: 10 transition type: 0 codec: p
> [12:17:28.771] sendSTAT:166 [0050C580]: STAT:[STMf] msplayed 0
> [12:17:28.772] sq_get_metadata:375 [0050C580]: cannot get metadata
> [12:17:28.772] bind_socket:397 cannot bind socket 1244
> [12:17:28.772] output_start:82 [0050C580]: start thread 0
> [12:17:28.772] process_start:1191 [0050C580]: codec:p, ch:2, s:16, r:44100
> [12:17:28.772] sendSTAT:166 [0050C580]: STAT:[STMc] msplayed 0
> [12:17:28.772] process_strm:339 [0050C580] no matching codec p
> [12:17:28.772] sendSTAT:166 [0050C580]: STAT:[STMn] msplayed 0
> [12:17:29.619] AVTSetPlayMode:166 [004C1960]: uPNP set play mode (cookie 00000000)
> [12:17:29.619] AVTPlay:150 [004C1960]: uPNP play (cookie 00000001)
> [12:17:29.619] CtrlSetVolume:244 [004C1960]: uPNP volume 16 (cookie 00000002)
> [12:17:29.620] process_strm:235 [0050C580] strm command s
> [12:17:29.620] process_strm:304 [0050C580], strm s autostart: 1 transition period: 10 transition type: 0 codec: p
> [12:17:29.620] sendSTAT:166 [0050C580]: STAT:[STMf] msplayed 0
> [12:17:29.620] send_packet:105 failed writing to socket: 10054, Unknown error
> 
> [12:17:29.620] sq_get_metadata:375 [0050C580]: cannot get metadata
> [12:17:29.620] bind_socket:397 cannot bind socket 1312
> [12:17:29.620] bind_socket:397 cannot bind socket 1312
> [12:17:29.620] output_start:82 [0050C580]: start thread 1
> [12:17:29.620] sq_callback:333 [004C1960]:
>   artist:
>   album:
>   title:Streaming from LMS
>   genre:
>   duration:0.000
>   size:0
>   cover:
>   offset:0
> [12:17:29.620] sq_callback:369 [004C1960]: set current URI (s:0) http://192.168.1.14:49154/bridge-2.pcm
> [12:17:29.620] AVTSetURI:90 [004C1960]: uPNP setURI http://192.168.1.14:49154/bridge-2.pcm (cookie 00000003)
> [12:17:29.620] process_start:1191 [0050C580]: codec:p, ch:2, s:16, r:44100
> [12:17:29.621] sendSTAT:166 [0050C580]: STAT:[STMc] msplayed 0
> [12:17:29.703] output_http_thread:141 [0050C580]: got HTTP connection 1340
> [12:17:30.821] _output_new_stream:433 [0050C580]: PCM encoding r:44100 s:16 f:p
> [12:17:30.821] _output_new_stream:434 [0050C580]: HTTP -3, estimated len 4294810800
> [12:17:30.821] output_http_thread:170 [0050C580]: drain is 2621440 (waited 2046)
> [12:17:30.821] handle_http:468 [0050C580]: received GET /bridge-4.pcm HTTP/1.1
> [12:17:30.821] handle_http:471 [0050C580]: HTTP headers
> Host: 192.168.1.14:49153
> Connection: close
> User-Agent: foobar2000/1.5.2
> Accept: */*
> Icy-MetaData: 1
> 
> [12:17:30.821] handle_http:502 wrong file requested, refusing 4 1
> [12:17:30.821] handle_http:563 [0050C580]: responding:
> HTTP/1.1 410 Gone
> Server: squeezebox-bridge
> Connection: close
> Transfer-Encoding: chunked
> 
> 
> [12:17:30.821] output_http_thread:193 [0050C580]: HTTP close 1340 (bytes 0) (n:1 res:0)
> [12:17:41.000] slimproto_run:570 [0050C580] Closing CLI socket 1240
> [12:17:53.594] CtrlSetVolume:244 [004C1960]: uPNP volume 0 (cookie 0000000E)
> [12:17:53.594] process_strm:235 [0050C580] strm command p
> [12:17:53.594] process_strm:265 [0050C580] pause (interval:0)
> [12:17:53.594] AVTBasic:200 [004C1960]: uPNP Pause (cookie 0000000F)
> [12:17:53.595] CtrlSetVolume:244 [004C1960]: uPNP volume 16 (cookie 00000010)
> [12:17:53.595] sendSTAT:166 [0050C580]: STAT:[STMp] msplayed 0
> [12:17:53.645] output_http_thread:373 [0050C580]: end thread 0 (0 bytes)
> [12:17:53.669] output_http_thread:373 [0050C580]: end thread 1 (0 bytes)
> [12:17:53.670] sendSTAT:166 [0050C580]: STAT:[STMf] msplayed 0
> [12:17:53.670] AVTStop:216 [004C1960]: uPNP stop (cookie 00000011)
> [12:17:56.987] AVTStop:216 [004C1960]: uPNP stop (cookie 00000012)
> [12:17:56.996] process_strm:235 [0050C580] strm command s
> [12:17:56.996] process_strm:304 [0050C580], strm s autostart: 0 transition period: 0 transition type: 2 codec: p
> [12:17:56.996] sendSTAT:166 [0050C580]: STAT:[STMf] msplayed 0
> [12:17:56.997] sq_get_metadata:375 [0050C580]: cannot get metadata
> [12:17:56.998] bind_socket:397 cannot bind socket 992
> [12:17:56.998] output_start:82 [0050C580]: start thread 0
> [12:17:56.998] sq_callback:333 [004C1960]:
>   artist:
>   album:
>   title:Streaming from LMS
>   genre:
>   duration:0.000
>   size:0
>   cover:
>   offset:0
> [12:17:56.998] sq_callback:369 [004C1960]: set current URI (s:0) http://192.168.1.14:49153/bridge-3.pcm
> [12:17:56.998] AVTSetURI:90 [004C1960]: uPNP setURI http://192.168.1.14:49153/bridge-3.pcm (cookie 00000013)
> [12:17:56.998] process_start:1191 [0050C580]: codec:p, ch:2, s:16, r:44100
> [12:17:56.998] sendSTAT:166 [0050C580]: STAT:[STMc] msplayed 0
> [12:17:58.135] AVTSetPlayMode:166 [004C1960]: uPNP set play mode (cookie 00000014)
> [12:17:58.135] AVTPlay:150 [004C1960]: uPNP play (cookie 00000015)
> [12:17:58.135] CtrlSetVolume:244 [004C1960]: uPNP volume 16 (cookie 00000015)
> [12:17:58.135] sendSTAT:166 [0050C580]: STAT:[STMl] msplayed 0
> [12:17:58.135] process_strm:235 [0050C580] strm command u
> [12:17:58.135] process_strm:284 [0050C580] unpause at: 0 now: 70931734
> [12:17:58.135] sendSTAT:166 [0050C580]: STAT:[STMr] msplayed 0
> [12:17:58.219] output_http_thread:141 [0050C580]: got HTTP connection 1268
> [12:17:58.236] _checkfade:862 [0050C580]: fade mode: 2 duration: 0 track-start
> [12:17:58.236] _checkfade:875 [0050C580]: fade IN: 0 frames
> [12:17:58.270] _output_new_stream:433 [0050C580]: PCM encoding r:44100 s:16 f:p
> [12:17:58.270] _output_new_stream:434 [0050C580]: HTTP -3, estimated len 4294810800
> [12:17:58.270] output_http_thread:170 [0050C580]: drain is 2621440 (waited 1282)
> [12:17:58.270] handle_http:468 [0050C580]: received GET /bridge-3.pcm HTTP/1.1
> [12:17:58.270] handle_http:471 [0050C580]: HTTP headers
> Host: 192.168.1.14:49153
> Connection: close
> User-Agent: foobar2000/1.5.2
> Accept: */*
> Icy-MetaData: 1
> 
> [12:17:58.270] handle_http:563 [0050C580]: responding:
> HTTP/1.1 200 OK
> Server: squeezebox-bridge
> Connection: close
> Content-Type: audio/L16;rate=44100;channels=2
> Transfer-Encoding: chunked
> 
> 
> [12:17:58.270] gain_and_fade:932 [0050C580]: track start rate:44100 gain:65536
> [12:17:58.270] gain_and_fade:944 [0050C580]: fade start reached
> [12:17:58.270] gain_and_fade:983 [0050C580]: fade complete
> [12:17:58.581] _SyncNotifState:657 foobar2000 Renderer (username) [PCNAME]: uPNP playing
> [12:17:58.583] sendSTAT:166 [0050C580]: STAT:[STMs] msplayed 0
> [12:18:11.000] slimproto_run:570 [0050C580] Closing CLI socket 784

Plugged in TV via HDMI

> [12:19:25.005] XMLGetFirstDocumentItem:176 (BUG) ixmlNode_getFirstChild(tmpNode) returned NULL
> 
> Retarting Squeeze2upnp after crash: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -f C:\ProgramData\Squeezebox\Logs\upnpbridge.log -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml
> [12:19:33.724] main:1685 Starting squeeze2upnp version: v1.25.1 (Dec 21 2019 @ 13:41:22)
> [12:19:33.736] output_init:603 success loading FLAC encoder
> [12:19:33.744] Start:1452 Binding to 192.168.1.14:49152
> [12:19:33.750] XMLGetFirstDocumentItem:176 (BUG) ixmlNode_getFirstChild(tmpNode) returned NULL
> 
> Retarting Squeeze2upnp after crash: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml
> 
> Retarting Squeeze2upnp after crash: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -f C:\ProgramData\Squeezebox\Logs\upnpbridge.log -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml
> [12:19:55.358] main:1685 Starting squeeze2upnp version: v1.25.1 (Dec 21 2019 @ 13:41:22)
> [12:19:55.371] output_init:603 success loading FLAC encoder
> [12:19:55.381] Start:1452 Binding to 192.168.1.14:49152
> [12:19:55.388] XMLGetFirstDocumentItem:176 (BUG) ixmlNode_getFirstChild(tmpNode) returned NULL
> 
> Retarting Squeeze2upnp after crash: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -f C:\ProgramData\Squeezebox\Logs\upnpbridge.log -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml
> [12:20:03.775] main:1685 Starting squeeze2upnp version: v1.25.1 (Dec 21 2019 @ 13:41:22)
> [12:20:03.786] output_init:603 success loading FLAC encoder
> [12:20:03.793] Start:1452 Binding to 192.168.1.14:49152
> [12:20:03.800] XMLGetFirstDocumentItem:176 (BUG) ixmlNode_getFirstChild(tmpNode) returned NULL
> 
> Retarting Squeeze2upnp after crash: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml
> 
> Retarting Squeeze2upnp after crash: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -f C:\ProgramData\Squeezebox\Logs\upnpbridge.log -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml
> [12:20:25.399] main:1685 Starting squeeze2upnp version: v1.25.1 (Dec 21 2019 @ 13:41:22)
> [12:20:25.413] output_init:603 success loading FLAC encoder
> [12:20:25.421] Start:1452 Binding to 192.168.1.14:49152
> [12:20:25.427] XMLGetFirstDocumentItem:176 (BUG) ixmlNode_getFirstChild(tmpNode) returned NULL

Unplugged HDMI

> Retarting Squeeze2upnp after crash: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -f C:\ProgramData\Squeezebox\Logs\upnpbridge.log -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml
> [12:20:33.809] main:1685 Starting squeeze2upnp version: v1.25.1 (Dec 21 2019 @ 13:41:22)
> [12:20:33.831] output_init:603 success loading FLAC encoder
> [12:20:33.848] Start:1452 Binding to 192.168.1.14:49152
> [12:20:35.009] AddMRDevice:1343 [004C1960]: adding renderer (foobar2000 Renderer (username) [PCNAME])
> [12:20:35.027] MasterHandler:1001 [004C1960]: subscribe success
> [12:20:35.210] slimproto:855 squeezelite [0050C580] <=> player [004C1960]
> [12:20:35.210] slimproto:856 [0050C580] connecting to 169.254.217.168:3483
> [12:20:35.210] slimproto:886 [0050C580] connected
> [12:20:35.210] sendHELO:133 [0050C580] cap: CanHTTPS=1,Model=squeezelite,ModelName=SqueezeLite,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=48000,aac,ogg,flc,alc,aif,pcm,mp3
> [12:20:35.222] process_strm:235 [0050C580] strm command s
> [12:20:35.222] process_strm:304 [0050C580], strm s autostart: 1 transition period: 10 transition type: 0 codec: p
> [12:20:35.222] sendSTAT:166 [0050C580]: STAT:[STMf] msplayed 0
> [12:20:35.222] sq_get_metadata:375 [0050C580]: cannot get metadata
> [12:20:35.223] bind_socket:397 cannot bind socket 1248
> [12:20:35.223] output_start:82 [0050C580]: start thread 0
> [12:20:35.223] process_start:1191 [0050C580]: codec:p, ch:2, s:16, r:44100
> [12:20:35.223] sendSTAT:166 [0050C580]: STAT:[STMc] msplayed 0
> [12:20:35.223] process_strm:339 [0050C580] no matching codec p
> [12:20:35.223] sendSTAT:166 [0050C580]: STAT:[STMn] msplayed 0
> [12:20:36.337] AVTSetPlayMode:166 [004C1960]: uPNP set play mode (cookie 00000000)
> [12:20:36.337] AVTPlay:150 [004C1960]: uPNP play (cookie 00000001)
> [12:20:36.337] CtrlSetVolume:244 [004C1960]: uPNP volume 16 (cookie 00000002)
> [12:20:36.443] output_http_thread:141 [0050C580]: got HTTP connection 1288
> [12:20:36.443] _output_new_stream:433 [0050C580]: PCM encoding r:44100 s:16 f:p
> [12:20:36.443] _output_new_stream:434 [0050C580]: HTTP -3, estimated len 4294810800
> [12:20:36.443] output_http_thread:170 [0050C580]: drain is 2621440 (waited 1218)
> [12:20:36.443] handle_http:468 [0050C580]: received GET /bridge-3.pcm HTTP/1.1
> [12:20:36.443] handle_http:471 [0050C580]: HTTP headers
> Host: 192.168.1.14:49153
> Connection: close
> User-Agent: foobar2000/1.5.2
> Accept: */*
> Icy-MetaData: 1
> 
> [12:20:36.444] handle_http:502 wrong file requested, refusing 3 1
> [12:20:36.444] handle_http:563 [0050C580]: responding:
> HTTP/1.1 410 Gone
> Server: squeezebox-bridge
> Connection: close
> Transfer-Encoding: chunked
> 
> 
> [12:20:36.444] output_http_thread:193 [0050C580]: HTTP close 1288 (bytes 0) (n:1 res:0)
> [12:20:37.942] process_strm:235 [0050C580] strm command s
> [12:20:37.942] process_strm:304 [0050C580], strm s autostart: 1 transition period: 10 transition type: 0 codec: p
> [12:20:37.942] sendSTAT:166 [0050C580]: STAT:[STMf] msplayed 0
> [12:20:37.942] send_packet:105 failed writing to socket: 10054, Unknown error
> 
> [12:20:37.942] sq_get_metadata:375 [0050C580]: cannot get metadata
> [12:20:37.942] process_start:1086 [0050C580]: buffer should be empty
> [12:20:37.942] bind_socket:397 cannot bind socket 1288
> [12:20:37.943] bind_socket:397 cannot bind socket 1288
> [12:20:37.943] output_start:82 [0050C580]: start thread 1
> [12:20:37.943] sq_callback:333 [004C1960]:
>   artist:
>   album:
>   title:Streaming from LMS
>   genre:
>   duration:0.000
>   size:0
>   cover:
>   offset:0
> [12:20:37.943] sq_callback:369 [004C1960]: set current URI (s:0) http://192.168.1.14:49154/bridge-2.pcm
> [12:20:37.944] AVTSetURI:90 [004C1960]: uPNP setURI http://192.168.1.14:49154/bridge-2.pcm (cookie 00000003)
> [12:20:37.955] process_start:1191 [0050C580]: codec:p, ch:2, s:16, r:44100
> [12:20:37.966] sendSTAT:166 [0050C580]: STAT:[STMc] msplayed 0
> [12:20:51.000] slimproto_run:570 [0050C580] Closing CLI socket 1244
> [12:20:54.313] CtrlSetVolume:244 [004C1960]: uPNP volume 0 (cookie 0000000A)
> [12:20:54.314] process_strm:235 [0050C580] strm command p
> [12:20:54.314] process_strm:265 [0050C580] pause (interval:0)
> [12:20:54.314] AVTBasic:200 [004C1960]: uPNP Pause (cookie 0000000B)
> [12:20:54.314] CtrlSetVolume:244 [004C1960]: uPNP volume 16 (cookie 0000000C)
> [12:20:54.314] sendSTAT:166 [0050C580]: STAT:[STMp] msplayed 0
> [12:20:54.319] output_http_thread:373 [0050C580]: end thread 0 (0 bytes)
> [12:20:54.351] output_http_thread:373 [0050C580]: end thread 1 (0 bytes)
> [12:20:54.352] sendSTAT:166 [0050C580]: STAT:[STMf] msplayed 0
> [12:20:54.352] AVTStop:216 [004C1960]: uPNP stop (cookie 0000000D)
> [12:20:55.024] _SyncNotifState:629 [004C1960]: uPNP stop
> [12:20:56.184] AVTStop:216 [004C1960]: uPNP stop (cookie 0000000F)
> [12:20:56.198] process_strm:235 [0050C580] strm command s
> [12:20:56.198] process_strm:304 [0050C580], strm s autostart: 0 transition period: 0 transition type: 2 codec: p
> [12:20:56.198] sendSTAT:166 [0050C580]: STAT:[STMf] msplayed 0
> [12:20:56.201] sq_get_metadata:375 [0050C580]: cannot get metadata
> [12:20:56.201] bind_socket:397 cannot bind socket 1376
> [12:20:56.201] output_start:82 [0050C580]: start thread 0
> [12:20:56.201] sq_callback:333 [004C1960]:
>   artist:
>   album:
>   title:Streaming from LMS
>   genre:
>   duration:0.000
>   size:0
>   cover:
>   offset:0
> [12:20:56.201] sq_callback:369 [004C1960]: set current URI (s:0) http://192.168.1.14:49153/bridge-3.pcm
> [12:20:56.201] AVTSetURI:90 [004C1960]: uPNP setURI http://192.168.1.14:49153/bridge-3.pcm (cookie 00000010)
> [12:20:56.202] process_start:1191 [0050C580]: codec:p, ch:2, s:16, r:44100
> [12:20:56.202] sendSTAT:166 [0050C580]: STAT:[STMc] msplayed 0
> [12:20:57.282] AVTSetPlayMode:166 [004C1960]: uPNP set play mode (cookie 00000011)
> [12:20:57.283] AVTPlay:150 [004C1960]: uPNP play (cookie 00000012)
> [12:20:57.283] CtrlSetVolume:244 [004C1960]: uPNP volume 16 (cookie 00000012)
> [12:20:57.283] sendSTAT:166 [0050C580]: STAT:[STMl] msplayed 0
> [12:20:57.283] process_strm:235 [0050C580] strm command u
> [12:20:57.283] process_strm:284 [0050C580] unpause at: 0 now: 71110890
> [12:20:57.283] sendSTAT:166 [0050C580]: STAT:[STMr] msplayed 0
> [12:20:57.350] _checkfade:862 [0050C580]: fade mode: 2 duration: 0 track-start
> [12:20:57.350] _checkfade:875 [0050C580]: fade IN: 0 frames
> [12:20:57.387] output_http_thread:141 [0050C580]: got HTTP connection 1292
> [12:20:57.387] _output_new_stream:433 [0050C580]: PCM encoding r:44100 s:16 f:p
> [12:20:57.387] _output_new_stream:434 [0050C580]: HTTP -3, estimated len 4294810800
> [12:20:57.387] output_http_thread:170 [0050C580]: drain is 2621440 (waited 1188)
> [12:20:57.388] handle_http:468 [0050C580]: received GET /bridge-3.pcm HTTP/1.1
> [12:20:57.388] handle_http:471 [0050C580]: HTTP headers
> Host: 192.168.1.14:49153
> Connection: close
> User-Agent: foobar2000/1.5.2
> Accept: */*
> Icy-MetaData: 1
> 
> [12:20:57.388] handle_http:563 [0050C580]: responding:
> HTTP/1.1 200 OK
> Server: squeezebox-bridge
> Connection: close
> Content-Type: audio/L16;rate=44100;channels=2
> Transfer-Encoding: chunked
> 
> 
> [12:20:57.388] gain_and_fade:932 [0050C580]: track start rate:44100 gain:65536
> [12:20:57.388] gain_and_fade:944 [0050C580]: fade start reached
> [12:20:57.388] gain_and_fade:983 [0050C580]: fade complete
> [12:21:00.532] _SyncNotifState:657 foobar2000 Renderer (username) [PCNAME]: uPNP playing
> [12:21:00.532] sendSTAT:166 [0050C580]: STAT:[STMs] msplayed 0
> [12:21:11.000] slimproto_run:570 [0050C580] Closing CLI socket 1372

upnpbridge-log.txt

philippe44 commented 4 years ago

Can you put the debug log to sdebug "set in the additional command line" -d all=sdebug. This will help me to see where is crashes. It means a player should return a field in an UPnP object and it does not, so that's a faulty item, but I can try to do a workaround. This function is used at many different places, most of them are protected but not all so I need to know better where the issue happens

PilotFlying commented 4 years ago

Hi, thanks. Here's the log with that option:

Starting Squeeze2upnp: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -f C:\ProgramData\Squeezebox\Logs\upnpbridge.log -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml -d all=sdebug
[08:18:37.630] main:1685 Starting squeeze2upnp version: v1.25.1 (Dec 21 2019 @ 13:41:22)
[08:18:37.728] output_init:603 success loading FLAC encoder
[08:18:37.728] register_alac:544 using alac to decode alc
[08:18:37.741] load_mad:408 loaded libmad-0.dll
[08:18:37.741] register_mad:430 using mad to decode mp3
[08:18:37.753] load_faad:620 loaded libfaad2.dll
[08:18:37.753] register_faad:641 using faad to decode aac
[08:18:37.800] load_vorbis:325 loaded libvorbisfile.dll
[08:18:37.800] register_vorbis:346 using vorbis to decode ogg
[08:18:37.800] register_pcm:275 using pcm
[08:18:37.800] load_flac:266 loaded libFLAC.dll
[08:18:37.800] register_flac:287 using flac to decode flc
[08:18:37.820] load_opus:251 dlerror: code: 126
[08:18:37.820] register_m4a_thru:301 using mp4 to aac (ADTS)
[08:18:37.820] register_flac_thru:247 using flac
[08:18:37.820] register_thru:106 using thru
[08:18:37.831] load_soxr:381 loaded libsoxr.dll
[08:18:37.831] register_soxr:394 using soxr for resampling
[08:18:37.831] Start:1452 Binding to 192.168.1.14:49152
[08:18:39.849] MasterHandler:916 event: 6 [UPNP_DISCOVERY_SEARCH_RESULT] [00000000] (recurse 0)
[08:18:39.856] AddMRDevice:1270 UDN:    uuid:a42dc730-7dc7-cf23-e43e-5bc53202e0d7
FriendlyName:   foobar2000 Renderer (username) [PCNAME]
[08:18:39.857] XMLGetFirstDocumentItem:188 Error finding URLBase in XML Node
[08:18:39.857] XMLGetNthServiceList:273 GetNthServiceList called : n = 0
[08:18:39.857] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:AVTransport:1
[08:18:39.857] XMLFindAndParseService:342 Service pRÀS, serviceId: urn:upnp-org:serviceId:AVTransport
[08:18:39.857] XMLGetNthServiceList:273 GetNthServiceList called : n = 1
[08:18:39.857] AddMRDevice:1315     service [urn:schemas-upnp-org:service:AVTransport] urn:schemas-upnp-org:service:AVTransport:1 urn:upnp-org:serviceId:AVTransport, http://192.168.1.14:1825/AVTransport/a42dc730-7dc7-cf23-e43e-5bc53202e0d7/event.xml, http://192.168.1.14:1825/AVTransport/a42dc730-7dc7-cf23-e43e-5bc53202e0d7/control.xml
[08:18:39.874] XMLGetFirstDocumentItem:188 Error finding URLBase in XML Node
[08:18:39.874] XMLGetNthServiceList:273 GetNthServiceList called : n = 0
[08:18:39.874] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:AVTransport:1
[08:18:39.874] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:ConnectionManager:1
[08:18:39.874] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:RenderingControl:1
[08:18:39.874] XMLFindAndParseService:342 Service `JPðR, serviceId: urn:upnp-org:serviceId:RenderingControl
[08:18:39.874] XMLGetNthServiceList:273 GetNthServiceList called : n = 1
[08:18:39.874] AddMRDevice:1315     service [urn:schemas-upnp-org:service:RenderingControl] urn:schemas-upnp-org:service:RenderingControl:1 urn:upnp-org:serviceId:RenderingControl, http://192.168.1.14:1825/RenderingControl/a42dc730-7dc7-cf23-e43e-5bc53202e0d7/event.xml, http://192.168.1.14:1825/RenderingControl/a42dc730-7dc7-cf23-e43e-5bc53202e0d7/control.xml
[08:18:39.874] XMLGetFirstDocumentItem:188 Error finding URLBase in XML Node
[08:18:39.874] XMLGetNthServiceList:273 GetNthServiceList called : n = 0
[08:18:39.874] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:AVTransport:1
[08:18:39.874] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:ConnectionManager:1
[08:18:39.874] XMLFindAndParseService:342 Service (JPðR, serviceId: urn:upnp-org:serviceId:ConnectionManager
[08:18:39.874] XMLGetNthServiceList:273 GetNthServiceList called : n = 1
[08:18:39.874] AddMRDevice:1315     service [urn:schemas-upnp-org:service:ConnectionManager] urn:schemas-upnp-org:service:ConnectionManager:1 urn:upnp-org:serviceId:ConnectionManager, http://192.168.1.14:1825/ConnectionManager/a42dc730-7dc7-cf23-e43e-5bc53202e0d7/event.xml, http://192.168.1.14:1825/ConnectionManager/a42dc730-7dc7-cf23-e43e-5bc53202e0d7/control.xml
[08:18:39.874] XMLGetFirstDocumentItem:188 Error finding URLBase in XML Node
[08:18:39.874] XMLGetNthServiceList:273 GetNthServiceList called : n = 0
[08:18:39.874] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:AVTransport:1
[08:18:39.874] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:ConnectionManager:1
[08:18:39.874] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:RenderingControl:1
[08:18:39.874] XMLGetNthServiceList:273 GetNthServiceList called : n = 1
[08:18:39.874] XMLGetFirstDocumentItem:188 Error finding URLBase in XML Node
[08:18:39.874] XMLGetNthServiceList:273 GetNthServiceList called : n = 0
[08:18:39.874] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:AVTransport:1
[08:18:39.874] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:ConnectionManager:1
[08:18:39.874] XMLFindAndParseService:331 serviceType urn:schemas-upnp-org:service:RenderingControl:1
[08:18:39.874] XMLGetNthServiceList:273 GetNthServiceList called : n = 1
[08:18:39.874] AddMRDevice:1343 [004C1960]: adding renderer (foobar2000 Renderer (username) [PCNAME])
[08:18:39.874] GetProtocolInfo:356 [004C1960]: uPNP GetProtocolInfo
[08:18:39.877] GetProtocolInfo:367 [004C1960]: ProtocolInfo http-get:*:audio/L16:*,http-get:*:audio/mp3:*,http-get:*:audio/x-mp3:*,http-get:*:audio/mpeg:*,http-get:*:audio/x-ms-wma:*,http-get:*:audio/wma:*,http-get:*:audio/mpeg3:*,http-get:*:audio/wav:*,http-get:*:audio/x-wav:*,http-get:*:audio/ogg:*,http-get:*:audio/x-ogg:*,http-get:*:audio/musepack:*,http-get:*:audio/x-musepack:*,http-get:*:audio/flac:*,http-get:*:audio/x-flac:*,http-get:*:audio/mp4:*,http-get:*:audio/m4a:*,http-get:*:audio/aiff:*,http-get:*:audio/x-aiff:*,http-get:*:audio/basic:*,http-get:*:audio/x-wavpack:*,http-get:*:application/octet-stream:*
[08:18:39.877] stream_thread_init:387 [0050C580] streambuf size: 524288
[08:18:39.878] MRThread:530 [004C1960]: UPnP thread timer 0 5000
[08:18:39.882] MasterHandler:916 event: 11 [UPNP_EVENT_SUBSCRIBE_COMPLETE] [02521DD0] (recurse 0)
[08:18:39.882] MasterHandler:1001 [004C1960]: subscribe success
[08:18:39.884] MasterHandler:916 event: 9 [UPNP_EVENT_RECEIVED] [00000000] (recurse 0)
[08:18:39.884] ProcessEvent:755 device off, no squeezebox device (yet) or not change for uuid:a58a82eb-65bb-11ea-895c-aeac69f0751e
[08:18:40.076] output_thread_init:569 [0050C580] init output media renderer
[08:18:40.076] decode_thread_init:168 [0050C580]: init decode
[08:18:40.076] resample_init:345 [0050C580]: resampling sync recipe: 0x00, flags: 0x00, scale: 0.89, precision: 0.0, passband_end: 0.00000, stopband_begin: 0.00000, phase_response: -1.0
[08:18:40.076] UpdateThread:1196 Updating configuration C:\ProgramData\Squeezebox\prefs\upnpbridge.xml
[08:18:40.076] discover_server:803 [0050C580] sending discovery
[08:18:40.076] discover_server:835 [0050C580] got response from: 169.254.217.168:3483
[08:18:40.076] slimproto:855 squeezelite [0050C580] <=> player [004C1960]
[08:18:40.076] slimproto:856 [0050C580] connecting to 169.254.217.168:3483
[08:18:40.077] slimproto:886 [0050C580] connected
[08:18:40.077] sendHELO:132 [0050C580] mac: bb:bb:a9:99:ab:f1
[08:18:40.077] sendHELO:133 [0050C580] cap: CanHTTPS=1,Model=squeezelite,ModelName=SqueezeLite,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=48000,aac,ogg,flc,alc,aif,pcm,mp3
[08:18:40.077] process:497 [0050C580] strm
[08:18:40.077] process_strm:238 [0050C580] strm command q
[08:18:40.077] decode_flush:208 [0050C580]: decode flush
[08:18:40.077] output_flush:564 [0050C580]: flush output buffer
[08:18:40.077] sq_callback:308 [004C1960]: device off or not controlled by LMS
[08:18:40.077] process:497 [0050C580] strm
[08:18:40.077] process_strm:238 [0050C580] strm command q
[08:18:40.077] decode_flush:208 [0050C580]: decode flush
[08:18:40.077] output_flush:564 [0050C580]: flush output buffer
[08:18:40.077] process:497 [0050C580] setd
[08:18:40.077] sendSETDName:224 [1156]: set playername: foobar2000 Renderer (username) [PCNAME]
[08:18:40.077] process:497 [0050C580] setd
[08:18:40.077] process:497 [0050C580] aude
[08:18:40.077] process_aude:389 [0050C580] on/off using aude 1
[08:18:40.077] sq_callback:304 [004C1960]: device set on/off 1
[08:18:40.077] sq_callback:313 callback for foobar2000 Renderer (username) [PCNAME]
[08:18:40.078] process:497 [0050C580] audg
[08:18:40.078] process_audg:403 [0050C580] (old) audg gainL: 15 gainR: 15
[08:18:40.078] sq_callback:313 callback for foobar2000 Renderer (username) [PCNAME]
[08:18:40.958] MasterHandler:916 event: 6 [UPNP_DISCOVERY_SEARCH_RESULT] [00000000] (recurse 0)
[08:18:40.958] UpdateThread:1111 [004C1960] UPnP keep alive: foobar2000 Renderer (username) [PCNAME]
[08:18:44.017] process:497 [0050C580] strm
[08:18:44.017] process_strm:238 [0050C580] strm command t
[08:18:44.879] MRThread:530 [004C1960]: UPnP thread timer 5000 5000
[08:18:49.000] process:497 [0050C580] strm
[08:18:49.000] process_strm:238 [0050C580] strm command t
[08:18:49.879] MRThread:530 [004C1960]: UPnP thread timer 5000 5000
[08:18:54.000] process:497 [0050C580] strm
[08:18:54.000] process_strm:238 [0050C580] strm command t
[08:18:54.879] MRThread:530 [004C1960]: UPnP thread timer 5000 5000
[08:18:57.000] MasterHandler:916 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[08:18:57.000] UpdateThread:1057 Presence checking
[08:18:58.114] MasterHandler:916 event: 6 [UPNP_DISCOVERY_SEARCH_RESULT] [00000000] (recurse 0)
[08:18:58.114] UpdateThread:1111 [004C1960] UPnP keep alive: foobar2000 Renderer (username) [PCNAME]
[08:18:59.000] process:497 [0050C580] strm
[08:18:59.000] process_strm:238 [0050C580] strm command t
[08:18:59.879] MRThread:530 [004C1960]: UPnP thread timer 5000 5000
[08:19:00.024] MasterHandler:916 event: 6 [UPNP_DISCOVERY_SEARCH_RESULT] [00000000] (recurse 0)
[08:19:00.024] UpdateThread:1111 [004C1960] UPnP keep alive: foobar2000 Renderer (username) [PCNAME]
[08:19:04.000] process:497 [0050C580] strm
[08:19:04.000] process_strm:238 [0050C580] strm command t
[08:19:04.880] MRThread:530 [004C1960]: UPnP thread timer 5000 5000
[08:19:09.000] process:497 [0050C580] strm
[08:19:09.000] process_strm:238 [0050C580] strm command t
[08:19:09.881] MRThread:530 [004C1960]: UPnP thread timer 5000 5000
[08:19:14.000] process:497 [0050C580] strm
[08:19:14.000] process_strm:238 [0050C580] strm command t
[08:19:14.881] MRThread:530 [004C1960]: UPnP thread timer 5000 5000
[08:19:17.001] MasterHandler:916 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[08:19:17.001] UpdateThread:1057 Presence checking
[08:19:17.789] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:17.790] CheckAndLock:268 device is NULL
[08:19:17.794] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:17.794] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:17.794] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:17.794] CheckAndLock:268 device is NULL
[08:19:17.795] CheckAndLock:268 device is NULL
[08:19:17.795] CheckAndLock:268 device is NULL
[08:19:17.795] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:17.795] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:17.795] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:17.795] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:17.795] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:17.795] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:17.795] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:17.795] CheckAndLock:268 device is NULL
[08:19:17.795] CheckAndLock:268 device is NULL
[08:19:17.796] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:19.000] process:497 [0050C580] strm
[08:19:19.000] process_strm:238 [0050C580] strm command t
[08:19:19.881] MRThread:530 [004C1960]: UPnP thread timer 5000 5000
[08:19:20.127] MasterHandler:916 event: 6 [UPNP_DISCOVERY_SEARCH_RESULT] [00000000] (recurse 0)
[08:19:20.127] UpdateThread:1111 [004C1960] UPnP keep alive: foobar2000 Renderer (username) [PCNAME]
[08:19:20.987] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:20.987] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:20.987] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:20.988] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:20.991] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:20.992] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.192] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.193] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.193] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.193] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.193] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.193] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.394] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.395] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.395] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.395] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.397] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.397] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.598] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.598] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.598] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.599] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.599] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:21.599] MasterHandler:916 event: 4 [UPNP_DISCOVERY_ADVERTISEMENT_ALIVE] [00000000] (recurse 0)
[08:19:24.000] process:497 [0050C580] strm
[08:19:24.000] process_strm:238 [0050C580] strm command t
[08:19:24.881] MRThread:530 [004C1960]: UPnP thread timer 5000 5000
[08:19:29.000] process:497 [0050C580] strm
[08:19:29.000] process_strm:238 [0050C580] strm command t
[08:19:29.881] MRThread:530 [004C1960]: UPnP thread timer 5000 5000
[08:19:31.080] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:31.080] CheckAndLock:268 device is NULL
[08:19:31.084] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:31.084] CheckAndLock:268 device is NULL
[08:19:31.084] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:31.084] CheckAndLock:268 device is NULL
[08:19:31.085] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:31.085] CheckAndLock:268 device is NULL
[08:19:31.188] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:31.189] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:31.189] CheckAndLock:268 device is NULL
 MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:31.189] CheckAndLock:268 device is NULL
[08:19:31.189] CheckAndLock:268 device is NULL
[08:19:31.190] MasterHandler:916 event: 5 [UPNP_DISCOVERY_ADVERTISEMENT_BYEBYE] [00000000] (recurse 0)
[08:19:31.190] CheckAndLock:268 device is NULL
[08:19:34.000] process:497 [0050C580] strm
[08:19:34.000] process_strm:238 [0050C580] strm command t
[08:19:34.882] MRThread:530 [004C1960]: UPnP thread timer 5000 5000
[08:19:37.001] MasterHandler:916 event: 7 [UPNP_DISCOVERY_SEARCH_TIMEOUT] [00000000] (recurse 0)
[08:19:37.001] UpdateThread:1057 Presence checking
[08:19:37.003] MasterHandler:916 event: 6 [UPNP_DISCOVERY_SEARCH_RESULT] [00000000] (recurse 1)
[08:19:37.008] XMLGetFirstDocumentItem:176 (BUG) ixmlNode_getFirstChild(tmpNode) returned NULL
[08:19:37.014] MasterHandler:916 event: 6 [UPNP_DISCOVERY_SEARCH_RESULT] [00000000] (recurse 1)
[08:19:37.105] MasterHandler:916 event: 6 [UPNP_DISCOVERY_SEARCH_RESULT] [00000000] (recurse 1)
[08:19:37.107] MasterHandler:916 event: 6 [UPNP_DISCOVERY_SEARCH_RESULT] [00000000] (recurse 1)
[08:19:39.001] process:497 [0050C580] strm
[08:19:39.001] process_strm:238 [0050C580] strm command t

Retarting Squeeze2upnp after crash: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml

Retarting Squeeze2upnp after crash: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -f C:\ProgramData\Squeezebox\Logs\upnpbridge.log -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml -d all=sdebug
[08:20:07.630] main:1685 Starting squeeze2upnp version: v1.25.1 (Dec 21 2019 @ 13:41:22)
[08:20:07.645] output_init:603 success loading FLAC encoder
[08:20:07.645] register_alac:544 using alac to decode alc
[08:20:07.645] load_mad:408 loaded libmad-0.dll
[08:20:07.645] register_mad:430 using mad to decode mp3
[08:20:07.649] load_faad:620 loaded libfaad2.dll
[08:20:07.649] register_faad:641 using faad to decode aac
[08:20:07.654] load_vorbis:325 loaded libvorbisfile.dll
[08:20:07.654] register_vorbis:346 using vorbis to decode ogg
[08:20:07.654] register_pcm:275 using pcm
[08:20:07.654] load_flac:266 loaded libFLAC.dll
[08:20:07.654] register_flac:287 using flac to decode flc
[08:20:07.658] load_opus:251 dlerror: code: 126
[08:20:07.658] register_m4a_thru:301 using mp4 to aac (ADTS)
[08:20:07.658] register_flac_thru:247 using flac
[08:20:07.658] register_thru:106 using thru
[08:20:07.659] load_soxr:381 loaded libsoxr.dll
[08:20:07.659] register_soxr:394 using soxr for resampling
[08:20:07.659] Start:1452 Binding to 192.168.1.14:49152
[08:20:07.663] MasterHandler:916 event: 6 [UPNP_DISCOVERY_SEARCH_RESULT] [00000000] (recurse 0)
[08:20:07.667] XMLGetFirstDocumentItem:176 (BUG) ixmlNode_getFirstChild(tmpNode) returned NULL
[08:20:07.761] MasterHandler:916 event: 6 [UPNP_DISCOVERY_SEARCH_RESULT] [00000000] (recurse 0)

Retarting Squeeze2upnp after crash: C:\PROGRA~3\SQUEEZ~1\Cache\INSTAL~1\Plugins\UPNPBR~1\Bin\SQUEEZ~1.EXE -Z -I -x C:\ProgramData\Squeezebox\prefs\upnpbridge.xml
philippe44 commented 4 years ago

Could you try the release I've pushed a few hours ago?

PilotFlying commented 4 years ago

I installed the plugin through the LMS "Advanced Settings / Plugins" web interface. I have checked "update plugins automatically" there but restarting LMS still gives me v.1.26.0.

Not sure how to update the plugin manually (do I just copy your binaries into C:\ProgramData\Squeezebox\Cache\InstalledPlugins\Plugins\UPnPBridge)?

Thanks

Edit: This is explained in the user guide, section 2:

If you want to try the development version, add the following repository to LMS: http://downloads.sourceforge.net/project/lms-to-upnp/dev/repo-sf.xml

PilotFlying commented 4 years ago

Hi, the plugin updated automatically and I can confirm that the issue is resolved. Connecting that TV no longer crashes squeeze2upnp-win.exe.

Many thanks!