Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Service silently vanishes and hangs, sigterm times out #398

Open
paulbastian opened this issue Sep 6, 2021 · 1 comment
Open

Service silently vanishes and hangs, sigterm times out #398

paulbastian opened this issue Sep 6, 2021 · 1 comment
Labels
bug Something isn't working

Comments

@paulbastian
Copy link

Describe the bug
Hello,
the librespot service silently vanishes after some days from the spotify connect list, a restart is needed. Restart shows the app hanging, sig-term times out and needs to be killed, therefore restarting takes quite a lot of time.

To Reproduce
unclear

Expected behavior
clear ;)

Screenshots/Stracktraces/Logs

-- Journal begins at Sat 2021-06-26 07:13:40 CEST, ends at Mon 2021-09-06 20:35:52 CEST. --
Sep 06 20:35:52 soundpi2 java[21991]: 2021-09-06 20:35:52,535 INFO  Zeroconf:500 - Announced Service{alias='Magnat_Boxen_Kueche', service='spotify-connect', port=6473, text={VERSION=1.0, CPath=/, Stack=SP}, add>
Sep 06 20:35:51 soundpi2 java[21991]: 2021-09-06 20:35:51,059 INFO  ZeroconfServer:472 - Zeroconf HTTP server started successfully on port 6473!
Sep 06 20:35:50 soundpi2 java[21991]: 2021-09-06 20:35:50,895 INFO  Utils:104 - Cryptography restrictions removal not needed.
Sep 06 20:35:48 soundpi2 systemd[1]: Started A spotify playing daemon.
Sep 06 20:35:48 soundpi2 systemd[1]: Stopped A spotify playing daemon.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Failed with result 'timeout'.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Main process exited, code=killed, status=9/KILL
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21986 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21984 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21983 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21960 (zeroconf-client) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21959 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21957 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21956 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21955 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21954 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21953 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21952 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21950 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21949 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21947 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21946 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21944 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21943 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21940 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21939 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21928 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21925 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21922 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21919 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21917 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21916 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21915 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21914 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21910 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21909 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21908 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21905 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21904 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21903 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21902 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21901 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21270 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21268 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21220 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21218 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21211 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21203 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21202 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21197 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21191 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21147 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21137 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21131 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21129 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21128 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21117 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21116 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21115 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21114 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21113 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21112 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21110 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21109 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21106 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21105 (zeroconf-client) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21103 (zeroconf-client) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21102 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 21099 (zeroconf-client) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 20920 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 20468 (zeroconf-client) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 20393 (zeroconf-client) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 20313 (zeroconf-client) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 20292 (zeroconf-client) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 20247 (zeroconf-client) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 20237 (zeroconf-client) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 20174 (player-queue-13) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 20146 (player-queue-23) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 20130 (OkHttp TaskRunn) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 15942 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14118 (pool-6-thread-1) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14093 (event-service-s) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14091 (put-state-worke) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14090 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14118 (pool-6-thread-1) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14093 (event-service-s) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14091 (put-state-worke) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14090 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14089 (dealer-schedule) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14088 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14087 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 14086 (session-schedul) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 12195 (pool-5-thread-1) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 3023 (Okio Watchdog) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 11534 (pool-4-thread-1) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 9917 (pool-3-thread-1) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 5004 (pool-2-thread-1) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4999 (Java Sound Even) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4971 (zeroconf-io-thr) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4964 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4963 (GC Thread#1) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4960 (Common-Cleaner) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4959 (VM Periodic Tas) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4958 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4957 (Sweeper thread) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4956 (C2 CompilerThre) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4955 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4954 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4953 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4952 (Finalizer) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4951 (Reference Handl) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4950 (n/a) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4949 (G1 Service) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4946 (G1 Main Marker) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4944 (java) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: Killing process 4943 (java) with signal SIGKILL.
Sep 06 20:35:48 soundpi2 systemd[1]: librespot-java.service: State 'stop-sigterm' timed out. Killing.
Sep 06 20:34:18 soundpi2 java[4943]: 2021-09-06 20:34:18,087 TRACE PlayerQueue:157 - Queue has been cleared.
Sep 06 20:34:18 soundpi2 java[4943]: 2021-09-06 20:34:18,086 TRACE PlayerQueue:157 - Queue has been cleared.
Sep 06 20:34:18 soundpi2 systemd[1]: Stopping A spotify playing daemon...
Sep 05 21:16:56 soundpi2 java[4943]: 2021-09-05 21:16:56,306 TRACE DealerClient:114 - Received request. {mid: hm://connect-state/v1/player/command, key: 3d8d7e60-206d-468e-9824-c1c7c3dcd485, pid: 929328141, sen>

Version/Commit
Release 1.6.1

Thanks for looking into this!
Best regards,
Paul
@paulbastian paulbastian added the bug Something isn't working label Sep 6, 2021
@paulbastian
Copy link
Author

Often this behaviour is followed by this error:

Sep 10 13:07:30 soundpi1 java[15479]: 2021-09-10 13:07:30,295 TRACE DealerClient:271 - Scheduled reconnection attempt in 10 seconds...
Sep 10 13:07:30 soundpi1 java[15479]:         at java.lang.Thread.run(Thread.java:831) [?:?]
Sep 10 13:07:30 soundpi1 java[15479]:         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) [?:?]
Sep 10 13:07:30 soundpi1 java[15479]:         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) [?:?]
Sep 10 13:07:30 soundpi1 java[15479]:         at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:519) [librespot-player.jar:1.6.1]
Sep 10 13:07:30 soundpi1 java[15479]:         at okhttp3.internal.ws.RealWebSocket$connect$1.onResponse(RealWebSocket.kt:195) [librespot-player.jar:1.6.1]
Sep 10 13:07:30 soundpi1 java[15479]:         at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.kt:293) [librespot-player.jar:1.6.1]
Sep 10 13:07:30 soundpi1 java[15479]:         at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.kt:102) ~[librespot-player.jar:1.6.1]
Sep 10 13:07:30 soundpi1 java[15479]:         at okhttp3.internal.ws.WebSocketReader.readHeader(WebSocketReader.kt:119) ~[librespot-player.jar:1.6.1]
Sep 10 13:07:30 soundpi1 java[15479]:         at okio.RealBufferedSource.readByte(RealBufferedSource.kt:209) ~[librespot-player.jar:1.6.1]
Sep 10 13:07:30 soundpi1 java[15479]:         at okio.RealBufferedSource.require(RealBufferedSource.kt:199) ~[librespot-player.jar:1.6.1]
Sep 10 13:07:30 soundpi1 java[15479]: java.io.EOFException: null
Sep 10 13:07:30 soundpi1 java[15479]: 2021-09-10 13:07:30,293 WARN  DealerClient:403 - An exception occurred. Reconnecting...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@paulbastian