philippe44 / LMS-uPnP

Integrate UPnP players with LogitechMediaServer
111 stars 17 forks source link

Xiaomi soundbox pro can't play music by the dlan bridge #57

Closed laomao9000 closed 11 months ago

laomao9000 commented 2 years ago

thanks for you good work! The dlna bridge can find my xiaomi soundbox pro,but can't play music on it. below is some log:

[12:00:52.896] Start:1507 Binding to 192.168.1.11:49152 (http:0) [12:00:53.764] AddMRDevice:1399 [004C428C]: adding renderer (灏忕埍闊崇-2209) [12:00:53.764] GetProtocolInfo:358 [004C428C]: uPNP GetProtocolInfo [12:00:53.771] GetProtocolInfo:369 [004C428C]: ProtocolInfo http-get:::* [12:00:53.771] stream_thread_init:464 [00510FAC] streambuf size: 1048576 [12:00:53.776] MasterHandler:1036 [004C428C]: subscribe success [12:00:53.903] output_thread_init:611 [00510FAC] init output media renderer [12:00:53.903] decode_thread_init:168 [00510FAC]: init decode [12:00:53.903] resample_init:345 [00510FAC]: resampling sync recipe: 0x00, flags: 0x00, scale: 0.89, precision: 0.0, passband_end: 0.00000, stopband_begin: 0.00000, phase_response: -1.0 [12:00:53.903] UpdateThread:1249 Updating configuration C:\ProgramData\Squeezebox\prefs\upnpbridge.xml [12:00:53.903] discover_server:809 [00510FAC] sending discovery [12:00:53.904] discover_server:841 [00510FAC] got response from: 192.168.1.11:3483 [12:00:53.904] slimproto:861 squeezelite [00510FAC] <=> player [004C428C] [12:00:53.904] slimproto:862 [00510FAC] connecting to 192.168.1.11:3483 [12:00:53.904] slimproto:892 [00510FAC] connected [12:00:53.904] sendHELO:134 [00510FAC] mac: bb:bb:18:69:a5:55 [12:00:53.904] sendHELO:135 [00510FAC] cap: CanHTTPS=1,Model=squeezelite,ModelName=UPnPBridge,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=48000,aac,ogg,ops,ogf,flc,alc,wav,aif,pcm,mp3 [12:00:53.904] process:500 [00510FAC] strm [12:00:53.904] process_strm:241 [00510FAC] strm command q [12:00:53.904] decode_flush:208 [00510FAC]: decode flush [12:00:53.904] output_flush:606 [00510FAC]: flush output buffer [12:00:53.904] sq_callback:313 [004C428C]: device off or not controlled by LMS [12:00:53.904] process:500 [00510FAC] strm [12:00:53.904] process_strm:241 [00510FAC] strm command q [12:00:53.904] decode_flush:208 [00510FAC]: decode flush [12:00:53.904] output_flush:606 [00510FAC]: flush output buffer [12:00:53.904] process:500 [00510FAC] setd [12:00:53.904] sendSETDName:227 [1268]: set playername: 灏忕埍闊崇-2209 [12:00:53.905] process:500 [00510FAC] setd [12:00:53.905] process:500 [00510FAC] aude [12:00:53.905] process_aude:392 [00510FAC] on/off using aude 1 [12:00:53.905] sq_callback:309 [004C428C]: device set on/off 1 [12:00:53.905] process:500 [00510FAC] audg [12:00:53.905] process_audg:406 [00510FAC] (old) audg gainL: 46 gainR: 46 [12:00:54.000] process:500 [00510FAC] strm [12:00:54.000] process_strm:241 [00510FAC] strm command t [12:00:54.000] sendSTAT:169 [00510FAC]: STAT:[STMt] msplayed 0 [12:00:54.958] UpdateThread:1249 Updating configuration C:\ProgramData\Squeezebox\prefs\upnpbridge.xml [12:00:56.051] UpdateThread:1249 Updating configuration C:\ProgramData\Squeezebox\prefs\upnpbridge.xml [12:00:59.004] process:500 [00510FAC] strm [12:00:59.004] process_strm:241 [00510FAC] strm command t [12:00:59.004] sendSTAT:169 [00510FAC]: STAT:[STMt] msplayed 0 [12:01:04.010] process:500 [00510FAC] strm [12:01:04.010] process_strm:241 [00510FAC] strm command t [12:01:04.010] sendSTAT:169 [00510FAC]: STAT:[STMt] msplayed 0 [12:01:05.988] UpdateThread:1146 [004C428C] UPnP keep alive: 灏忕埍闊崇-2209 [12:01:08.422] process:500 [00510FAC] strm [12:01:08.422] process_strm:241 [00510FAC] strm command q [12:01:08.422] decode_flush:208 [00510FAC]: decode flush [12:01:08.422] output_flush:606 [00510FAC]: flush output buffer [12:01:08.422] AVTStop:216 [004C428C]: uPNP stop (cookie 00000000) [12:01:08.429] process:500 [00510FAC] audg [12:01:08.429] process_audg:406 [00510FAC] (old) audg gainL: 46 gainR: 46 [12:01:08.430] process:500 [00510FAC] strm [12:01:08.430] process_strm:238 [00510FAC] strm command s [12:01:08.430] process_strm:307 [00510FAC], strm s autostart: 1 transition period: 10 transition type: 0 codec: f [12:01:08.430] sendSTAT:169 [00510FAC]: STAT:[STMf] msplayed 0 [12:01:08.430] process_strm:322 [00510FAC]: set fade mode: 0 [12:01:08.430] cli_open_socket:180 [00510FAC]: opened CLI socket 1088 [12:01:08.432] sq_getmetadata:502 [00510FAC]: idx 1 artist:绋嬬挧 album:鏅存棩鍏卞壀绐� title:鎬濇晠涔� genre:Folk duration:212.213 size:0 cover:http://192.168.1.11:9000/music/0720cd9f/cover.jpg [12:01:08.432] process_start:1214 [00510FAC]: something went wrong starting process 1 [12:01:08.433] connect_socket:155 [00510FAC] connecting to 192.168.1.11:9000 [12:01:08.433] stream_sock:592 [00510FAC] header: GET /stream.mp3?player=bb:bb:18:69:a5:55 HTTP/1.0

+++++++++++++++++++++++ The soundbox can play by foobar2000(use UPnP MediaRenderer Output.fb2k-component ).

laomao9000 commented 2 years ago

This is my config:

