FD- / RPiPlay

An open-source AirPlay mirroring server for the Raspberry Pi. Supports iOS 9 and up.
GNU General Public License v3.0
4.93k stars 353 forks source link

Problem with iOS - Photos App #41

Open tripplet opened 4 years ago

tripplet commented 4 years ago

Hi, I recently used rpiplay to show photos on my TV using the iOS Photos app. I'm using iOS 13.2.3. After some time it just stops working, the TV image just hangs, trying to reconnect also does not work. It seems to be triggered by showing video from the photos app or displaying live photos but not always. After rpiplay hangs stopping with Ctrl+C also does not work. Only "kill -9" seems to work then. After restarting RPiPlay and connection again everything is fine again.

Aside from this problem, thanks for the awesome work.

Full log here, last lines:

...
Got h264 data of 43056 bytes
Video delay is -20839
raop_rtp_mirror video ntp = 1574506718580821, now = 1574506718513865, latency = -66956
Got h264 data of 3353 bytes
Video delay is -66480
raop_rtp_mirror video ntp = 1574506718597487, now = 1574506718583738, latency = -13749
Got h264 data of 49743 bytes
Video delay is -11904
raop_rtp_mirror video ntp = 1574506718614154, now = 1574506718586835, latency = -27319
Got h264 data of 41264 bytes
Video delay is -25962
raop_rtp_mirror video ntp = 1574506718630821, now = 1574506718601092, latency = -29729
Got h264 data of 49183 bytes
Video delay is -28102
raop_rtp_mirror video ntp = 1574506718747487, now = 1574506718707646, latency = -39841
Got h264 data of 50959 bytes
Video delay is -36800
raop_rtp_mirror video ntp = 1574506718764154, now = 1574506718725078, latency = -39076
Got h264 data of 58212 bytes
Video delay is -37502
raop_rtp_mirror video ntp = 1574506718764154, now = 1574506718726773, latency = -37381
Got h264 data of 10565 bytes
Video delay is -36957
raop_rtp_mirror width_source = 1920.000000 height_source = 1080.000000 width = 1920.000000 height = 1080.000000
raop_rtp_mirror sps size = 18
raop_rtp_mirror pps size = 4
Got h264 data of 30 bytes
Injecting max_dec_frame_buffering
Video delay is 1574506718777595
raop_rtp_mirror tcp socket closed
^CStopping...
^C^C^C
FD- commented 4 years ago

What's really strange is that the video delay suddenly is enormously large (1574506718777595 micro seconds = almost 50 years). Does that always happen before the hang? Is it always a similar value or completely random? Watching the log in real time, does any of these last entries hang for a few seconds before the next shows up?

FD- commented 4 years ago

Also, what Pi model are you using?

tripplet commented 4 years ago

No I just got it to hang here:

raop_rtp_mirror video ntp = 1574508697592481, now = 1574508697577377, latency = -15104
Got h264 data of 22593 bytes
Video delay is -14182
raop_rtp_mirror tcp socket closed
^CStopping...
^C

I'm not sure about the large delay it seems to be multiple times in the full log from my first post. Right at the start is:

Handling request SET_PARAMETER with URL rtsp://172.20.96.10/13309015917043992711
raop_rtp_mirror width_source = 450.000000 height_source = 972.000000 width = 470.000000 height = 1016.000000
raop_rtp_mirror sps size = 17
raop_rtp_mirror pps size = 4
Got h264 data of 29 bytes
Injecting max_dec_frame_buffering
Video delay is 1574506513352009
raop_rtp_mirror video ntp = 1574506513358720, now = 1574506513352140, latency = -6580
Got h264 data of 3878 bytes

Also after some time the casting of audio does no longer work but that is not really that important for me for showing photos :smirk:. Maybe its related to the fast swapping between videos and photos?

tripplet commented 4 years ago

I'm using a raspberry pi 4 - 4GB with archlinux arm connected to full-hd tv: Linux quimby 4.19.84-1-ARCH #1 SMP PREEMPT Thu Nov 21 00:52:06 UTC 2019 armv7l GNU/Linux

FD- commented 4 years ago

I have forgotten parts of the implementation already, but I think the large delay right at the start comes from the reference not being synced yet and initialised with 0.

I sometimes observed the audio stopping at some point as well, but I always assumed it was due to the lack of processing power of the Pi Zero. Does it also happen for you when debug logging is disabled? BTW, are you using the most recent code? I recently fixed a rather big memory leak in the audio renderer.

tripplet commented 4 years ago

