Hangs when changing song with Remote

[davidhq]

I was listening to music, then I tried to change the song from iPhone (Remote app), when the playing stopped (not sure if it was the end of the song or even playlist) and now I cannot connect to my library anymore. Tried rebooting the iPhone etc. Seems the problem is on the server side.

There is nothing suspicious on /var/log/forked-daapd.log, last lines are from yesterday:

[2017-03-01 17:09:16] [  LOG]  artwork: Source 'embedded' returned an error for 'Cosmic Company (Talamasca Remix)'
[2017-03-01 18:05:25] [  LOG]     mdns: Avahi state change: Client collision
[2017-03-01 18:05:25] [  LOG]     mdns: Avahi state change: Client registering
[2017-03-01 18:05:26] [  LOG]     mdns: Avahi state change: Client running

I didn't restart forked-daapd yet because I want to help debug. I had log level set to log unfortunately, adjusted to debug now but not sure if forked-daapd daemon can reread this configuration without full restart.

I assume it will work again after I restart the process but is there anything else I can do to troubleshoot this or is the only chance restarting it and waiting for the next time it happens. Is debug log level going to be enough or is there something more that can be done to prepare?

[ejurgensen]

Yes, changing the log level requires a restart. Have you checked that the process is actually running? Maybe it crashed.

If is still running, but not responding, then I can't think of a way that you can get info about its state. So I suggest you restart with debug and see if it happens again. If you are running it on a device with limited disk space then don't keep it on debug for too long.

[davidhq]

Hi!

Process is running, yes, but I now see it is hung...

$ mpc volume
error: Timeout

Also I attached with gdb and wanted to check stacktrace, not exactly expert in gdb though...

(gdb) info registers
r0             0xfffffffc   4294967292
r1             0x9f26b8 10430136
r2             0x20 32
r3             0xffffffff   4294967295
r4             0x0  0
r5             0x9f2540 10429760
r6             0x9e1720 10360608
r7             0xfc 252
r8             0x9e1720 10360608
r9             0x75fd3a20   1979529760
r10            0xffffffff   4294967295
r11            0x75fd3830   1979529264
r12            0x0  0
sp             0x7ec72568   0x7ec72568
lr             0x75bf6da4   1975479716
pc             0x75be9c14   0x75be9c14 <epoll_wait+68>
cpsr           0x80000010   -2147483632
(gdb) set logging file /home/pi/Desktop/gdb-program.txt
(gdb) set logging on
Copying output to /home/pi/Desktop/gdb-program.txt.
(gdb) bt
#0  0x75be9c14 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81
#1  0x75fab078 in ?? () from /usr/lib/arm-linux-gnueabihf/libevent-2.0.so.5
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) Quit
A debugging session is active.

    Inferior 1 [process 10773] will be detached.

Quit anyway? (y or n) Y
Detaching from program: /usr/sbin/forked-daapd, process 10773

Not sure if this is gdb misbehaving ((corrupt stack?)), it's most likely my usage of it... or really is telling something about the nature of problem in forked-daapd?

Any new ideas now? If not, I'll slowly consider restarting the process.

[davidhq]

UPDATE: actually mpc volume is not working because of attached gdb session... when I dettach, I get the volume... so internal mpd server is working but still cannot connect to shared "iTunes" library from Remote app.

How else can I test if forked-daapd is really stuck and which part?

[davidhq]

Here is another update: now I tried with another paired iPhone Remote (which wasn't at home earlier) and there it worked...

Then I restarted forked-daapd finally and now my iPhone finds the library instantly.

So I guess the problem was somewhere in the server code but related to this particular pairing since the other worked fine. I will monitor these issues more esp. now with DEBUG enabled.

As I mentioned earlier I think the server got confused when I was browsing through the library from Remote while it was playing... Maybe I was even stoping / resuming songs in that moment, not sure.

[ejurgensen]

Rather than the particular Remote, it is more likely that there is a bug when processing the track switch command under some particular circumstances. Forked-daapd was probably waiting for an event that didn't happen, or happened but was not detected due to e.g. a threading problem.

Determining the missing event can be pretty difficult. Having the log level on DEBUG may help finding the circumstances. So if you see the error again please share the log.

[davidhq]

Yes, that’s what I ment, the bug was caused because of a glitch such as you described but then the whole session for this Remote got unhinged.

I’ll reproduce hopefully with more debug info.

On Thu, Mar 2, 2017 at 8:57 PM, ejurgensen notifications@github.com wrote:

Rather than the particular Remote, it is more likely that there is a bug when processing the track switch command under some particular circumstances. Forked-daapd was probably waiting for an event that didn't happen, or happened but was not detected due to e.g. a threading problem.

Determining the missing event can be pretty difficult. Having the log level on DEBUG may help finding the circumstances. So if you see the error again please share the log.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/ejurgensen/forked-daapd/issues/357#issuecomment-283762219, or mute the thread https://github.com/notifications/unsubscribe-auth/AAAPO7DNO30cC_hc-T3OyzaWKmlBc2Saks5rhx83gaJpZM4MQu-d .

[ejurgensen]

Closing, no feedback

[davidhq]

Hi, this happened again yesterday, would it be possible to reach you via email? I can send you the log there, please send me an email david.krmpotic@gmail.com