[common parameters] These parameters set the defaults for all players (EMPTY value means use built-in default) Streaming options HTTP mode chunked Gapless Yes Seek on resume Yes Next 15 afore end
UPnP player audio capabilities Codecs aac,ogg,ops,ogf,flc,alc,wav,aif,pcm,mp3 Max sample rate 48000 Show advanced options
Audio format to UPnP player Transcode flac Flow 24 bits PCM packed type 1 Show advanced options
Player discovery options LMS Server ? Player is enabled Yes Remove timeout 120

Player volume management Maximum volume 100 LMS volume changes only when playing Feedback to LMS Yes

Send LMS metadata to player Yes Include cover art No at resolution Send ICY metadata Text only

houoop commented 2 years ago

my xiaomi wifi speaker has same problem. I tried every configration in plugin setting web ui, but it don't work always.

[22:03:39.369799] sendSTAT:169 [0xbbb140]: STAT:[STMc] msplayed 0 [22:03:39.369824] process_strm:342 [0xbbb140] no matching codec f [22:03:39.369846] sendSTAT:169 [0xbbb140]: STAT:[STMn] msplayed 0 [22:03:39.369878] process:500 [0xbbb140] audg [22:03:39.369900] process_audg:406 [0xbbb140] (old) audg gainL: 110 gainR: 110 [22:03:39.412075] process:500 [0xbbb140] strm [22:03:39.412165] process_strm:241 [0xbbb140] strm command q [22:03:39.412186] decode_flush:208 [0xbbb140]: decode flush [22:03:39.412264] output_flush:611 [0xbbb140]: flush output buffer [22:03:39.412336] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [22:03:39.412384] AVTStop:217 [0xc44b00]: uPNP stop (cookie 0xe) [22:03:39.436270] process:500 [0xbbb140] audg [22:03:39.436359] process_audg:406 [0xbbb140] (old) audg gainL: 110 gainR: 110 [22:03:39.438288] process:500 [0xbbb140] strm [22:03:39.438371] process_strm:238 [0xbbb140] strm command s [22:03:39.438392] process_strm:307 [0xbbb140], strm s autostart: 1 transition period: 10 transition type: 0 codec: f [22:03:39.438415] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [22:03:39.438507] process_strm:322 [0xbbb140]: set fade mode: 0 [22:03:39.438586] process_start:1226 [0xbbb140]: something went wrong starting process 14 [22:03:39.438631] connect_socket:155 [0xbbb140] connecting to 192.168.6.189:9000 [22:03:39.438800] stream_sock:592 [0xbbb140] header: GET /stream.mp3?player=bb:bb:a6:ba:fd:4f HTTP/1.0

[22:03:39.438837] sendSTAT:169 [0xbbb140]: STAT:[STMc] msplayed 0 [22:03:39.438865] process_strm:342 [0xbbb140] no matching codec f [22:03:39.438886] sendSTAT:169 [0xbbb140]: STAT:[STMn] msplayed 0 [22:03:39.438921] process:500 [0xbbb140] audg [22:03:39.438942] process_audg:406 [0xbbb140] (old) audg gainL: 110 gainR: 110 [22:03:39.455896] ActionHandler:837 [0xc44b00]: Waited action StopResponse [22:03:39.481631] process:500 [0xbbb140] strm [22:03:39.481719] process_strm:241 [0xbbb140] strm command q [22:03:39.481741] decode_flush:208 [0xbbb140]: decode flush [22:03:39.481808] output_flush:611 [0xbbb140]: flush output buffer [22:03:39.481892] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [22:03:39.481944] AVTStop:217 [0xc44b00]: uPNP stop (cookie 0xf) [22:03:39.493993] ActionHandler:837 [0xc44b00]: Waited action StopResponse [22:03:39.507047] process:500 [0xbbb140] audg [22:03:39.507130] process_audg:406 [0xbbb140] (old) audg gainL: 110 gainR: 110 [22:03:39.507163] process:500 [0xbbb140] strm [22:03:39.507223] process_strm:238 [0xbbb140] strm command s [22:03:39.507257] process_strm:307 [0xbbb140], strm s autostart: 1 transition period: 10 transition type: 0 codec: f [22:03:39.507280] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [22:03:39.507344] process_strm:322 [0xbbb140]: set fade mode: 0 [22:03:39.507425] process_start:1226 [0xbbb140]: something went wrong starting process 15 [22:03:39.507470] connect_socket:155 [0xbbb140] connecting to 192.168.6.189:9000 [22:03:39.507625] stream_sock:592 [0xbbb140] header: GET /stream.mp3?player=bb:bb:a6:ba:fd:4f HTTP/1.0

[22:03:39.507669] sendSTAT:169 [0xbbb140]: STAT:[STMc] msplayed 0 [22:03:39.507696] process_strm:342 [0xbbb140] no matching codec f [22:03:39.507718] sendSTAT:169 [0xbbb140]: STAT:[STMn] msplayed 0 [22:03:39.507751] process:500 [0xbbb140] audg [22:03:39.507772] process_audg:406 [0xbbb140] (old) audg gainL: 110 gainR: 110 [22:03:39.536558] stream_thread:337 [0xbbb140] headers: len: 488 HTTP/1.1 200 OK Server: Logitech Media Server (8.2.1 - TRUNK) Connection: close Content-Type: audio/x-flac Set-Cookie: Squeezebox-albumView=; path=/ Set-Cookie: Squeezebox-expandPlayerControl=true; path=/ Set-Cookie: Squeezebox-expanded-MY_MUSIC=1; path=/ Set-Cookie: Squeezebox-expanded-FAVORITES=0; path=/ Set-Cookie: Squeezebox-expanded-PLUGINS=1; path=/ Set-Cookie: Squeezebox-expanded-PLUGIN_MY_APPS_MODULE_NAME=1; path=/ Set-Cookie: Squeezebox-expanded-RADIO=1; path=/