Yes I'm on the latest version (d914d5c8b77c1285f589702c30325a1471cdd213) Yes both problems are happening with debugging logging disabled too. The audio problem happens very fast the hang or crash is mostly happening after a few minutes but I cannot pinpoint an exact cause. I just observed after the audio stops working when you then start the iOS Music app and start a song it is skipping from song to song very fast without starting to play them, very interesting.

FD- commented 4 years ago

1) Hang: A common log entry for your hang logs seems to be "raop_rtp_mirror tcp socket closed". This could mean that a) The network connection is dropping b) RPiPlay is treating a case as connection close that in fact is not one c) The iOS device closes the AirPlay connection, but without the end handshake I already observed hangs when a connection is not properly closed. In those cases, it seemed the (audio and mirror) rtp connections (and/or ntp connection) don't properly propagate the connection loss to the other components involved in the connection.

2) Audio: Well, that's interesting! Does a reboot of the iOS device probably help? During testing, I spent hours investigating why video suddenly stopped working, only to find the iOS device was in a state where it just wouldn't send any video over AirPlay anymore, even to an AppleTV. Rebooting the device fixed that.

tripplet commented 4 years ago

I did some further debugging: I disabled wifi and used and lightning to ethernet adapter to rule out network problems.

Both problems are still present.

  1. c) seems to be the most likely root cause for me as I observed a very stable connection for long times while for example only playing music, the rapid switching between photos and videos or live pictures might lead to iOS dropping a video connection without closing it properly. Further testing also showed the after showing video stops working once it does not work again without restarting rpiplay but showing photos continues to work.

I tried some remote gdb debugging to show where the programs hangs:

Stacktraces after complete hand of RPiPlay. I let the program continue multiple times and stopped it again but the stack traces stay the same:

thread apply all bt

