4.1.3: RDAirplay Freezes with Non-Existent File

[bpm1992]

When a non-existent file is encountered (where it is present in the library but missing on the filesystem), RDAirplay will freeze and halt all playback.

I get the following in the caed log:
Mar 18 15:18:24 rdbeta5 caed: jackLoadPlayback(/var/snd/002508_034.wav) openWave() failed to open file
Mar 18 15:18:24 rdbeta5 caed: unable to allocate stream for card 0
Mar 18 15:18:24 rdbeta5 caed: attempted to operate non-existent session, serial: 21
Mar 18 15:18:24 rdbeta5 caed: attempted to unload non-existent session, serial: 21
Mar 18 15:18:24 rdbeta5 caed: attempted to operate non-existent session, serial: 21
Mar 18 15:18:24 rdbeta5 caed: attempted to operate non-existent session, serial: 21
Mar 18 15:18:24 rdbeta5 caed: attempted to play non-existent session, serial:21
Mar 18 15:18:25 rdbeta5 caed: StopPlayback - Card: 0 Stream: 0 Serial: 20
Mar 18 15:18:25 rdbeta5 rdairplay: log engine: finished event: Line: 871 Cart: 278001 Cut: 9 Serial: 20 Card: 0 Port: 7
Mar 18 15:18:25 rdbeta5 caed: UnloadPlayback - Card: 0 Stream: 0 Serial: 20
Mar 18 15:18:25 rdbeta5 caed: attempted to unload non-existent session, serial:20

This did not occur in prior versions. Looks like it could be some sort of signaling problem.

[paulk-2]

I had the same thing happen, missing /var/snd/x.wav file. I did not get the "failed to open file":

Mar 20 14:40:37 z2 rdairplay: log engine: started audio cart: Line: 417 Cart: 82930 Cut: 1 Pos: 0 Serial: 6088 Card: 0 Port: 0
Mar 20 14:40:37 z2 caed: unable to allocate stream for card 0
Mar 20 14:40:37 z2 caed: attempted to operate non-existent session, serial: 6088
Mar 20 14:40:37 z2 caed: attempted to unload non-existent session, serial: 6088
Mar 20 14:40:37 z2 caed: attempted to operate non-existent session, serial: 6088
Mar 20 14:40:37 z2 caed: attempted to operate non-existent session, serial: 6088
Mar 20 14:40:37 z2 caed: attempted to play non-existent session, serial:6088
Mar 20 15:12:35 z2 caed: attempted to stop non-existent session, serial: 6088
Mar 20 15:12:37 z2 caed: message repeated 2 times: [ attempted to stop non-existent session, serial: 6088]

In 3.x,, rdairplay just continued on with the next cart.

[paulk-2]

Rdairplay crashed and exited. it was a failed chainto instead of a missing wav file. The common thread with above is the "non-existent session" and cart 82930 (wav file was restored).

Was able to (re)launch rdairplay and manually load WZIG_2024_03_24 (which existed) and resume playback.

audio stopped at 19:50. cart 82930 was on pause due to event above (Mar 20). It was left on the display while other carts played. the wav file for it was restored. Ran through 3 other chainto's before stopping at this one.

Mar 24 00:04:15 z2 rdairplay: log engine: finished event: Line: 656 Cart: 784568 Cut: 1 Serial: 7800 C>
Mar 24 00:04:15 z2 caed: StopPlayback - Card: 0 Stream: 0 Serial: 7800
Mar 24 00:04:15 z2 caed: UnloadPlayback - Card: 0 Stream: 0 Serial: 7800
Mar 24 00:04:15 z2 caed: attempted to unload non-existent session, serial:7800
Mar 24 00:05:19 z2 rdservice: ran local maintenance routines
Mar 24 00:19:50 z2 rdairplay: log engine: chained to log: Line: 658 Log: WZIG_2024_03_24
Mar 24 00:19:50 z2 ripcd: received rml: "LL 1 WZIG_2024_03_24 -2!" from 192.168.1.136
Mar 24 00:19:50 z2 caed: StopPlayback - Card: 0 Stream: 1 Serial: 7801
Mar 24 00:19:50 z2 caed: UnloadPlayback - Card: 0 Stream: 1 Serial: 7801
Mar 24 00:19:50 z2 caed: attempted to unload non-existent session, serial:6088
Mar 24 00:19:50 z2 rdairplay: log engine: finished event: Line: 0 Cart: 82930 Cut: 1 Serial: 6088 Card>
Mar 24 00:19:50 z2 caed: attempted to unload non-existent session, serial:6088
Mar 24 00:53:41 z2 rdservice: ran local maintenance routines
Mar 24 00:53:41 z2 rdservice: ran system-wide maintenance routines
Mar 24 00:53:41 z2 rdservice: process "/usr/bin/rdmaint" exited with exit code 1

crash report attached (less coredump)
_usr_bin_rdairplay.1000.crash.txt

[paulk-2]

This has become urgent - rdairplay is crashing after a chainto. The cart 121 at the beginning of the next log is valid.

Here is the latest example:

Apr 7 00:20:12 z3 caed: UnloadPlayback - Card: 0 Stream: 1 Serial: 1147
Apr 7 00:20:12 z3 caed: attempted to unload non-existent session, serial:488
Apr 7 00:20:12 z3 rdairplay: log engine: finished event: Line: 0 Cart: 121 C>
Apr 7 00:20:12 z3 caed: attempted to unload non-existent session, serial:488
Apr 7 00:44:26 z3 rdservice: ran local maintenance routines
Apr 7 00:44:26 z3 rdservice: ran system-wide maintenance routines
Apr 7 00:44:26 z3 rdservice: process "/usr/bin/rdmaint --system" exited with e>
Apr 7 00:44:26 z3 rdservice: process "/usr/bin/rdmaint" exited with exit code 1
Apr 7 01:31:39 z3 rdservice: ran local maintenance routines
Apr 7 01:31:39 z3 rdservice: ran system-wide maintenance routines
Apr 7 01:31:39 z3 rdservice: process "/usr/bin/rdmaint" exited with exit code 1
Apr 7 02:03:55 z3 rdservice: ran local maintenance routines
Apr 7 02:54:01 z3 rdservice: ran local maintenance routines

[ElvishArtisan]

This has become urgent - rdairplay is crashing after a chainto. The cart 121 at the beginning of the next log is valid.

Unable to reproduce this here. Any chance of getting a backtrace?

[ElvishArtisan]

When a non-existent file is encountered (where it is present in the library but missing on the filesystem), RDAirplay will freeze and halt all playback.

Confirmed here.

[dklann]

I wonder if this is the same problem as I have experienced and wrote about in #949. I'll be watching this closely and will report back when you post a fix @ElvishArtisan! Maybe squash 2 issues with one fix?!