philippe44 / SpotConnect

Turn any UPnP or AirPlay player into a Spotify Connect device
MIT License
77 stars 3 forks source link

Spot upnp Segmentation fault #19

Closed Jelobax closed 1 year ago

Jelobax commented 1 year ago

Hi, thanks for sharing this awesome application. I have an Upnp Streamer, Yamaha NP-S2000. When i hit the stop button or turn the streamer off the application shuts down with Connection lost, will need to reconnect... Segmentation fault I run spotupnp-linux-armv6-static (interactive) on RaspberryPi 4 with 64-bit Cortex A-72 processor PRETTY_NAME="Raspbian GNU/Linux 11 (bullseye)" NAME="Raspbian GNU/Linux" VERSION_ID="11" VERSION="11 (bullseye)" VERSION_CODENAME=bullseye ID=raspbian

Cut from interactive mode window; [17:41:53.239708] ActionHandler:584 [0xf3f1f008]: uPNP playing D MercurySession.cpp:251: Executing Mercury Request, type SEND I spotify.cpp:351: current trackInfo id 183327d85ad24632940c84d5f0d723dd => I spotify.cpp:419: track bbbbde72dd49_2 started by URL (1) I spotify.cpp:383: adjusting real position 0 from 0 (offset is 0) D MercurySession.cpp:251: Executing Mercury Request, type SEND I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet E HTTPstreamer.cpp:400: HTTP error for bbbbde72dd49_2 => send(15, 32768) = 9768 I HTTPstreamer.cpp:459: HTTP close 15 [17:42:48.283075] ActionHandler:564 [0xf3f1f008]: uPNP stopped I spotify.cpp:445: Disconnecting NP-S2000

[17:42:48.283201] AVTStop:204 [0xf3f1f008]: uPNP stop (cookie 0xb0) I HTTPstreamer.cpp:148: HTTP streamer bbbbde72dd49_2 deleted I TrackPlayer.cpp:94: Resetting state I MercurySession.cpp:128: Disconnecting mercury session I PlainConnection.cpp:197: Closing socket... E PlainConnection.cpp:146: Connection lost, will need to reconnect... Segmentation fault jibax@raspberrypi:~/Desktop/spotconnect $

Great if you are able to help with this issue. /Jesper

philippe44 commented 1 year ago

Does it happen all the time? Does it happen under other circumstances? I can't reproduce at that time and what happens when stopping a player from the player itself is often difficult to handle.

Jelobax commented 1 year ago

It happens every time I shut down the player. But as long as I play it works. Pause also works. I also see this problem in the Windows version but no error messages there. I could try and change the network settings in the player. Change to statis IP or use the Mac address filter function. I also can try with a more modern Yamaha AV-Receiver. I will let you know my findings.

philippe44 commented 1 year ago

Oh, if you see an error in Windows instead of a crash that would be much more useful (although I've probably left debug symbols at that stage so you can use gdb if you're familiar with it on your Linux box)

Jelobax commented 1 year ago

I see now that the program crashes when I turn on the player again. If you look below. I turn the player off at 21:47:01, I then turn it on again at 21:47:42, this is from the Windows version. So the program deletes the player after I turn it on again and then crashes.