Thread 14 (Thread 0xaf0ff3e0 (LWP 19169)):
#0  0xb6cb210c in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0xb6cb2278 in __new_sem_wait_slow.constprop.1 () from /usr/lib/libpthread.so.0
#2  0xb6ce4d90 in vcos_semaphore_wait (sem=0xae7005dc) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_platform.h:254
#3  _vcos_thread_sem_wait () at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_platform.h:646
#4  vcos_generic_event_flags_get (flags=0x7b0468, bitmask=1, op=5, suspend=4294967295, retrieved_bits=0xaf0f6b60) at /home/dom/projects/staging/userland/interface/vcos/generic/vcos_generic_event_flags.c:223
#5  0x0046055c in vcos_event_flags_get (flags=0x7b0468, requested_events=1, op=5, suspend=4294967295, retrieved_events=0xaf0f6b60) at /opt/vc/include/interface/vcos/generic/vcos_generic_event_flags.h:118
#6  0x00463b28 in ilclient_get_input_buffer (comp=0x7b0450, portIndex=100, block=1) at /home/ttobias/projects/firmware/hardfp/opt/vc/src/hello_pi/libs/ilclient/ilclient.c:1352
#7  0x004089a8 in audio_renderer_render_buffer (renderer=0x771c88, ntp=0xb1b02ef8, data=0xae700b68 "\216\211\264R!\ft\b\r\226\241\035\225WkT\352d\233j\364ھ7\267\360\004\022\b:\243\365_\204\212c}Ӱ 5^\323\303\347\253;\366\001\317\034\331\065\371\224\065\204\352ͮ&\300\322\021\263\002\321\353\331.\373\030\270ǟ\035\367\232M\325/\310}@lD\272\374\275d̙\225W\255\212\215\062\006\065F\364o\375p\345\231\347>\270T\241\270\267Oy\353\241\366Y!\264&\371\236\203\250 \230/h2\236z\016U|\231\254\"\353\301)G\272ja\227\277]gzJW[x\211\a\362\033\rEa~\353Ї\310>@>@\275", data_len=168, pts=1575234598908752) at /home/ttobias/projects/RPiPlay/renderers/audio_renderer_rpi.c:314
#8  0x0040573c in audio_process (cls=0x0, ntp=0xb1b02ef8, data=0xaf0f6cb0) at /home/ttobias/projects/RPiPlay/rpiplay.cpp:162
#9  0x00411784 in raop_rtp_thread_udp (arg=0xb1b03210) at /home/ttobias/projects/RPiPlay/lib/raop_rtp.c:499
#10 0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#11 0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 12 (Thread 0xb12fe3e0 (LWP 19163)):
#0  0xb6a2608c in select () from /usr/lib/libc.so.6
#1  0x00412738 in raop_rtp_mirror_thread (arg=0xb1b03790) at /home/ttobias/projects/RPiPlay/lib/raop_rtp_mirror.c:192
#2  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#3  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 10 (Thread 0xb24f83e0 (LWP 19159)):
#0  0xb6cb329c in read () from /usr/lib/libpthread.so.0
#1  0xb6d9a2e0 in ?? () from /usr/lib/libdns_sd.so.1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 9 (Thread 0xb2cf93e0 (LWP 19158)):
#0  0xb6cb329c in read () from /usr/lib/libpthread.so.0
#1  0xb6d9a2e0 in ?? () from /usr/lib/libdns_sd.so.1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 8 (Thread 0xb34fa3e0 (LWP 19157)):
#0  0xb6ca9b84 in __pthread_timedjoin_ex () from /usr/lib/libpthread.so.0
#1  0x00412098 in raop_rtp_stop (raop_rtp=0xb1b03210) at /home/ttobias/projects/RPiPlay/lib/raop_rtp.c:676
#2  0x0040df74 in conn_request (ptr=0xb1b005b8, request=0xb1b01158, response=0xb34f9914) at /home/ttobias/projects/RPiPlay/lib/raop.c:199
#3  0x004169c0 in httpd_thread (arg=0x5d6318) at /home/ttobias/projects/RPiPlay/lib/httpd.c:303
#4  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#5  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 7 (Thread 0xb3cfb3e0 (LWP 19156)):
#0  0xb6cb210c in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0xb6cb2278 in __new_sem_wait_slow.constprop.1 () from /usr/lib/libpthread.so.0
#2  0xb6ccfb60 in vchiu_queue_pop () from /opt/vc/lib/libvchiq_arm.so
#3  0xb6d26d70 in ilcs_task () from /opt/vc/lib/libopenmaxil.so
#4  0xb6ce3cb0 in vcos_thread_entry (arg=0x5d82b8) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:144
#5  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#6  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 6 (Thread 0xb44fc3e0 (LWP 19155)):
#0  0xb6caf184 in pthread_cond_wait@@GLIBC_2.4 () from /usr/lib/libpthread.so.0
#1  0xb6ce3d94 in _timer_thread (arg=0x5d8248) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:722
#2  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#3  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 5 (Thread 0xb4cfd3e0 (LWP 19154)):
#0  0xb6cb210c in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0xb6cb2278 in __new_sem_wait_slow.constprop.1 () from /usr/lib/libpthread.so.0
#2  0xb6d08720 in cecservice_notify_func () from /opt/vc/lib/libbcm_host.so
#3  0xb6ce3cb0 in vcos_thread_entry (arg=0xb6d22398 <cecservice_notify_task>) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:144
#4  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#5  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 4 (Thread 0xb54fe3e0 (LWP 19153)):
#0  0xb6cb210c in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0xb6cb2278 in __new_sem_wait_slow.constprop.1 () from /usr/lib/libpthread.so.0
#2  0xb6d073b0 in tvservice_notify_func () from /opt/vc/lib/libbcm_host.so
#3  0xb6ce3cb0 in vcos_thread_entry (arg=0xb6d21608 <tvservice_notify_task>) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:144
#4  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#5  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 3 (Thread 0xb5cff3e0 (LWP 19152)):
#0  0xb6cb210c in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0xb6cb2278 in __new_sem_wait_slow.constprop.1 () from /usr/lib/libpthread.so.0
#2  0xb6d0b4d4 in dispmanx_notify_func () from /opt/vc/lib/libbcm_host.so
#3  0xb6ce3cb0 in vcos_thread_entry (arg=0xb6d231c0 <dispmanx_notify_task>) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:144
#4  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#5  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 2 (Thread 0xb66aa3e0 (LWP 19151)):
#0  0xb6a24f4c in ioctl () from /usr/lib/libc.so.6
#1  0xb6ccd010 in completion_thread () from /opt/vc/lib/libvchiq_arm.so
#2  0xb6ce3cb0 in vcos_thread_entry (arg=0xb6ce0318 <vchiq_instance+16>) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:144
#3  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#4  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 1 (Thread 0xb6ff3220 (LWP 19148)):
#0  0xb69f56ac in nanosleep () from /usr/lib/libc.so.6
#1  0xb69f5558 in sleep () from /usr/lib/libc.so.6
#2  0x00405530 in main (argc=1, argv=0xbefff2b4) at /home/ttobias/projects/RPiPlay/rpiplay.cpp:152

Then setting running to false in thread 1 via gdb (which normally is done via ctrl+c) the programs hangs indefinitely here:

thread apply all bt

