`alda play` stops way too early when playing a file

[wiwikuan]

🐞 Bug report 🐞

Description

alda play stops way too early when I try to play my file.

Steps to Reproduce

I tried to play this file that I composed by alda play -f demo3-1.alda, and it doesn't play the whole file, instead, it stopped playing about 8 bars before the end.

But if I alda export -f demo3-1.alda -o demo3-1.mid, it can produce a correct MIDI file from start to end.

I then used Audacious to play the exported midi file by alda export -f demo3-1.alda -o demo3-1.mid && audacious -Hq demo3-1.mid, it plays perfectly from start to end. So the problem must be something about the alda play command, not the interpretation of the file itself.

Expected Behavior

I expect it plays the whole file without cutting off the end.

Actual Behavior

It cuts off about the final 10 seconds.

Environment

I tried on macOS 10.14 and Linux (64-bit), exactly the same behavior.

Alda version:

$ alda version
alda 2.0.3

$ alda-player info
alda-player 2.0.3
log path: /Users/wiwi/Library/Caches/alda/logs

Health check:

$ alda doctor
OK  Parse source code
OK  Generate score model
OK  Find an open port
OK  Send and receive OSC messages
OK  Locate alda-player executable on PATH
OK  Check alda-player version
OK  Spawn a player process
OK  Ping player process
OK  Play score
OK  Export score as MIDI
OK  Locate player logs
OK  Player logs show the ping was received
OK  Shut down player process
OK  Spawn a player on an unknown port
OK  Discover the player
OK  Ping the player
OK  Shut the player down
OK  Start a REPL server
nREPL server started on port 52575 on host localhost - nrepl://localhost:52575
OK  Find the REPL server
OK  Interact with the REPL server
OK  Shut down the REPL server

Logs:

ngn DEBUG 2021-08-09 02:12:07 Parser.parse:238 - received ping
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:346 - TRACK 6: startOffset is 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:346 - TRACK 7: startOffset is 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:346 - TRACK 5: startOffset is 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:346 - TRACK 4: startOffset is 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:346 - TRACK 2: startOffset is 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:346 - TRACK 3: startOffset is 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:346 - TRACK 11: startOffset is 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:346 - TRACK 9: startOffset is 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:346 - TRACK 8: startOffset is 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:346 - TRACK 10: startOffset is 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:349 - eraBefore: 0; eraAfter: 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:349 - eraBefore: 0; eraAfter: 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:346 - TRACK 1: startOffset is 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:349 - eraBefore: 0; eraAfter: 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:349 - eraBefore: 0; eraAfter: 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:349 - eraBefore: 0; eraAfter: 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:349 - eraBefore: 0; eraAfter: 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:349 - eraBefore: 0; eraAfter: 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:349 - eraBefore: 0; eraAfter: 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:349 - eraBefore: 0; eraAfter: 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:349 - eraBefore: 0; eraAfter: 0
ngn DEBUG 2021-08-09 02:12:07 Player.invoke:349 - eraBefore: 0; eraAfter: 0
hex INFO  2021-08-09 02:12:08 StateManager.cleanUpStaleStateFiles:72 - Cleaning up stale files in /Users/wiwi/Library/Caches/alda/state/players...
hex INFO  2021-08-09 02:12:08 StateManager.cleanUpStaleStateFiles:72 - Cleaning up stale files in /Users/wiwi/Library/Caches/alda/state/repl-servers...
hex INFO  2021-08-09 02:12:08 Main.run:77 - Starting receiver, listening on port 52699...
hex INFO  2021-08-09 02:12:08 MidiEngine.<init>:269 - Initializing MIDI sequencer...
hex INFO  2021-08-09 02:12:08 MidiEngine.<init>:274 - Initializing MIDI synthesizer...
hex INFO  2021-08-09 02:12:12 Main.run:90 - Starting player...
ngn INFO  2021-08-09 02:12:37 Main.invoke:95 - Stopping receiver...
ngn INFO  2021-08-09 02:12:37 Main.invoke:97 - Stopping player...

``

[wiwikuan]

Update: If I added a lot of extra empty bars at the end, like this, then it solves the problem. Maybe there's a bug in how alda play calculates when to stop.

[daveyarwood]

Wow, this demo file is fantastic! Well done!

I was able to reproduce the problem locally by playing the file in your first post. It also cut off abruptly for me. I think there must be a bug in the logic that determines how long to wait before shutting the player process down. I'll have a look soon and see if I can figure out why this is happening and fix it.

[daveyarwood]

@wiwikuan Oops. I should have copied your score file somewhere, and now it looks like it isn't available anymore at the link you provided above.

Do you still have a score that I can use to repro the issue?

[wiwikuan]

Hi, I just put them back: https://wiwicloud.com/demo3-1.alda and https://wiwicloud.com/demo3-1-extra-bars.alda

[daveyarwood]

I've fixed this in Alda 2.0.5, which is available now. Thanks again for reporting this bug!