[22:03:39.536949] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.537274] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.537520] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.537746] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.537968] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.538178] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.538418] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.538792] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.538900] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.539068] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.539310] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.539537] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.539746] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.539972] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.540182] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.540440] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.540662] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.540875] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.541084] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.541332] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.541591] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.543464] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.544155] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.544471] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.544706] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.548292] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.548672] stream_thread:436 [0xbbb140] streambuf read 32768 bytes [22:03:39.552284] process:500 [0xbbb140] strm [22:03:39.552376] process_strm:241 [0xbbb140] strm command q [22:03:39.552399] decode_flush:208 [0xbbb140]: decode flush [22:03:39.552464] output_flush:611 [0xbbb140]: flush output buffer [22:03:39.552493] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [22:03:39.552587] AVTStop:217 [0xc44b00]: uPNP stop (cookie 0x10) [22:03:39.567585] ActionHandler:837 [0xc44b00]: Waited action StopResponse [22:03:39.575043] process:500 [0xbbb140] audg [22:03:39.575140] process_audg:406 [0xbbb140] (old) audg gainL: 110 gainR: 110 [22:03:39.579009] process:500 [0xbbb140] strm [22:03:39.579091] process_strm:238 [0xbbb140] strm command s [22:03:39.579112] process_strm:307 [0xbbb140], strm s autostart: 1 transition period: 10 transition type: 0 codec: f [22:03:39.579134] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [22:03:39.579265] process_strm:322 [0xbbb140]: set fade mode: 0 [22:03:39.579472] process_start:1226 [0xbbb140]: something went wrong starting process 16 [22:03:39.579539] connect_socket:155 [0xbbb140] connecting to 192.168.6.189:9000 [22:03:39.579746] stream_sock:592 [0xbbb140] header: GET /stream.mp3?player=bb:bb:a6:ba:fd:4f HTTP/1.0

[22:03:39.579797] sendSTAT:169 [0xbbb140]: STAT:[STMc] msplayed 0 [22:03:39.579835] process_strm:342 [0xbbb140] no matching codec f [22:03:39.579857] sendSTAT:169 [0xbbb140]: STAT:[STMn] msplayed 0 [22:03:39.579893] process:500 [0xbbb140] audg [22:03:39.579920] process_audg:406 [0xbbb140] (old) audg gainL: 110 gainR: 110 [22:03:39.622535] process:500 [0xbbb140] strm [22:03:39.622626] process_strm:241 [0xbbb140] strm command q [22:03:39.622647] decode_flush:208 [0xbbb140]: decode flush [22:03:39.622708] output_flush:611 [0xbbb140]: flush output buffer [22:03:39.622779] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [22:03:39.622826] AVTStop:217 [0xc44b00]: uPNP stop (cookie 0x11) [22:03:39.641810] ActionHandler:837 [0xc44b00]: Waited action StopResponse [22:03:39.645421] process:500 [0xbbb140] audg [22:03:39.645527] process_audg:406 [0xbbb140] (old) audg gainL: 110 gainR: 110 [22:03:39.647665] process:500 [0xbbb140] strm [22:03:39.647753] process_strm:238 [0xbbb140] strm command s [22:03:39.647774] process_strm:307 [0xbbb140], strm s autostart: 1 transition period: 10 transition type: 0 codec: f [22:03:39.647796] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [22:03:39.647838] process_strm:322 [0xbbb140]: set fade mode: 0 [22:03:39.647934] process_start:1226 [0xbbb140]: something went wrong starting process 17 [22:03:39.647980] connect_socket:155 [0xbbb140] connecting to 192.168.6.189:9000 [22:03:39.648139] stream_sock:592 [0xbbb140] header: GET /stream.mp3?player=bb:bb:a6:ba:fd:4f HTTP/1.0

this is my setting

`<?xml version="1.0"?>

debug debug debug debug debug ? -1 debug debug 1 100 1 48000 1 1 ? 4194304 -1 aac,ogg,ops,ogf,flc,alc,wav,aif,pcm,mp3 1048576 pcm 0 1 0 1 1 15 raw,wav,aif 120 0 1 1 debug bb:bb:a6:ba:fd:4f uuid:88f16c5c-7568-46a2-95eb-79920a0fb96e 1 小爱音箱-5260 小爱音箱-5260 0 小爱音箱-7643 小爱音箱-7643 bb:bb:c9:56:25:c0 uuid:b6f2be06-837d-4a4e-8a5d-cf252712d651 `
philippe44 commented 2 years ago

You have set "roon" mode and use pcm for forced output format but your player likely does not support the "raw" formats of pcm. First, why do you use "roon" mode and then why forcing pcm as an output transcode?

houoop commented 2 years ago

no , I just want to try every param to let it work. Because I use the default param , It don't work . I try the all param from Transcode selection, no answer. so I think this plugin can't use in my dlna player.

this is the log when I use the default param. Maybe you can help me how to select the param. ths!

------------------------------------log----------------------------------------- [10:21:31.066335] sendSETDName:227 [9]: set playername: 小爱音箱-5260 [10:21:31.066406] process:500 [0xbbb140] setd [10:21:31.066439] process:500 [0xbbb140] aude [10:21:31.066462] process_aude:392 [0xbbb140] on/off using aude 1 [10:21:31.066485] sq_callback:312 [0xc44b00]: device set on/off 1 [10:21:31.066515] process:500 [0xbbb140] audg [10:21:31.066537] process_audg:406 [0xbbb140] (old) audg gainL: 110 gainR: 110 [10:21:31.085539] MasterHandler:1054 [0xc44b00]: subscribe success [10:21:34.001521] process:500 [0xbbb140] strm [10:21:34.001618] process_strm:241 [0xbbb140] strm command t [10:21:34.001646] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [10:21:37.557100] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [10:21:39.001925] process:500 [0xbbb140] strm [10:21:39.002042] process_strm:241 [0xbbb140] strm command t [10:21:39.002073] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [10:21:42.589435] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [10:21:44.000763] process:500 [0xbbb140] strm [10:21:44.000846] process_strm:241 [0xbbb140] strm command t [10:21:44.000868] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [10:21:47.123390] UpdateThread:1169 [0xc44b00] UPnP keep alive: 小爱音箱-5260 [10:21:48.001290] UpdateThread:1110 Presence checking [10:21:48.201778] UpdateThread:1110 Presence checking [10:21:49.001288] process:500 [0xbbb140] strm [10:21:49.001378] process_strm:241 [0xbbb140] strm command t [10:21:49.001402] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [10:21:54.001334] process:500 [0xbbb140] strm [10:21:54.001420] process_strm:241 [0xbbb140] strm command t [10:21:54.001443] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [10:21:55.346562] UpdateThread:1169 [0xc44b00] UPnP keep alive: 小爱音箱-5260 [10:21:57.807060] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [10:21:59.006363] process:500 [0xbbb140] strm [10:21:59.006458] process_strm:241 [0xbbb140] strm command t [10:21:59.006481] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [10:22:01.153754] process:500 [0xbbb140] strm [10:22:01.153849] process_strm:241 [0xbbb140] strm command q [10:22:01.153872] decode_flush:208 [0xbbb140]: decode flush [10:22:01.153898] output_flush:611 [0xbbb140]: flush output buffer [10:22:01.153921] AVTStop:217 [0xc44b00]: uPNP stop (cookie (nil)) [10:22:03.551503] process:500 [0xbbb140] strm [10:22:03.551599] process_strm:241 [0xbbb140] strm command q [10:22:03.551624] decode_flush:208 [0xbbb140]: decode flush [10:22:03.551646] output_flush:611 [0xbbb140]: flush output buffer [10:22:03.860566] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [10:22:03.934593] UpdateThread:1169 [0xc44b00] UPnP keep alive: 小爱音箱-5260 [10:22:04.001822] process:500 [0xbbb140] strm [10:22:04.001919] process_strm:241 [0xbbb140] strm command t [10:22:04.001943] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [10:22:04.719703] process:500 [0xbbb140] strm [10:22:04.719798] process_strm:241 [0xbbb140] strm command q [10:22:04.719820] decode_flush:208 [0xbbb140]: decode flush [10:22:04.719842] output_flush:611 [0xbbb140]: flush output buffer [10:22:04.719865] AVTStop:217 [0xc44b00]: uPNP stop (cookie 0x1) [10:22:04.733294] ActionHandler:837 [0xc44b00]: Waited action StopResponse [10:22:06.086814] _SyncNotifState:659 [0xc44b00]: uPNP stop [10:22:06.086892] sq_notify:651 [0xbbb140] notify STOP [10:22:08.003323] UpdateThread:1110 Presence checking [10:22:08.204125] UpdateThread:1110 Presence checking [10:22:09.005002] process:500 [0xbbb140] strm [10:22:09.005098] process_strm:241 [0xbbb140] strm command t [10:22:09.005121] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [10:22:13.163290] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [10:22:14.001223] process:500 [0xbbb140] strm [10:22:14.001345] process_strm:241 [0xbbb140] strm command t [10:22:14.001369] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [10:22:14.751634] UpdateThread:1169 [0xc44b00] UPnP keep alive: 小爱音箱-5260 [10:22:16.838338] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [10:22:17.321496] UpdateThread:1169 [0xc44b00] UPnP keep alive: 小爱音箱-5260 [10:22:19.001768] process:500 [0xbbb140] strm [10:22:19.001857] process_strm:241 [0xbbb140] strm command t [10:22:19.001881] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [10:22:24.002032] process:500 [0xbbb140] strm [10:22:24.002121] process_strm:241 [0xbbb140] strm command t [10:22:24.002143] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 ------------------------------------log-----------------------------------------