Thread 14 (Thread 0xaf0ff3e0 (LWP 19169)):
#0  0xb6cb210c in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0xb6cb2278 in __new_sem_wait_slow.constprop.1 () from /usr/lib/libpthread.so.0
#2  0xb6ce4d90 in vcos_semaphore_wait (sem=0xae7005dc) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_platform.h:254
#3  _vcos_thread_sem_wait () at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_platform.h:646
#4  vcos_generic_event_flags_get (flags=0x7b0468, bitmask=1, op=5, suspend=4294967295, retrieved_bits=0xaf0f6b60) at /home/dom/projects/staging/userland/interface/vcos/generic/vcos_generic_event_flags.c:223
#5  0x0046055c in vcos_event_flags_get (flags=0x7b0468, requested_events=1, op=5, suspend=4294967295, retrieved_events=0xaf0f6b60) at /opt/vc/include/interface/vcos/generic/vcos_generic_event_flags.h:118
#6  0x00463b28 in ilclient_get_input_buffer (comp=0x7b0450, portIndex=100, block=1) at /home/ttobias/projects/firmware/hardfp/opt/vc/src/hello_pi/libs/ilclient/ilclient.c:1352
#7  0x004089a8 in audio_renderer_render_buffer (renderer=0x771c88, ntp=0xb1b02ef8, data=0xae700b68 "\216\211\264R!\ft\b\r\226\241\035\225WkT\352d\233j\364ھ7\267\360\004\022\b:\243\365_\204\212c}Ӱ 5^\323\303\347\253;\366\001\317\034\331\065\371\224\065\204\352ͮ&\300\322\021\263\002\321\353\331.\373\030\270ǟ\035\367\232M\325/\310}@lD\272\374\275d̙\225W\255\212\215\062\006\065F\364o\375p\345\231\347>\270T\241\270\267Oy\353\241\366Y!\264&\371\236\203\250 \230/h2\236z\016U|\231\254\"\353\301)G\272ja\227\277]gzJW[x\211\a\362\033\rEa~\353Ї\310>@>@\275", data_len=168, pts=1575234598908752) at /home/ttobias/projects/RPiPlay/renderers/audio_renderer_rpi.c:314
#8  0x0040573c in audio_process (cls=0x0, ntp=0xb1b02ef8, data=0xaf0f6cb0) at /home/ttobias/projects/RPiPlay/rpiplay.cpp:162
#9  0x00411784 in raop_rtp_thread_udp (arg=0xb1b03210) at /home/ttobias/projects/RPiPlay/lib/raop_rtp.c:499
#10 0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#11 0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 12 (Thread 0xb12fe3e0 (LWP 19163)):
#0  0xb6a2608c in select () from /usr/lib/libc.so.6
#1  0x00412738 in raop_rtp_mirror_thread (arg=0xb1b03790) at /home/ttobias/projects/RPiPlay/lib/raop_rtp_mirror.c:192
#2  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#3  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 10 (Thread 0xb24f83e0 (LWP 19159)):
#0  0xb6cb329c in read () from /usr/lib/libpthread.so.0
#1  0xb6d9a2e0 in ?? () from /usr/lib/libdns_sd.so.1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 9 (Thread 0xb2cf93e0 (LWP 19158)):
#0  0xb6cb329c in read () from /usr/lib/libpthread.so.0
#1  0xb6d9a2e0 in ?? () from /usr/lib/libdns_sd.so.1
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 8 (Thread 0xb34fa3e0 (LWP 19157)):
#0  0xb6ca9b84 in __pthread_timedjoin_ex () from /usr/lib/libpthread.so.0
#1  0x00412098 in raop_rtp_stop (raop_rtp=0xb1b03210) at /home/ttobias/projects/RPiPlay/lib/raop_rtp.c:676
#2  0x0040df74 in conn_request (ptr=0xb1b005b8, request=0xb1b01158, response=0xb34f9914) at /home/ttobias/projects/RPiPlay/lib/raop.c:199
#3  0x004169c0 in httpd_thread (arg=0x5d6318) at /home/ttobias/projects/RPiPlay/lib/httpd.c:303
#4  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#5  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 7 (Thread 0xb3cfb3e0 (LWP 19156)):
#0  0xb6cb210c in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0xb6cb2278 in __new_sem_wait_slow.constprop.1 () from /usr/lib/libpthread.so.0
#2  0xb6ccfb60 in vchiu_queue_pop () from /opt/vc/lib/libvchiq_arm.so
#3  0xb6d26d70 in ilcs_task () from /opt/vc/lib/libopenmaxil.so
#4  0xb6ce3cb0 in vcos_thread_entry (arg=0x5d82b8) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:144
#5  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#6  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 6 (Thread 0xb44fc3e0 (LWP 19155)):
#0  0xb6caf184 in pthread_cond_wait@@GLIBC_2.4 () from /usr/lib/libpthread.so.0
#1  0xb6ce3d94 in _timer_thread (arg=0x5d8248) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:722
#2  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#3  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 5 (Thread 0xb4cfd3e0 (LWP 19154)):
#0  0xb6cb210c in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0xb6cb2278 in __new_sem_wait_slow.constprop.1 () from /usr/lib/libpthread.so.0
#2  0xb6d08720 in cecservice_notify_func () from /opt/vc/lib/libbcm_host.so
#3  0xb6ce3cb0 in vcos_thread_entry (arg=0xb6d22398 <cecservice_notify_task>) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:144
#4  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#5  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 4 (Thread 0xb54fe3e0 (LWP 19153)):
#0  0xb6cb210c in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0xb6cb2278 in __new_sem_wait_slow.constprop.1 () from /usr/lib/libpthread.so.0
#2  0xb6d073b0 in tvservice_notify_func () from /opt/vc/lib/libbcm_host.so
#3  0xb6ce3cb0 in vcos_thread_entry (arg=0xb6d21608 <tvservice_notify_task>) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:144
#4  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#5  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 3 (Thread 0xb5cff3e0 (LWP 19152)):
#0  0xb6cb210c in do_futex_wait.constprop () from /usr/lib/libpthread.so.0
#1  0xb6cb2278 in __new_sem_wait_slow.constprop.1 () from /usr/lib/libpthread.so.0
#2  0xb6d0b4d4 in dispmanx_notify_func () from /opt/vc/lib/libbcm_host.so
#3  0xb6ce3cb0 in vcos_thread_entry (arg=0xb6d231c0 <dispmanx_notify_task>) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:144
#4  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#5  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 2 (Thread 0xb66aa3e0 (LWP 19151)):
#0  0xb6a24f4c in ioctl () from /usr/lib/libc.so.6
#1  0xb6ccd010 in completion_thread () from /opt/vc/lib/libvchiq_arm.so
#2  0xb6ce3cb0 in vcos_thread_entry (arg=0xb6ce0318 <vchiq_instance+16>) at /home/dom/projects/staging/userland/interface/vcos/pthreads/vcos_pthreads.c:144
#3  0xb6ca8568 in start_thread () from /usr/lib/libpthread.so.0
#4  0xb6a2cac8 in ?? () from /usr/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Thread 1 (Thread 0xb6ff3220 (LWP 19148)):
#0  0xb6ca9b84 in __pthread_timedjoin_ex () from /usr/lib/libpthread.so.0
#1  0x00417178 in httpd_stop (httpd=0x5d6318) at /home/ttobias/projects/RPiPlay/lib/httpd.c:452
#2  0x0040e89c in raop_stop (raop=0x5d6230) at /home/ttobias/projects/RPiPlay/lib/raop.c:385
#3  0x0040e494 in raop_destroy (raop=0x5d6230) at /home/ttobias/projects/RPiPlay/lib/raop.c:309
#4  0x00405e30 in stop_server () at /home/ttobias/projects/RPiPlay/rpiplay.cpp:268
#5  0x0040554c in main (argc=1, argv=0xbefff2b4) at /home/ttobias/projects/RPiPlay/rpiplay.cpp:156

Hope that helps

pallas commented 3 years ago

Could this be related to the stale sequence number issues that were fixed upstream?

tripplet commented 3 years ago

Might be possible I'll try testing latest version this weekend

tripplet commented 3 years ago

Sadly my raspberry pi 4 seems not work with my new 4k TV, I get some weird flickering unrelated to rpiplay. Might be the HDMI cable, or something else. I've ordered I new cable and will report then.

tripplet commented 3 years ago

New cable made no difference, I had to limit the resolution to 1080p in the /boot/config.txt. The video problem seems to be fixed and rpiplay seems to be a lot more stable now :smiley: Only the audio seems to stop working after some time when often switching between live photos and normal photos. (Same problem as discussed above). Running it with debug shows that after some time the audio delay seems to be suddenly very big. rpiplay_log.txt (First occurence is at line 44205. Before that all reported audio delays are negative and around -350000, e.g.:

Audio delay is -354168

After line 44205 it is always positiv and very big.

Audio delay is 74373649245

Not sure if this helps, seems to be similar to the previous problem with the enormous video_delay, which is gone now. Now we are left with audio :raised_eyebrow:.