vNvdOeF3iv9KEOn0= ←[0;34mI ←[0;93mspotify.cpp←[0m:385: ←[0madjusting real position 0 from 20700 (offset is 0) ←[0;31mD ←[0;37mMercurySession.cpp←[0m:252: Executing Mercury Request, type SEND ←[0;34mI ←[0;37mMercurySession.cpp←[0m:42: ←[0mReceived packet, command: 178 ←[0;31mD ←[0;37mMercurySession.cpp←[0m:174: Received mercury packet [21:47:01.530] ActionHandler:648 Error in action callback -- -204 (cookie 00000070) [21:47:01.530] ActionHandler:648 Error in action callback -- -204 (cookie 0000006F) [21:47:02.042] ActionHandler:648 Error in action callback -- -204 (cookie 00000071) [21:47:02.538] ActionHandler:648 Error in action callback -- -204 (cookie 00000072) [21:47:02.538] ActionHandler:648 Error in action callback -- -204 (cookie 00000073) [21:47:03.053] ActionHandler:648 Error in action callback -- -204 (cookie 00000074) [21:47:03.546] ActionHandler:648 Error in action callback -- -204 (cookie 00000075) [21:47:04.065] ActionHandler:648 Error in action callback -- -204 (cookie 00000076) [21:47:04.566] ActionHandler:648 Error in action callback -- -204 (cookie 00000078) [21:47:04.566] ActionHandler:648 Error in action callback -- -204 (cookie 00000077) [21:47:05.064] ActionHandler:648 Error in action callback -- -204 (cookie 00000079) [21:47:06.546] ActionHandler:648 Error in action callback -- -204 (cookie 0000007A) [21:47:06.546] ActionHandler:648 Error in action callback -- -204 (cookie 0000007B) [21:47:07.048] ActionHandler:648 Error in action callback -- -204 (cookie 0000007C) [21:47:07.550] ActionHandler:648 Error in action callback -- -204 (cookie 0000007D) [21:47:07.550] ActionHandler:648 Error in action callback -- -204 (cookie 0000007E) [21:47:08.064] ActionHandler:648 Error in action callback -- -204 (cookie 0000007F) [21:47:42.021] MasterHandler:732 [0147DE28]: Auto-renewal failed, re-subscribing ←[0;31mE ←[0;92mHTTPstreamer.cpp←[0m:400: ←[0;31mHTTP error for bbbbde72dd49_1 => send(1356, 32768) = 0 ←[0;34mI ←[0;92mHTTPstreamer.cpp←[0m:459: ←[0mHTTP close 1356 [21:47:47.027] MasterHandler:756 [0147DE28]: subscribe fail, re-trying 1 [21:47:52.037] MasterHandler:756 [0147DE28]: subscribe fail, re-trying 2 [21:47:53.178] MasterHandler:756 [0147DE28]: subscribe fail, re-trying 3 [21:47:53.493] MasterHandler:760 [0147DE28]: subscribe fail, volume feedback will not work [21:47:53.792] UpdateThread:830 [0147DE28]: renderer bye-bye: NP-S2000+ ←[0;34mI ←[0;93mspotify.cpp←[0m:125: ←[0mplayer <NP-S2000+> deletion pending ←[0;34mI ←[0;90mTrackPlayer.cpp←[0m:94: ←[0mResetting state ←[0;34mI ←[0;37mMercurySession.cpp←[0m:128: ←[0mDisconnecting mercury session ←[0;34mI ←[0;35mPlainConnection.cpp←[0m:197: ←[0mClosing socket... ←[0;31mE ←[0;37mMercurySession.cpp←[0m:53: ←[0;31mError while receiving packet: Error in read ←[0;34mI ←[0;90mTrackPlayer.cpp←[0m:249: ←[0mPlaying done ←[0;34mI ←[0;93mspotify.cpp←[0m:551: ←[0mdisconnecting player <NP-S2000+> ←[0;34mI ←[0;93mspotify.cpp←[0m:555: ←[0mterminating player <NP-S2000+> ←[0;34mI ←[0;93mspotify.cpp←[0m:135: ←[0mdone ←[0;34mI ←[0;92mHTTPstreamer.cpp←[0m:148: ←[0mHTTP streamer bbbbde72dd49_1 deleted

philippe44 commented 1 year ago

I'm not sure I see the crash in that log

Jelobax commented 1 year ago

Hi I have installed GDB on my Linux box. But not sure how to use it. I run this command: gdb exec-file ./spotupnp-linux-armv6-static -x config There a new window opening that seam to be a debug window saying: No source available

Can you give any hints or point me in a direction on how use GDB?

philippe44 commented 1 year ago

When using a program with arga, you must use the --args option first in front. Like gdb --args ./spotupnp... -f ...

Hit return and then type run.

The ... are figurative, they just mean your command line in whole

Jelobax commented 1 year ago

ok, now im getting data in the debug window: [New LWP 2371] I spotify.cpp:495: Server using actual port 43893 I MDNSService.cpp:181: using built-in mDNS for NP-S2000 [LWP 2301 exited] [New LWP 2382] [LWP 2382 exited] [New LWP 2383] [New LWP 2384] [LWP 2384 exited] [LWP 2383 exited] [New LWP 2386] [LWP 2386 exited] [New LWP 2391] [New LWP 2392] [LWP 2392 exited] [LWP 2391 exited] [New LWP 2393] [LWP 2393 exited] [New LWP 2394] [New LWP 2395] [LWP 2395 exited] [LWP 2394 exited] [New LWP 2397] [LWP 2397 exited] [New LWP 2398] [16:08:25.004678] UpdateThread:815 [0xf3f9e008]: removing unresponsive player (NP-S2000) I spotify.cpp:125: player deletion pending I spotify.cpp:555: terminating player I spotify.cpp:135: done [LWP 2366 exited] [LWP 2371 exited] [LWP 2370 exited] [LWP 2369 exited] [LWP 2368 exited] [LWP 2367 exited] [LWP 2398 exited] [New LWP 2400] [LWP 2400 exited] [New LWP 2401] [New LWP 2402]

Jelobax commented 1 year ago

Hi I did another try and this time I got another message in the bottom. I did as before, started spotupnp, started player and connected spotify. Then i turned of player and after a while turned on player again and its then spotupnp craches. jibax@raspberrypi:~/Desktop/spotconnect $ gdb --args ./spotupnp-linux-armv6-static -x config GNU gdb (Raspbian 10.1-1.7) 10.1.90.20210103-git Copyright (C) 2021 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "arm-linux-gnueabihf". Type "show configuration" for configuration details. For bug reporting instructions, please see: https://www.gnu.org/software/gdb/bugs/. Find the GDB manual and other documentation resources online at: http://www.gnu.org/software/gdb/documentation/.

For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from ./spotupnp-linux-armv6-static... (No debugging symbols found in ./spotupnp-linux-armv6-static) (gdb) run Starting program: /home/jibax/Desktop/spotconnect/spotupnp-linux-armv6-static -x config [09:20:47.694748] main:1479 Starting stopupnp version: v0.1.6 (Aug 9 2023 @ 21:11:56) [New LWP 1683] [New LWP 1684] [New LWP 1685] [New LWP 1686] [New LWP 1687] [New LWP 1688] [New LWP 1689] [New LWP 1690] [09:20:47.763127] Start:1207 Binding to iface eth0@192.168.1.195:0 [09:20:47.763335] Start:1221 Binding to 192.168.1.195:49152 [New LWP 1691] [New LWP 1692] [LWP 1684 exited] [LWP 1688 exited] [09:21:17.100425] AddMRDevice:1133 [0xf3f9e008]: adding renderer (NP-S2000) with mac BBBB49DD72DE [New LWP 1695] [New LWP 1696] [New LWP 1697] [New LWP 1698] I BellHTTPServer.cpp:191: Server listening on port 0 [New LWP 1699] [New LWP 1700] [New LWP 1701] [New LWP 1702] [New LWP 1703] [09:21:17.184600] MasterHandler:754 [0xf3f9e008]: subscribe success [09:21:17.196592] ProcessEvent:483 [0xf3f9e008]: UPnP Volume local change 50:-1 (master) I spotify.cpp:495: Server using actual port 34873 [New LWP 1704] I MDNSService.cpp:181: using built-in mDNS for NP-S2000 [LWP 1697 exited] [LWP 1696 exited] I spotify.cpp:516: Spotify client connected for NP-S2000 D Session.cpp:63: Connecting with AP D PlainConnection.cpp:101: Connected to spotify server I Session.cpp:39: Received APHello response D Session.cpp:44: Received shannon keys D Session.cpp:82: Authorization successful [New LWP 1705] [New LWP 1706] I MercurySession.cpp:42: Received packet, command: 4 D TimeProvider.cpp:15: Time synced with spotify servers I MercurySession.cpp:42: Received packet, command: 2 I MercurySession.cpp:42: Received packet, command: 118 I MercurySession.cpp:42: Received packet, command: 27 D MercurySession.cpp:251: Executing Mercury Request, type SUB D MercurySession.cpp:153: Received country code SE I MercurySession.cpp:42: Received packet, command: 80 I MercurySession.cpp:42: Received packet, command: 31 I MercurySession.cpp:42: Received packet, command: 105 I MercurySession.cpp:42: Received packet, command: 181 I MercurySession.cpp:42: Received packet, command: 74 I MercurySession.cpp:42: Received packet, command: 179 D MercurySession.cpp:174: Received mercury packet D MercurySession.cpp:251: Executing Mercury Request, type SEND D SpircHandler.cpp:59: Sent kMessageTypeHello! I AccessKeyFetcher.cpp:99: Access token expired, fetching new one... 236 I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I MercurySession.cpp:42: Received packet, command: 181 D SpircHandler.cpp:67: Received subscription response D SpircHandler.cpp:124: Notify frame I AccessKeyFetcher.cpp:114: Access token sucessfully fetched I MercurySession.cpp:42: Received packet, command: 181 D SpircHandler.cpp:67: Received subscription response [New LWP 1707] D SpircHandler.cpp:170: Load frame 50! D MercurySession.cpp:251: Executing Mercury Request, type SEND I TrackPlayer.cpp:94: Resetting state D MercurySession.cpp:251: Executing Mercury Request, type GET I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I TrackQueue.cpp:158: Track name: The Sinking Feeling I TrackQueue.cpp:159: Track duration: 221000 D TrackQueue.cpp:161: trackInfo.restriction.size() = 1 D TrackQueue.cpp:212: File format: 2 D TrackQueue.cpp:212: File format: 1 I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I MercurySession.cpp:42: Received packet, command: 13 I TrackQueue.cpp:252: Got audio key I TrackQueue.cpp:275: Received access key, fetching CDN URL... I TrackQueue.cpp:301: Received CDN URL, https://audio-fa.scdn.co/audio/2f6d714312e4800b10c85909f2435bb0c4d52132?1695626488_xDaiHdthfqHSSyUI_WjhaNuKZKORreZiA92wcpJ--bQ= I TrackPlayer.cpp:167: Got track ID=2f6d714312e4800b10c85909f2435bb0c4d52132 I CDNAudioFile.cpp:43: Opening HTTP stream to https://audio-fa.scdn.co/audio/2f6d714312e4800b10c85909f2435bb0c4d52132?1695626488_xDaiHdthfqHSSyUI_WjhaNuKZKORreZiA92wcpJ--bQ= I CDNAudioFile.cpp:70: Header and footer bytes received D MercurySession.cpp:251: Executing Mercury Request, type SEND

I spotify.cpp:260: new track will start at 5001 D MercurySession.cpp:251: Executing Mercury Request, type SEND I spotify.cpp:273: play/pause D MercurySession.cpp:251: Executing Mercury Request, type GET I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I TrackQueue.cpp:158: Track name: This Is The Night I TrackQueue.cpp:159: Track duration: 230413 D TrackQueue.cpp:161: trackInfo.restriction.size() = 1 D TrackQueue.cpp:212: File format: 2 D TrackQueue.cpp:212: File format: 1 I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I TrackPlayer.cpp:200: Playing I spotify.cpp:149: trackUniqueId update => 2f6d714312e4800b10c85909f2435bb0c4d52132 I spotify.cpp:214: new track id 36261b0a2f314ed6888f747368d020ae => I HTTPstreamer.cpp:135: Bound to port 58613 I spotify.cpp:224: loading with id bbbbde72dd49_0 [09:21:28.970603] shadowRequest:323 [0xf3f9e008]: spotify LOAD request [09:21:28.970850] AVTSetURI:78 [0xf3f9e008]: uPNP setURI http://192.168.1.195:58613/stream?id=bbbbde72dd49_0 (cookie (nil)) [09:21:28.971201] shadowRequest:337 [0xf3f9e008]: spotify play request [09:21:28.971273] AVTPlay:138 [0xf3f9e008]: uPNP play (cookie 0x1) [New LWP 1708] I HTTPstreamer.cpp:443: got HTTP connection 14 I HTTPstreamer.cpp:210: HTTP received => GET /stream?id=bbbbde72dd49_0 HTTP/1.1 Host: 192.168.1.195:58613 User-Agent: Network_Player/3.0 (NP-S2000) Accept: / transferMode.dlna.org: Streaming Content-Length: 0

I HTTPstreamer.cpp:312: HTTP response => HTTP/1.1 200 OK transfermode.dlna.org: streaming Server: spot-connect Content-Type: audio/flac Connection: close

I MercurySession.cpp:42: Received packet, command: 178 I MercurySession.cpp:42: Received packet, command: 13 D MercurySession.cpp:174: Received mercury packet I TrackQueue.cpp:252: Got audio key I TrackQueue.cpp:275: Received access key, fetching CDN URL... I TrackQueue.cpp:301: Received CDN URL, https://audio-fa.scdn.co/audio/387a217c33d3319df93fd6aeaa4998bbace75f3c?1695626489_3jPOfrkOBP9BmehclNVpp8hGBi63RS2ICba7dU7YW_8= D MercurySession.cpp:251: Executing Mercury Request, type GET I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I TrackQueue.cpp:158: Track name: Kingdom of Rain I TrackQueue.cpp:159: Track duration: 349973 D TrackQueue.cpp:161: trackInfo.restriction.size() = 1 D TrackQueue.cpp:212: File format: 2 D TrackQueue.cpp:212: File format: 1 I MercurySession.cpp:42: Received packet, command: 13 I TrackQueue.cpp:252: Got audio key I TrackQueue.cpp:275: Received access key, fetching CDN URL... I TrackQueue.cpp:301: Received CDN URL, https://audio-fa.scdn.co/audio/6dfd7357cedcf1d37a44efef11b69dc30d83dc99?1695626489_KbB9MPc-Y_ykCsn260v06zSyvKGAkm1ZAUJ_3_lQXlE= [09:21:32.635679] ActionHandler:584 [0xf3f9e008]: uPNP playing D MercurySession.cpp:251: Executing Mercury Request, type SEND I spotify.cpp:351: current trackInfo id 36261b0a2f314ed6888f747368d020ae => I spotify.cpp:419: track bbbbde72dd49_0 started by URL (1) I spotify.cpp:383: adjusting real position 3000 from 0 (offset is -5001) D MercurySession.cpp:251: Executing Mercury Request, type SEND I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet [New LWP 1709] [New LWP 1710] [New LWP 1711] [New LWP 1712] [New LWP 1713] [New LWP 1714] [New LWP 1715] [New LWP 1716] [09:22:07.635625] ActionHandler:648 Error in action callback -- -204 (cookie 0x37) [09:22:08.636618] ActionHandler:648 Error in action callback -- -204 (cookie 0x38) [09:22:08.637187] ActionHandler:648 Error in action callback -- -204 (cookie 0x39) [New LWP 1717] [09:22:09.638493] ActionHandler:648 Error in action callback -- -204 (cookie 0x3a) [New LWP 1718] [09:22:10.139724] ActionHandler:648 Error in action callback -- -204 (cookie 0x3b) [09:22:10.140003] ActionHandler:648 Error in action callback -- -204 (cookie 0x3c) [09:22:11.140393] ActionHandler:648 Error in action callback -- -204 (cookie 0x3d) [09:22:11.641178] ActionHandler:648 Error in action callback -- -204 (cookie 0x3e) [09:22:12.141130] ActionHandler:648 Error in action callback -- -204 (cookie 0x3f) [09:22:13.140261] ActionHandler:648 Error in action callback -- -204 (cookie 0x40) [09:22:13.642016] ActionHandler:648 Error in action callback -- -204 (cookie 0x41) [09:22:14.142513] ActionHandler:648 Error in action callback -- -204 (cookie 0x42) [09:22:14.143085] ActionHandler:648 Error in action callback -- -204 (cookie 0x43) [LWP 1712 exited] [09:22:15.140146] ActionHandler:648 Error in action callback -- -204 (cookie 0x44) [LWP 1713 exited] [09:22:15.144741] ActionHandler:648 Error in action callback -- -204 (cookie 0x45) [LWP 1714 exited] [LWP 1715 exited] [LWP 1689 exited] [LWP 1709 exited] [LWP 1710 exited] [LWP 1717 exited] [LWP 1711 exited] [LWP 1718 exited] [09:22:37.208805] UpdateThread:830 [0xf3f9e008]: renderer bye-bye: NP-S2000 I spotify.cpp:125: player deletion pending I TrackPlayer.cpp:94: Resetting state I MercurySession.cpp:128: Disconnecting mercury session I PlainConnection.cpp:197: Closing socket... E PlainConnection.cpp:146: Connection lost, will need to reconnect... [LWP 1705 exited] --Type for more, q to quit, c to continue without paging--

Thread 23 "spotupnp-linux-" received signal SIGSEGV, Segmentation fault. [Switching to LWP 1706] 0x001d3bd0 in ?? () (gdb)

philippe44 commented 1 year ago

I've fix a bug when deleting a player in 0.1.8 but I don't think that impacts your issue, still can you give it a try?

Jelobax commented 1 year ago

Hi,Still same in 0.1.8. This from interactive window. Player turned off at 19:17:56.139472] Player turned on again at 19:19:03.057684] So it continue with the deletion process after the player turned on again, seam a bit odd?

jibax@raspberrypi:~/Desktop/spotconnect $ ./spotupnp-linux-armv6-static -x config [19:16:10.102957] main:1479 Starting stopupnp version: v0.1.8 (Sep 24 2023 @ 13:18:09) [19:16:10.155035] Start:1207 Binding to iface eth0@192.168.1.195:0 [19:16:10.155161] Start:1221 Binding to 192.168.1.195:49153 [19:17:10.110706] AddMRDevice:1133 [0xf3e46008]: adding renderer (NP-S2000) with mac BBBB49DD72DE I BellHTTPServer.cpp:191: Server listening on port 0 [19:17:10.192944] MasterHandler:755 [0xf3e46008]: subscribe success [19:17:10.206331] ProcessEvent:484 [0xf3e46008]: UPnP Volume local change 50:-1 (master) I spotify.cpp:495: Server using actual port 42749 I MDNSService.cpp:181: using built-in mDNS for NP-S2000+ I spotify.cpp:516: Spotify client connected for NP-S2000+ D Session.cpp:63: Connecting with AP D PlainConnection.cpp:101: Connected to spotify server I Session.cpp:39: Received APHello response D Session.cpp:44: Received shannon keys D Session.cpp:82: Authorization successful I MercurySession.cpp:42: Received packet, command: 4 D TimeProvider.cpp:15: Time synced with spotify servers I MercurySession.cpp:42: Received packet, command: 2 I MercurySession.cpp:42: D Received packet, command: 118 MercurySession.cpp:251: Executing Mercury Request, type SUB I MercurySession.cpp:42: Received packet, command: 27 D MercurySession.cpp:153: Received country code SE I MercurySession.cpp:42: Received packet, command: 80 I MercurySession.cpp:42: Received packet, command: 31 I MercurySession.cpp:42: Received packet, command: 105 I MercurySession.cpp:42: Received packet, command: 181 I MercurySession.cpp:42: Received packet, command: 74 I MercurySession.cpp:42: Received packet, command: 179 D MercurySession.cpp:174: Received mercury packet D MercurySession.cpp:251: Executing Mercury Request, type SEND D SpircHandler.cpp:59: Sent kMessageTypeHello! I AccessKeyFetcher.cpp:99: Access token expired, fetching new one... 236 I MercurySession.cpp:42: Received packet, command: 181 I MercurySession.cpp:42: Received packet, command: 178 D SpircHandler.cpp:67: Received subscription response D SpircHandler.cpp:124: Notify frame D MercurySession.cpp:174: Received mercury packet I AccessKeyFetcher.cpp:114: Access token sucessfully fetched I MercurySession.cpp:42: Received packet, command: 181 D SpircHandler.cpp:67: Received subscription response D SpircHandler.cpp:170: Load frame 45! D MercurySession.cpp:251: Executing Mercury Request, type SEND I TrackPlayer.cpp:94: Resetting state I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet D MercurySession.cpp:251: Executing Mercury Request, type GET I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I TrackQueue.cpp:158: Track name: Armageddon Days (Are Here Again) I TrackQueue.cpp:159: Track duration: 340173 D TrackQueue.cpp:161: trackInfo.restriction.size() = 1 D TrackQueue.cpp:212: File format: 2 D TrackQueue.cpp:212: File format: 1 I MercurySession.cpp:42: Received packet, command: 13 I TrackQueue.cpp:252: Got audio key I TrackQueue.cpp:275: Received access key, fetching CDN URL... I TrackQueue.cpp:301: Received CDN URL, https://audio-fa.scdn.co/audio/d44767e3bee9297981d72d632b54893d2baf7de1?1695748639_aJVS-MASpiG36BG1EWBBrkJU1v48g2ciSyeTiefiC9k= I TrackPlayer.cpp:167: Got track ID=d44767e3bee9297981d72d632b54893d2baf7de1 I CDNAudioFile.cpp:43: Opening HTTP stream to https://audio-fa.scdn.co/audio/d44767e3bee9297981d72d632b54893d2baf7de1?1695748639_aJVS-MASpiG36BG1EWBBrkJU1v48g2ciSyeTiefiC9k= I MercurySession.cpp:42: Received packet, command: 181 D SpircHandler.cpp:67: Received subscription response D SpircHandler.cpp:124: Notify frame I CDNAudioFile.cpp:70: Header and footer bytes received D MercurySession.cpp:251: Executing Mercury Request, type SEND

I spotify.cpp:260: new track will start at 142460 D MercurySession.cpp:251: Executing Mercury Request, type SEND I spotify.cpp:273: play/pause D MercurySession.cpp:251: Executing Mercury Request, type GET I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I TrackQueue.cpp:158: Track name: Soul Mining I TrackQueue.cpp:159: Track duration: 287760 D TrackQueue.cpp:161: trackInfo.restriction.size() = 1 D TrackQueue.cpp:212: File format: 2 D TrackQueue.cpp:212: File format: 1 I TrackPlayer.cpp:200: Playing I spotify.cpp:149: trackUniqueId update => d44767e3bee9297981d72d632b54893d2baf7de1 I spotify.cpp:214: new track id db1fc35dae2d469e93f1034008f9782c => <Armageddon Days (Are Here Again)> I HTTPstreamer.cpp:135: Bound to port 55145 I spotify.cpp:224: loading with id bbbbde72dd49_0 [19:17:20.615723] shadowRequest:324 [0xf3e46008]: spotify LOAD request [19:17:20.615873] AVTSetURI:77 [0xf3e46008]: uPNP setURI http://192.168.1.195:55145/stream?id=bbbbde72dd49_0 (cookie (nil)) [19:17:20.616110] shadowRequest:338 [0xf3e46008]: spotify play request [19:17:20.616135] AVTPlay:137 [0xf3e46008]: uPNP play (cookie 0x1) I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I HTTPstreamer.cpp:443: got HTTP connection 15 I HTTPstreamer.cpp:210: HTTP received => GET /stream?id=bbbbde72dd49_0 HTTP/1.1 Host: 192.168.1.195:55145 User-Agent: Network_Player/3.0 (NP-S2000) Accept: / transferMode.dlna.org: Streaming Content-Length: 0

I HTTPstreamer.cpp:312: HTTP response => HTTP/1.1 200 OK transfermode.dlna.org: streaming Server: spot-connect Content-Type: audio/flac Connection: close

I MercurySession.cpp:42: Received packet, command: 178 I MercurySession.cpp:42: Received packet, command: 13 D MercurySession.cpp:174: Received mercury packet I TrackQueue.cpp:252: Got audio key I TrackQueue.cpp:275: Received access key, fetching CDN URL... I TrackQueue.cpp:301: Received CDN URL, https://audio-fa.scdn.co/audio/125bc99e95d7b0ae0157f0e9c08031a8ee04893c?1695748640_yCiZTrTxMyRalnRTguzhE5fqdmxRzzBK1kEIvV9B28U= D MercurySession.cpp:251: Executing Mercury Request, type GET I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I TrackQueue.cpp:158: Track name: Lonely Planet I TrackQueue.cpp:159: Track duration: 326706 D TrackQueue.cpp:161: trackInfo.restriction.size() = 1 D TrackQueue.cpp:212: File format: 2 D TrackQueue.cpp:212: File format: 1 I MercurySession.cpp:42: Received packet, command: 13 I TrackQueue.cpp:252: Got audio key I TrackQueue.cpp:275: Received access key, fetching CDN URL... I TrackQueue.cpp:301: Received CDN URL, https://audio-fa.scdn.co/audio/f32194228cc48baaa3deac6020111f5dc2863f59?1695748640_G80d7PAZJE4J8K0SvdX6_82BN06b57ivWVi34ekel70= [19:17:25.276740] ActionHandler:585 [0xf3e46008]: uPNP playing D MercurySession.cpp:251: Executing Mercury Request, type SEND I spotify.cpp:351: current trackInfo id db1fc35dae2d469e93f1034008f9782c => <Armageddon Days (Are Here Again)> I spotify.cpp:419: track bbbbde72dd49_0 started by URL (1) I spotify.cpp:383: adjusting real position 3000 from 0 (offset is -142460) D MercurySession.cpp:251: Executing Mercury Request, type SEND I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet [19:17:56.139472] ActionHandler:649 Error in action callback -- -204 (cookie 0x2e) [19:17:56.139774] ActionHandler:649 Error in action callback -- -204 (cookie 0x2f) [19:17:57.139760] ActionHandler:649 Error in action callback -- -204 (cookie 0x30) [19:17:57.640118] ActionHandler:649 Error in action callback -- -204 (cookie 0x31) [19:17:58.140497] ActionHandler:649 Error in action callback -- -204 (cookie 0x32) [19:17:59.140895] ActionHandler:649 Error in action callback -- -204 (cookie 0x33) [19:17:59.141046] ActionHandler:649 Error in action callback -- -204 (cookie 0x34) [19:18:00.141578] ActionHandler:649 Error in action callback -- -204 (cookie 0x35) [19:18:00.641932] ActionHandler:649 Error in action callback -- -204 (cookie 0x36) [19:18:01.142826] ActionHandler:649 Error in action callback -- -204 (cookie 0x37) [19:18:02.142878] ActionHandler:649 Error in action callback -- -204 (cookie 0x38) [19:18:02.143060] ActionHandler:649 Error in action callback -- -204 (cookie 0x39) [19:18:03.143090] ActionHandler:649 Error in action callback -- -204 (cookie 0x3a) [19:18:03.643302] ActionHandler:649 Error in action callback -- -204 (cookie 0x3b) [19:18:04.141245] ActionHandler:649 Error in action callback -- -204 (cookie 0x3c) [19:19:03.057684] MasterHandler:733 [0xf3e46008]: Auto-renewal failed, re-subscribing [19:19:03.969562] MasterHandler:757 [0xf3e46008]: subscribe fail, re-trying 1 [19:19:04.184425] MasterHandler:757 [0xf3e46008]: subscribe fail, re-trying 2 [19:19:04.484391] MasterHandler:757 [0xf3e46008]: subscribe fail, re-trying 3 [19:19:04.747439] UpdateThread:831 [0xf3e46008]: renderer bye-bye: NP-S2000+ I spotify.cpp:125: player <NP-S2000+> deletion pending I TrackPlayer.cpp:94: Resetting state I MercurySession.cpp:128: Disconnecting mercury session I PlainConnection.cpp:197: Closing socket... E PlainConnection.cpp:146: Connection lost, will need to reconnect... Segmentation fault jibax@raspberrypi:~/Desktop/spotconnect $

philippe44 commented 1 year ago

No, because it should finish deletion and the create it again. Just to be sure does it still fail if you either do not switch back on the player or if you wait for deletion to be finished. I'm still shooting in the dark unfortunately because of lack of precise crash point

Jelobax commented 1 year ago

I will do another try.

Jelobax commented 1 year ago

I did a test and turned of the player and let it be off. After 20 mins still seams to be running. There was an HTTP error but i dont think its connected.

[20:36:05.915904] ActionHandler:585 [0xf396b008]: uPNP playing D MercurySession.cpp:251: Executing Mercury Request, type SEND I spotify.cpp:351: current trackInfo id 335abfb61bc64c18b3a838bb64645686 => I spotify.cpp:419: track bbbbde72dd49_1 started by URL (1) I spotify.cpp:383: adjusting real position 0 from 0 (offset is 0) D MercurySession.cpp:251: Executing Mercury Request, type SEND I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I spotify.cpp:383: adjusting real position 1000 from 0 (offset is 0) D MercurySession.cpp:251: Executing Mercury Request, type SEND I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet [20:37:01.442877] ActionHandler:649 Error in action callback -- -204 (cookie 0x7c) [20:37:02.443051] ActionHandler:649 Error in action callback -- -204 (cookie 0x7d) [20:37:02.443275] ActionHandler:649 Error in action callback -- -204 (cookie 0x7e) [20:37:03.444100] ActionHandler:649 Error in action callback -- -204 (cookie 0x7f) [20:37:03.944787] ActionHandler:649 Error in action callback -- -204 (cookie 0x80) [20:37:04.445264] ActionHandler:649 Error in action callback -- -204 (cookie 0x81) [20:37:05.445586] ActionHandler:649 Error in action callback -- -204 (cookie 0x82) [20:37:05.445749] ActionHandler:649 Error in action callback -- -204 (cookie 0x83) [20:37:06.446328] ActionHandler:649 Error in action callback -- -204 (cookie 0x84) [20:37:06.946689] ActionHandler:649 Error in action callback -- -204 (cookie 0x85) [20:37:07.446737] ActionHandler:649 Error in action callback -- -204 (cookie 0x86) [20:37:08.447037] ActionHandler:649 Error in action callback -- -204 (cookie 0x88) [20:37:08.447130] ActionHandler:649 Error in action callback -- -204 (cookie 0x87) [20:37:09.447792] ActionHandler:649 Error in action callback -- -204 (cookie 0x8a) [20:37:09.447880] ActionHandler:649 Error in action callback -- -204 (cookie 0x89) [20:37:13.005382] MasterHandler:733 [0xf396b008]: Auto-renewal failed, re-subscribing [20:37:18.010670] MasterHandler:757 [0xf396b008]: subscribe fail, re-trying 1 [20:37:23.014107] MasterHandler:757 [0xf396b008]: subscribe fail, re-trying 2 [20:37:28.019529] MasterHandler:757 [0xf396b008]: subscribe fail, re-trying 3 [20:37:33.025300] MasterHandler:761 [0xf396b008]: subscribe fail, volume feedback will not work I MercurySession.cpp:42: Received packet, command: 4 D TimeProvider.cpp:15: Time synced with spotify servers I MercurySession.cpp:42: Received packet, command: 74 I MercurySession.cpp:42: Received packet, command: 4 D TimeProvider.cpp:15: Time synced with spotify servers I MercurySession.cpp:42: Received packet, command: 74 I MercurySession.cpp:42: Received packet, command: 4 D TimeProvider.cpp:15: Time synced with spotify servers I MercurySession.cpp:42: Received packet, command: 74 I MercurySession.cpp:42: Received packet, command: 4 D TimeProvider.cpp:15: Time synced with spotify servers I MercurySession.cpp:42: Received packet, command: 74 I MercurySession.cpp:42: Received packet, command: 4 D TimeProvider.cpp:15: Time synced with spotify servers I MercurySession.cpp:42: Received packet, command: 74 I MercurySession.cpp:42: Received packet, command: 4 D TimeProvider.cpp:15: Time synced with spotify servers I MercurySession.cpp:42: Received packet, command: 74 I MercurySession.cpp:42: Received packet, command: 4 D TimeProvider.cpp:15: Time synced with spotify servers I MercurySession.cpp:42: Received packet, command: 74 I MercurySession.cpp:42: Received packet, command: 4 D TimeProvider.cpp:15: Time synced with spotify servers I MercurySession.cpp:42: Received packet, command: 74 E HTTPstreamer.cpp:400: HTTP error for bbbbde72dd49_1 => send(15, 32768) = 26944 I HTTPstreamer.cpp:459: HTTP close 15 I MercurySession.cpp:42: Received packet, command: 4 D TimeProvider.cpp:15: Time synced with spotify servers I MercurySession.cpp:42: Received packet, command: 74

Jelobax commented 1 year ago

Then i turned on again and progem ended as before: [20:58:19.666322] UpdateThread:831 [0xf396b008]: renderer bye-bye: NP-S2000+ I spotify.cpp:125: player <NP-S2000+> deletion pending I TrackPlayer.cpp:94: Resetting state I MercurySession.cpp:128: Disconnecting mercury session I PlainConnection.cpp:197: Closing socket... E PlainConnection.cpp:146: Connection lost, will need to reconnect... Segmentation fault jibax@raspberrypi:~/Desktop/spotconnect $

philippe44 commented 1 year ago

That's very useful, thanks!

philippe44 commented 1 year ago

Can you try 0.2.2. I've fixed an issue related to this. I'm not 100% sure it's the explanation of the crash but it will prevent ending in that state where a player keeps hanging around forever.

Jelobax commented 1 year ago

I tried 0.2.2 and now it ends with same segmentation fault with without me powering on the player again.

[10:20:17.441766] ActionHandler:617 [0xf3f30008]: uPNP playing D MercurySession.cpp:251: Executing Mercury Request, type SEND I spotify.cpp:356: current trackInfo id 00df840d79814409b0b98a335bef1df3 => I spotify.cpp:424: track bbbbde72dd49_0 started by URL (1) I spotify.cpp:388: adjusting real position 3000 from 0 (offset is -3726) D MercurySession.cpp:251: Executing Mercury Request, type SEND I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I MercurySession.cpp:42: Received packet, command: 178 D MercurySession.cpp:174: Received mercury packet I MercurySession.cpp:42: Received packet, command: 181 I MercurySession.cpp:42: Received packet, command: 181 [10:21:05.152942] ActionHandler:682 [0xf3f30008]: Error -204 in action callback (count:-1 cookie:0x4e) [10:21:06.150799] ActionHandler:682 [0xf3f30008]: Error -204 in action callback (count:-1 cookie:0x4f) [10:21:06.150969] ActionHandler:682 [0xf3f30008]: Error -204 in action callback (count:-1 cookie:0x50) [10:21:07.154058] ActionHandler:682 [0xf3f30008]: Error -204 in action callback (count:-1 cookie:0x51) [10:21:07.654501] ActionHandler:682 [0xf3f30008]: Error -204 in action callback (count:-1 cookie:0x52) [10:21:08.154652] ActionHandler:682 [0xf3f30008]: Error -204 in action callback (count:-1 cookie:0x53) [10:21:09.155239] ActionHandler:682 [0xf3f30008]: Error -204 in action callback (count:-1 cookie:0x54) [10:21:09.155346] ActionHandler:682 [0xf3f30008]: Error -204 in action callback (count:-1 cookie:0x55) [10:21:10.153227] ActionHandler:682 [0xf3f30008]: Error -204 in action callback (count:-1 cookie:0x56) [10:21:22.005666] MasterHandler:766 [0xf3f30008]: Auto-renewal failed, re-subscribing [10:21:27.000151] UpdateThread:848 [0xf3f30008]: removing unresponsive player (NP-S2000+) I spotify.cpp:130: player <NP-S2000+> deletion pending I TrackPlayer.cpp:94: Resetting state I MercurySession.cpp:128: Disconnecting mercury session I PlainConnection.cpp:197: Closing socket... E PlainConnection.cpp:146: Connection lost, will need to reconnect... Segmentation fault jibax@raspberrypi:~/Desktop/spotconnect022 $

philippe44 commented 1 year ago

I know it does not look like progress for you 😄 but it is for me as it allows me to better corner the issue. Thanks!

philippe44 commented 1 year ago

All right - I was able to reproduce the issue, finally and it was ... an arm6 specific problem due to a compiler bug (yes...). Can you try the attached file just to be sure? bin.zip

Jelobax commented 1 year ago

Tried and it works, Im now able to turn of player, start it again, reconnect from Spotify client. This was just a quick test but it seam to work. Thanks!

philippe44 commented 1 year ago

YW - I'll close that now if you don't mind

Jelobax commented 1 year ago

Ok ,thanks again!Skickat från min iPhone2 okt. 2023 kl. 08:40 skrev philippe44 @.***>: YW - I'll close that now if you don't mind

—Reply to this email directly, view it on GitHub, or unsubscribe.You are receiving this because you authored the thread.Message ID: @.***>