this is the default settings

------------------------------------settings----------------------------------------- `<?xml version="1.0"?>

1 0 1 1 15 120 raw,wav,aif 0 0 1 4194304 ? -3 1048576 aac,ogg,ops,ogf,flc,alc,wav,aif,pcm,mp3 1 thru 1 1 100 1 1 48000 debug debug debug -1 debug ? debug debug debug debug uuid:88f16c5c-7568-46a2-95eb-79920a0fb96e bb:bb:a6:ba:fd:4f 1 小爱音箱-5260 小爱音箱-5260 bb:bb:c9:56:25:c0 uuid:b6f2be06-837d-4a4e-8a5d-cf252712d651 0 小爱音箱-7643 小爱音箱-7643 ` ------------------------------------settings-----------------------------------------
philippe44 commented 2 years ago

Don't start with all debug set. Erase config file and start just with default settings. What is you LMS configuration?

houoop commented 2 years ago

Logitech Media Server ver: 8.2.1 , docker ,network host mode docker run -d \ --name logitechmediaserver \ --restart always \ -v /volume2/docker/LMS/config:/config:rw \ -v /volume2/docker/music:/music:ro \ -v /volume2/docker/LMS/playlist:/playlist:rw \ -v "/etc/localtime":"/etc/localtime":ro \ -e PUID=1026 \ -e PGID=100 \ -e TZ=Asia/Shanghai \ --network host \ snoopy86/logitechmediaserver

this is the log which I use the default settings

Starting Squeeze2upnp: /config/cache/InstalledPlugins/Plugins/UPnPBridge/Bin/squeeze2upnp-x86-64-static -Z -I -f /config/logs/upnpbridge.log -x /config/prefs/upnpbridge.xml [11:06:33.864718] main:1774 Starting squeeze2upnp version: v1.81.3 (Jan 25 2022 @ 21:19:39) [11:06:33.920832] register_alac:541 using alac to decode alc [11:06:33.920919] register_mad:433 using mad to decode mp3 [11:06:33.920940] register_faad:647 using faad to decode aac [11:06:33.920960] register_vorbis:346 using vorbis to decode ogg [11:06:33.920979] register_pcm:339 using pcm [11:06:33.920998] register_flac:313 using flac to decode flc [11:06:33.921017] register_opus:286 using opus to decode ops [11:06:33.921036] register_m4a_thru:307 using mp4 to aac (ADTS) [11:06:33.921055] register_flac_thru:212 using flac [11:06:33.921074] register_thru:106 using thru [11:06:33.921093] register_soxr:394 using soxr for resampling [11:06:33.921115] Start:1536 Binding to 192.168.6.189:49153 (http:0) [11:06:43.396132] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [11:06:44.521290] AddMRDevice:1423 [0xc44b00]: adding renderer (小爱音箱-5260) [11:06:44.521381] GetProtocolInfo:359 [0xc44b00]: uPNP GetProtocolInfo [11:06:44.528428] GetProtocolInfo:370 [0xc44b00]: ProtocolInfo http-get:::* [11:06:44.528768] stream_thread_init:464 [0xbbb140] streambuf size: 1048576 [11:06:44.530345] output_thread_init:616 [0xbbb140] init output media renderer [11:06:44.530446] decode_thread_init:168 [0xbbb140]: init decode [11:06:44.530525] resample_init:345 [0xbbb140]: resampling sync recipe: 0x00, flags: 0x00, scale: 0.89, precision: 0.0, passband_end: 0.00000, stopband_begin: 0.00000, phase_response: -1.0 [11:06:44.530566] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [11:06:44.531553] discover_server:809 [0xbbb140] sending discovery [11:06:44.532339] discover_server:841 [0xbbb140] got response from: 192.168.6.189:3483 [11:06:44.532435] slimproto:861 squeezelite [0xbbb140] <=> player [0xc44b00] [11:06:44.532460] slimproto:862 [0xbbb140] connecting to 192.168.6.189:3483 [11:06:44.532674] slimproto:892 [0xbbb140] connected [11:06:44.532755] sendHELO:134 [0xbbb140] mac: bb:bb:a6:ba:fd:4f [11:06:44.532780] sendHELO:135 [0xbbb140] cap: CanHTTPS=1,Model=squeezelite,ModelName=UPnPBridge,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=48000, [11:06:44.535256] process:500 [0xbbb140] strm [11:06:44.535337] process_strm:241 [0xbbb140] strm command q [11:06:44.535359] decode_flush:208 [0xbbb140]: decode flush [11:06:44.535380] output_flush:611 [0xbbb140]: flush output buffer [11:06:44.535398] MasterHandler:1054 [0xc44b00]: subscribe success [11:06:44.535457] sq_callback:316 [0xc44b00]: device off or not controlled by LMS [11:06:44.535493] process:500 [0xbbb140] strm [11:06:44.535514] process_strm:241 [0xbbb140] strm command q [11:06:44.535533] decode_flush:208 [0xbbb140]: decode flush [11:06:44.535553] output_flush:611 [0xbbb140]: flush output buffer [11:06:44.536266] process:500 [0xbbb140] setd [11:06:44.536320] sendSETDName:227 [9]: set playername: 小爱音箱-5260 [11:06:44.536385] process:500 [0xbbb140] setd [11:06:44.536418] process:500 [0xbbb140] aude [11:06:44.536440] process_aude:392 [0xbbb140] on/off using aude 1 [11:06:44.536461] sq_callback:312 [0xc44b00]: device set on/off 1 [11:06:44.536489] process:500 [0xbbb140] audg [11:06:44.536510] process_audg:406 [0xbbb140] (old) audg gainL: 110 gainR: 110 [11:06:45.818712] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [11:06:46.002783] process:500 [0xbbb140] strm [11:06:46.002976] process_strm:241 [0xbbb140] strm command t [11:06:46.003008] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [11:06:47.611289] UpdateThread:1169 [0xc44b00] UPnP keep alive: 小爱音箱-5260 [11:06:51.008860] process:500 [0xbbb140] strm [11:06:51.008936] process_strm:241 [0xbbb140] strm command t [11:06:51.008959] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [11:06:53.007745] UpdateThread:1110 Presence checking [11:06:54.025608] UpdateThread:1110 Presence checking [11:06:55.001250] process:500 [0xbbb140] strm [11:06:55.001359] process_strm:241 [0xbbb140] strm command t [11:06:55.001384] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [11:06:59.001554] process:500 [0xbbb140] strm [11:06:59.001656] process_strm:241 [0xbbb140] strm command t [11:06:59.001680] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [11:06:59.590756] UpdateThread:1169 [0xc44b00] UPnP keep alive: 小爱音箱-5260 [11:06:59.800553] process:500 [0xbbb140] strm [11:06:59.800645] process_strm:241 [0xbbb140] strm command q [11:06:59.800668] decode_flush:208 [0xbbb140]: decode flush [11:06:59.800696] output_flush:611 [0xbbb140]: flush output buffer [11:06:59.800720] AVTStop:217 [0xc44b00]: uPNP stop (cookie (nil)) [11:07:00.673482] UpdateThread:1169 [0xc44b00] UPnP keep alive: 小爱音箱-5260 [11:07:03.001337] process:500 [0xbbb140] strm [11:07:03.001424] process_strm:241 [0xbbb140] strm command t [11:07:03.001448] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [11:07:05.085374] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [11:07:06.748961] process:500 [0xbbb140] strm [11:07:06.749055] process_strm:241 [0xbbb140] strm command q [11:07:06.749077] decode_flush:208 [0xbbb140]: decode flush [11:07:06.749099] output_flush:611 [0xbbb140]: flush output buffer [11:07:06.749122] AVTStop:217 [0xc44b00]: uPNP stop (cookie 0x1) [11:07:06.823387] ActionHandler:837 [0xc44b00]: Waited action StopResponse [11:07:07.000943] process:500 [0xbbb140] strm [11:07:07.001034] process_strm:241 [0xbbb140] strm command t [11:07:07.001058] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [11:07:09.546553] _SyncNotifState:659 [0xc44b00]: uPNP stop [11:07:09.546637] sq_notify:651 [0xbbb140] notify STOP [11:07:11.002257] process:500 [0xbbb140] strm [11:07:11.002347] process_strm:241 [0xbbb140] strm command t [11:07:11.002370] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [11:07:12.156431] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [11:07:12.197751] process:500 [0xbbb140] strm [11:07:12.197839] process_strm:241 [0xbbb140] strm command q [11:07:12.197861] decode_flush:208 [0xbbb140]: decode flush [11:07:12.197883] output_flush:611 [0xbbb140]: flush output buffer [11:07:12.197905] AVTStop:217 [0xc44b00]: uPNP stop (cookie 0x3) [11:07:12.209296] ActionHandler:837 [0xc44b00]: Waited action StopResponse [11:07:13.002074] UpdateThread:1110 Presence checking [11:07:14.001340] UpdateThread:1110 Presence checking [11:07:14.541496] _SyncNotifState:659 [0xc44b00]: uPNP stop [11:07:14.541580] sq_notify:651 [0xbbb140] notify STOP [11:07:14.839275] process:500 [0xbbb140] strm [11:07:14.839365] process_strm:241 [0xbbb140] strm command q [11:07:14.839387] decode_flush:208 [0xbbb140]: decode flush [11:07:14.839409] output_flush:611 [0xbbb140]: flush output buffer

philippe44 commented 2 years ago

Can you try to play something? There is no play attempt in that log

houoop commented 2 years ago

it can't play anything , i try to play mp3 or flac from my library. if I click the play button , the logger will output these logs

[13:18:32.002468] UpdateThread:1110 Presence checking [13:18:32.003439] process:500 [0xbbb140] strm [13:18:32.003531] process_strm:241 [0xbbb140] strm command t [13:18:32.003555] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [13:18:32.203095] UpdateThread:1110 Presence checking [13:18:33.352621] process:500 [0xbbb140] strm [13:18:33.352713] process_strm:241 [0xbbb140] strm command q [13:18:33.352736] decode_flush:208 [0xbbb140]: decode flush [13:18:33.352758] output_flush:611 [0xbbb140]: flush output buffer [13:18:33.352780] AVTStop:217 [0xc44b00]: uPNP stop (cookie (nil)) [13:18:33.593203] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml [13:18:37.001544] process:500 [0xbbb140] strm [13:18:37.001735] process_strm:241 [0xbbb140] strm command t [13:18:37.001761] sendSTAT:169 [0xbbb140]: STAT:[STMt] msplayed 0 [13:18:38.933297] process:500 [0xbbb140] strm [13:18:38.933395] process_strm:241 [0xbbb140] strm command q [13:18:38.933419] decode_flush:208 [0xbbb140]: decode flush [13:18:38.933452] output_flush:611 [0xbbb140]: flush output buffer [13:18:38.933477] AVTStop:217 [0xc44b00]: uPNP stop (cookie 0x1) [13:18:38.948958] ActionHandler:837 [0xc44b00]: Waited action StopResponse [13:18:40.007731] UpdateThread:1273 Updating configuration /config/prefs/upnpbridge.xml

philippe44 commented 2 years ago

If LMS does not try to play that means that your library is not well scanned. It typically does that when it cannot find the file you are trying to play

houoop commented 2 years ago

But I have another squeeze player can play music in LMS

houoop commented 2 years ago

whether would I change any param to get it work , I try the silent param in transcode setting, it can play , and my wifi speaker's android app show it is playing.

houoop commented 2 years ago

if I try any transcode param , It just get other error or crash to restart always.

philippe44 commented 2 years ago

Transcode should be "none" to start with (again, a blank / erased /clean config is what you want first). Please if you want my help dont try random things and setting changes. Now, your protocolInfo returned by the player is corrupted

[11:06:44.528428] GetProtocolInfo:370 [0xc44b00]: ProtocolInfo http-get:::*

Can you try "DeviceSpy" https://www.meshcommander.com/upnptools or a similar tool and under "ConnectManager" of you device, invoke "GetProtocolInfo" so see what comes back.

Otherwise, you can add in "additional mimetypes" (advanced settings of audio capabilities) and add "audio/mp3,audio/flac" - of course no "") and see what happens

houoop commented 2 years ago

iShot2022-01-28 14 33 51

philippe44 commented 2 years ago

Well, that's the first time a player says "I can support ANYTHING" which is obviously wrong, there is a reason why ProtocolInfo was created - crap, again a crappy implementation. Try the trick of the additional mimetype

houoop commented 2 years ago

it work . thanks! xiaomi smart wifi speaker is a very famous product in China , so I think every xiaomi user will happen this problem. If you can , you could fix this for us. Thanks you very much.

philippe44 commented 2 years ago

Yes, I know it's a famous speaker, but still the ProtocolInfo is questionable at best

houoop commented 2 years ago

maybe this player's DLNA reciever is not standard implemented

houoop commented 2 years ago

I found another problem , It can't go to next track when a song end

philippe44 commented 2 years ago

Send a log here, but it feels like another bad implementation if UPnP's gapless feature. In settings, try to set "Gapless" to "No" and see

houoop commented 2 years ago

it's not work when the Gapless is No, this is the log. upnpbridge (1).log

philippe44 commented 2 years ago

Sorry but this log is too verbose to start with (do not add any additional debugging) and incomplete. Just clean the log, put a few tracks in the playlist and let it go till it fails.

houoop commented 2 years ago

'Additional debugging' is None , I have set it. upnpbridge (2).log

houoop commented 2 years ago

It can go to next track automatically when “Gapless” is Force. I would still be curious to have a good log with "No" set

philippe44 commented 2 years ago

'Additional debugging' is None , I have set it. upnpbridge (2).log

This is the same log

philippe44 commented 2 years ago

It can go to next track automatically when “Gapless” is Force.

OMG, this really means implementation is bad...

houoop commented 2 years ago

I don't know how to get the clean log, I have erased the old log file and restarted.

philippe44 commented 2 years ago

I don't know how to get the clean log, I have erased the old log file and restarted.

Can you send me a copy of your config file? and a screenshot or the settings UI?

houoop commented 2 years ago

iShot2022-01-28 15 44 13

houoop commented 2 years ago

iShot2022-01-28 15 45 15

philippe44 commented 2 years ago

Your config.xml contains all the log statements set to debug, for a reason I don't understand. Either erase the lines like debug or erase the whole file. But to erase if properly, stop the bridge, erase it, and restart the bridge. After a few seconds, it should re-created and then you can add the "additional mimetypes" and the post a log with "gapless" set to "No" and a failed track transition

houoop commented 2 years ago

Starting Squeeze2upnp: /config/cache/InstalledPlugins/Plugins/UPnPBridge/Bin/squeeze2upnp-x86-64-static -Z -I -f /config/logs/upnpbridge.log -x /config/prefs/upnpbridge.xml [15:59:41.930151] main:1774 Starting squeeze2upnp version: v1.81.3 (Jan 25 2022 @ 21:19:39) [15:59:41.932503] Start:1536 Binding to 192.168.6.189:49153 (http:0) [15:59:46.548656] AddMRDevice:1423 [0xc44b00]: adding renderer (小爱音箱-5260) [15:59:46.575277] slimproto:861 squeezelite [0xbbb140] <=> player [0xc44b00] [15:59:46.575357] slimproto:862 [0xbbb140] connecting to 192.168.6.189:3483 [15:59:46.575530] slimproto:892 [0xbbb140] connected [15:59:46.575604] sendHELO:135 [0xbbb140] cap: CanHTTPS=1,Model=squeezelite,ModelName=UPnPBridge,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=48000,flc,mp3 [15:59:46.580104] MasterHandler:1054 [0xc44b00]: subscribe success [15:59:51.051442] AddMRDevice:1423 [0xc46e28]: adding renderer (小爱音箱-7643) [15:59:51.060351] slimproto:861 squeezelite [0xbbf608] <=> player [0xc46e28] [15:59:51.060434] slimproto:862 [0xbbf608] connecting to 192.168.6.189:3483 [15:59:51.061292] slimproto:892 [0xbbf608] connected [15:59:51.061433] sendHELO:135 [0xbbf608] cap: CanHTTPS=1,Model=squeezelite,ModelName=UPnPBridge,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=48000,flc,mp3 [15:59:51.066756] MasterHandler:1054 [0xc46e28]: subscribe success [16:00:06.838971] AVTStop:217 [0xc44b00]: uPNP stop (cookie (nil)) [16:00:06.900070] process_strm:238 [0xbbb140] strm command s [16:00:06.900158] process_strm:307 [0xbbb140], strm s autostart: 1 transition period: 10 transition type: 0 codec: f [16:00:06.900184] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [16:00:06.912582] output_start:81 [0xbbb140]: start thread 0 [16:00:06.912749] sqcallback:343 [0xc44b00]: artist:李健 album:似水流年 title:一辈子的十分钟 genre:无音乐曲风 duration:307.000 size:0 cover:http://192.168.6.189:9000/music/649e4470/cover.jpg offset:0 [16:00:06.912786] sq_callback:382 [0xc44b00]: set current URI (s:0) http://192.168.6.189:37865/bridge-1.flac [16:00:06.912898] AVTSetURI:91 [0xc44b00]: uPNP setURI http://192.168.6.189:37865/bridge-1.flac (cookie 0x1) [16:00:06.913217] process_start:1220 [0xbbb140]: codec:c, ch:0, s:0, r:0 [16:00:06.913748] sendSTAT:169 [0xbbb140]: STAT:[STMc] msplayed 0 [16:00:06.924742] AVTSetPlayMode:167 [0xc44b00]: uPNP set play mode (cookie 0x2) [16:00:06.924932] AVTPlay:151 [0xc44b00]: uPNP play (cookie 0x2) [16:00:06.925012] CtrlSetVolume:245 [0xc44b00]: uPNP volume 19 (cookie 0x2) [16:00:07.019487] output_http_thread:157 [0xbbb140]: got HTTP connection 17 [16:00:07.019827] output_http_thread:186 [0xbbb140]: drain is 2621440 (waited 107) [16:00:07.023943] handle_http:483 [0xbbb140]: received GET /bridge-1.flac HTTP/1.1 [16:00:07.024036] handle_http:486 [0xbbb140]: HTTP headers Host: 192.168.6.189:37865 User-Agent: xiaoai Range: bytes=0- Connection: close Icy-MetaData: 1

HTTP/1.1 200 OK Server: squeezebox-bridge Connection: close Content-Type: audio/flac Transfer-Encoding: chunked

[16:00:07.515820] _SyncNotifState:687 小爱音箱-5260: uPNP playing [16:00:07.517158] sendSTAT:169 [0xbbb140]: STAT:[STMs] msplayed 0 [16:00:21.923581] output_http_thread:389 [0xbbb140]: end thread 0 (3506176 bytes) [16:00:21.925028] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [16:00:21.925173] AVTStop:217 [0xc44b00]: uPNP stop (cookie 0x31) [16:00:21.942039] process_strm:238 [0xbbb140] strm command s [16:00:21.942132] process_strm:307 [0xbbb140], strm s autostart: 1 transition period: 10 transition type: 0 codec: f [16:00:21.942156] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [16:00:21.953292] output_start:81 [0xbbb140]: start thread 0 [16:00:21.953630] sqcallback:343 [0xc44b00]: artist:李健 album:似水流年 title:一辈子的十分钟 genre:无音乐曲风 duration:24.675 size:0 cover:http://192.168.6.189:9000/music/649e4470/cover.jpg offset:0 [16:00:21.953676] sq_callback:382 [0xc44b00]: set current URI (s:0) http://192.168.6.189:60980/bridge-2.flac [16:00:21.953812] AVTSetURI:91 [0xc44b00]: uPNP setURI http://192.168.6.189:60980/bridge-2.flac (cookie 0x32) [16:00:21.953893] process_start:1220 [0xbbb140]: codec:c, ch:0, s:0, r:0 [16:00:21.954082] sendSTAT:169 [0xbbb140]: STAT:[STMc] msplayed 0 [16:00:22.048423] AVTSetPlayMode:167 [0xc44b00]: uPNP set play mode (cookie 0x33) [16:00:22.048568] AVTPlay:151 [0xc44b00]: uPNP play (cookie 0x33) [16:00:22.048636] CtrlSetVolume:245 [0xc44b00]: uPNP volume 19 (cookie 0x33) [16:00:22.173948] output_http_thread:157 [0xbbb140]: got HTTP connection 17 [16:00:22.174051] output_http_thread:186 [0xbbb140]: drain is 2621440 (waited 219) [16:00:22.177689] handle_http:483 [0xbbb140]: received GET /bridge-2.flac HTTP/1.1 [16:00:22.177729] handle_http:486 [0xbbb140]: HTTP headers Host: 192.168.6.189:60980 User-Agent: xiaoai Range: bytes=0- Connection: close Icy-MetaData: 1

HTTP/1.1 200 OK Server: squeezebox-bridge Connection: close Content-Type: audio/flac Transfer-Encoding: chunked

[16:00:22.513889] process_strm:238 [0xbbb140] strm command u [16:00:22.513976] process_strm:287 [0xbbb140] unpause at: 0 now: 364046791 [16:00:22.514004] sendSTAT:169 [0xbbb140]: STAT:[STMr] msplayed 0 [16:00:22.661069] _SyncNotifState:687 小爱音箱-5260: uPNP playing [16:00:22.663005] sendSTAT:169 [0xbbb140]: STAT:[STMs] msplayed 0 [16:00:22.718742] output_http_thread:389 [0xbbb140]: end thread 0 (1671168 bytes) [16:00:22.719609] AVTStop:217 [0xc44b00]: uPNP stop (cookie 0x38) [16:00:22.719838] process_strm:238 [0xbbb140] strm command s [16:00:22.719865] process_strm:307 [0xbbb140], strm s autostart: 1 transition period: 10 transition type: 0 codec: f [16:00:22.719888] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 0 [16:00:22.730036] output_start:81 [0xbbb140]: start thread 0 [16:00:22.730158] sqcallback:343 [0xc44b00]: artist:李健 album:似水流年 title:一辈子的十分钟 genre:无音乐曲风 duration:35.492 size:0 cover:http://192.168.6.189:9000/music/649e4470/cover.jpg offset:0 [16:00:22.730194] sq_callback:382 [0xc44b00]: set current URI (s:0) http://192.168.6.189:45907/bridge-3.flac [16:00:22.730318] AVTSetURI:91 [0xc44b00]: uPNP setURI http://192.168.6.189:45907/bridge-3.flac (cookie 0x39) [16:00:22.730388] process_start:1220 [0xbbb140]: codec:c, ch:0, s:0, r:0 [16:00:22.730611] sendSTAT:169 [0xbbb140]: STAT:[STMc] msplayed 0 [16:00:22.821869] AVTSetPlayMode:167 [0xc44b00]: uPNP set play mode (cookie 0x3a) [16:00:22.822019] AVTPlay:151 [0xc44b00]: uPNP play (cookie 0x3a) [16:00:22.822089] CtrlSetVolume:245 [0xc44b00]: uPNP volume 19 (cookie 0x3a) [16:00:23.021113] output_http_thread:157 [0xbbb140]: got HTTP connection 17 [16:00:23.022474] output_http_thread:186 [0xbbb140]: drain is 2621440 (waited 292) [16:00:23.032674] handle_http:483 [0xbbb140]: received GET /bridge-3.flac HTTP/1.1 [16:00:23.032774] handle_http:486 [0xbbb140]: HTTP headers Host: 192.168.6.189:45907 User-Agent: xiaoai Range: bytes=0- Connection: close Icy-MetaData: 1

HTTP/1.1 200 OK Server: squeezebox-bridge Connection: close Content-Type: audio/flac Transfer-Encoding: chunked

[16:00:23.289754] process_strm:238 [0xbbb140] strm command u [16:00:23.289850] process_strm:287 [0xbbb140] unpause at: 0 now: 364047567 [16:00:23.289877] sendSTAT:169 [0xbbb140]: STAT:[STMr] msplayed 0 [16:00:23.867515] _SyncNotifState:687 小爱音箱-5260: uPNP playing [16:00:23.868515] sendSTAT:169 [0xbbb140]: STAT:[STMs] msplayed 0

[16:00:31.768175] sendSTAT:169 [0xbbb140]: STAT:[STMd] msplayed 7000 [16:00:31.800869] process_strm:238 [0xbbb140] strm command s [16:00:31.800957] process_strm:307 [0xbbb140], strm s autostart: 1 transition period: 10 transition type: 0 codec: f [16:00:31.800981] sendSTAT:169 [0xbbb140]: STAT:[STMf] msplayed 7000 [16:00:31.809127] output_start:81 [0xbbb140]: start thread 1 [16:00:31.809280] sqcallback:343 [0xc44b00]: artist:李健 album:无时无刻 title:我唯有的你 genre:Pop duration:252.091 size:0 cover:http://192.168.6.189:9000/music/631c1b46/cover.jpg offset:1 [16:00:31.809333] sq_callback:369 [0xc44b00]: next URI gapped (s:0) http://192.168.6.189:42932/bridge-4.flac [16:00:31.809356] process_start:1220 [0xbbb140]: codec:c, ch:0, s:0, r:0 [16:00:31.809541] sendSTAT:169 [0xbbb140]: STAT:[STMc] msplayed 7000

[16:00:35.753388] output_http_thread:389 [0xbbb140]: end thread 0 (3776321 bytes)

philippe44 commented 2 years ago

Can you tell me what's happening in that log? Seems that 1st track plays but stops after ~20s and the player moves to the next one. Is this correct?

houoop commented 2 years ago

I just play a song , because The song need 5min to go to the end , I drag the progress bar to near the end, then several seconds later, it stop at the end, and the play buttion in web is also show "Playing", but it don't play any voice.

philippe44 commented 2 years ago

I just play a song , because The song need 5min to go to the end , I drag the progress bar to near the end, then several seconds later, it stop at the end, and the play buttion in web is also show "Playing", but it don't play any voice.

Understood - that was pretty confusing. So, there is nothing in the log after, even waiting past the current track?

[16:00:31.809333] sq_callback:369 [0xc44b00]: next URI gapped (s:0) http://192.168.6.189:42932/bridge-4.flac
[16:00:31.809356] process_start:1220 [0xbbb140]: codec:c, ch:0, s:0, r:0
[16:00:31.809541] sendSTAT:169 [0xbbb140]: STAT:[STMc] msplayed 7000
[16:00:35.752809] output_http_thread:258 [0xbbb140]: self-exit
[16:00:35.753388] output_http_thread:389 [0xbbb140]: end thread 0 (3776321 bytes)
houoop commented 2 years ago

Yes , when it stopped , there was not logs any more. Then if I click the "NEXT BUTTON" in web ui , it can play next track normally

houoop commented 2 years ago

I just find these two line logs be added, maybe it can help you

[16:00:31.809541] sendSTAT:169 [0xbbb140]: STAT:[STMc] msplayed 7000

[16:00:35.753388] output_http_thread:389 [0xbbb140]: end thread 0 (3776321 bytes) [16:15:34.001027] slimproto_run:573 [0xbbb140] Closing CLI socket 10

philippe44 commented 2 years ago

This is pretty amazing, the player does not even signal to its controller that it has stopped/finished!!! I know I'm repeating myself, but it seems an extremely broken UPnP implementation

houoop commented 2 years ago

the player is playing correctly when I use the "forked daapd" music server's DLNA.

philippe44 commented 2 years ago

hmmm... I don't understand. AFAIK, forked daap is an AirPlay controller, not UPnP. Having said that, controllers which are just controller can more easily deal with broken players because they are the master of the system. My bridge is ... a bridge and has LMS as a master, so there are a bunch of aggressive actions I can no take "against" the player because LMS might counter them at any time. Out of curiosity, send me the exact reference (picture?) of the player so I can see if I can put my hands on one.

houoop commented 2 years ago

I use airconnect to switch upnp to airplay . what pictures do you want? I don't understand.

philippe44 commented 2 years ago

Yes but if you use AirConnect, the way communication is handled with the UPnP device is different. There is no track change, so the problem where the player does not report an "end of track" is irrelevant because AirPlay is just one single big track. Re picture I mean there are so many Xiaomi products (even "smart speaker"), send me a picture of this exact one.

philippe44 commented 2 years ago

Once thing you could do to help is take again a log when a track when a track ends and do not move to next one (Gapless set to "No") but also with in Additional Debugging, set "main application debugging". Clean the log, play 2 tracks and wait 30s after 1st track ends and nothing happens.

houoop commented 2 years ago

upnpbridge (3).log

I have two kind of product , they have same problem. pms_1597400546 0912252 下载

philippe44 commented 2 years ago

Thanks - These log & pictures gave me the information I needed. I've already done a change to support the ProtocolInfo returned by that player but if possible I'd like to get one last detail. In the same conditions than above, can you use DeviceSpy and invoke the "GetTransportInfo", under the "AVTransport service one time when it is playing and, ~15s after it has stopped and has not moved to next track, invoke it again and tell me what is the "CurrentTransportState" in both cases?

houoop commented 2 years ago

when it's playing , CurrentTransportState is "PLAYING", and when it's play ended after 15s, CurrentTransportState is also "PLAYING"

philippe44 commented 2 years ago

Thanks - that confirms the problem, crap. I have to decide if I do yet another workaround for a faulty player or not - this is how you destroy standards by making compromises ☹️

houoop commented 2 years ago

when I stop the song in the middle progress, then I play contine , it will replay this song from the start

houoop commented 2 years ago

yes, I know , can you write a special-purpose(for xiaomi player)settings file for these palyer to fix these problem. we can choose this setting by ourself.

philippe44 commented 2 years ago

I've pushed a version 1.82.0. Can you, in the following order

1- Does it solve the problem of not moving to next track with the configration above 2- If you set HTTP mode to "no length" does it work 3- Different topic: if you remove the "extra mimetype" in the settings does it now plays mp3/flac normally

In all 3 cases, if it fails, can you add the log