[Thelost77]

What was wrong

A review of an ABS-compatible server found six faults in the progress sync of pine. Each fault is confirmed in the code of pine, and a test reproduces it. "ABS" below is Audiobookshelf 2.37.1. The statements about ABS come from its source: server/models/MediaProgress.js, server/managers/PlaybackSessionManager.js, and server/controllers/SessionController.js.

1. A stop removed the finished mark of the last finished book. pine restores the last session at each start, paused (RestorePlaySessionMsg in internal/app/model.go). For a finished book, ABS starts that session at the position 0. At a quit, and at the play of a different item, stopPlayback and Cleanup in internal/app/playback.go sent PATCH /api/me/progress/{id} with {"currentTime":0,"progress":0,"isFinished":false}, and a close with {"currentTime":0,"timeListened":0}. ABS stored the book as not finished, with no finish time, at the position 0. pine sends the same body for the action "mark as not finished", so a server cannot tell the two apart. The close has the same effect if the stored position is not 0, because ABS reads a position in a close as a progress update.
2. At the end of a book, the stop sent "isFinished": false with the position at the end and the progress 1 (stopPlayback). The close ran at the same time. If ABS handled the close first, it marked the book as finished. Then the progress update removed the mark, and ABS stored the position 0.
3. Each sync sent the total listening time of the session (handleSyncTick). ABS adds the timeListened of each sync to the session. For one hour of play, ABS stored about 61 hours.
4. A paused session sent a sync each 30 seconds (handleSyncTick: isPlaying is true while a session exists). ABS stored the old position again. That removed a newer position that a second device wrote.
5. After the status 404 for a sync, pine wrote a log line and continued (handleSyncTick). ABS has no open session after a restart, or after 36 hours with no change of the session. Each later sync failed. ABS stored no listening time for the rest of the playback, and it stored the position only at the stop.
6. The close of the old session and the play request of the next item ran at the same time (tea.Batch in handlePlayCmd, handlePlayEpisodeCmd, startQueuedEntry, and handlePlaybackCompleted). ABS closes the open session of a device at a play request, and it then answers 404 to the close of pine. ABS did not store the listening time that the close carried.

The work on this pull request found three more faults: the faults 7 to 9. They are in "Faults found during the work on this pull request".

What changes

• Fault 3. timeListened is now the listening time that the server does not have. A sync takes it. If the sync fails, handleSessionSynced gives it back, so the next sync sends it also. A close sends only the time since the last sync.
• Fault 4. lastSyncPos is now the position that the server accepted. A session starts with the position of the server (PlaySessionData.SyncedTime), not with the seek target. No sync goes out while the position and the listening time have a change of less than 1 second (syncMinChange).
• Fault 5. After a 404, the sync command opens a new session for the book, or for the episode. It sends the same position and the same listening time to that session, and the model then uses the new session.
• Fault 2. The progress update of a stop uses the new abs.Client.UpdatePosition, which sends no isFinished key. Only "mark as finished" and "mark as not finished" send the key.
• Fault 1. If the server has the position and the listening time, a stop sends no progress update, and its close has no body (new abs.Client.CloseSessionNoSync).
• Fault 6. stopPlaybackCmds returns the close apart from the other cleanup commands. closeThen runs the play request, or the series lookup before it, after the close completes or fails.

Decisions:

• Fault 2: no isFinished key, not "isFinished": true. pine does not know the "mark as finished" setting of the library, and a stop near the end uses the same code as a stop at the end. With no key, ABS applies its own rule for the position, as it does for the close. The two requests of a stop then give the same result in each order.
• Fault 1: the review said that the close is enough. A close with a position is a progress update in ABS, so the close of an untouched session has no body. SessionController.close of ABS reads an empty body as a close with no position.
• Fault 5: the sync command opens the new session in the same step. A sync goes out only if it has something to send, so no session is opened for a paused player.
• Fault 6: the play request now waits for the close. If the server does not answer, the wait ends at the timeout of the HTTP client, which is 10 seconds.
• syncMinChange is 1 second, because a paused player can report a position that is a fraction of a second away from the start position of the session.

How it was tested

Each fault has a test in internal/app/progress_sync_test.go that failed before its correction. The tests use a fake ABS server (httptest) and the mock player of the app tests.

Fault	Tests
1	TestStopOfUntouchedSessionSendsNoProgress (quit with q, quit with ctrl+c, Cleanup, play of a different item)
2	TestStopSendsNoFinishedFlag (end of the book, Cleanup)
3	TestSyncSendsListeningTimeSinceLastSync, TestSyncCarriesListeningTimeOfFailedSync, TestCloseSendsListeningTimeSinceLastSync
4	TestSyncTickSendsNothingWhenNothingChanged
5	TestSyncOpensNewSessionAfter404 (book, episode)
6	TestOldSessionClosesBeforeNextPlay (book, episode, queue at the end of a book, skip in the queue, series, close that fails)

The test for fault 6 runs the commands as Bubble Tea does: each command of a batch runs in its own goroutine. Its server needs 100 ms for the close.

Three more tests guard the corrections. They passed before the corrections also:

• TestMarkFinishedSendsExplicitFlag: the two explicit actions keep the isFinished key.
• TestSyncSendsPositionOfSeekToOtherTrack: a seek to a different track of a paused book still reaches the server.
• TestSyncKeepsListeningTimeIfNewSessionFails: the listening time stays with the session if the new session cannot open.

internal/abs has a test for each new client function: TestUpdatePositionHTTP and TestCloseSessionNoSyncHTTP.

Three old tests asserted that lastSyncPos changes at the sync tick. They now assert the new contract: TestSyncTickWhenPlaying, TestPlaybackLifecycleIntegration, and TestPlaybackMultipleSyncCycles.

Checks on macOS (Apple Silicon), on the last commit (54cf382):

• gofmt -l .: no file
• go build ./...: pass
• go vet ./...: pass
• golangci-lint run with version 2.14.0: 0 issues
• PINE_REQUIRE_LIBMPV=1 PINE_REQUIRE_DBUS=1 go test ./... -count=1: 27 packages pass
• go test -race ./... -count=1: 27 packages pass

Faults found during the work on this pull request

The work on this pull request found three more faults. Each fault is confirmed in the code of pine, and a test reproduces it. Each fault has its own commit.

What was wrong

7. A quit with q could lose the last position and the listening time. The q key ran stopPlayback and returned its commands in a batch with tea.Quit (Update in internal/app/model.go). Bubble Tea 1.3.10 runs each command of a batch in its own goroutine, and it does not wait for a command at a quit. The model then had no session, so Cleanup sent nothing, and the process ended. The server got the close and the progress update only if the two requests left before the end of the process.
8. A quit with ctrl+c sent the close and the progress update two times. The ctrl+c key ran the commands of stopPlayback, but it kept the model that still had the session. Cleanup then sent the close and the progress update again. ABS adds the timeListened of each close to the session.
9. The listening time was the change of the position (handlePositionMsg). At the speed 2.0, the position moves two seconds in each second. For one hour of play, ABS stored two hours. The web client of ABS counts the time of the clock (client/players/PlayerHandler.js).

What changes

• Faults 7 and 8. The two quit keys return only tea.Quit and keep the session in the model. Cleanup sends the close and the progress update one time, and main waits for it. Cleanup has a limit of 5 seconds for the two requests. The rule for an untouched session stays: no progress update, and a close with no body.
• Fault 9. timeListened is the time of the clock between two position ticks of a player that plays (trackListeningTime). A tick of a paused player adds nothing, and the first tick after a pause adds nothing. A tick with an error of the player adds nothing. A tick that comes more than 5 seconds after the last tick adds nothing (maxListeningTick), for example after a suspend of the machine. A test moves the clock with Model.now.

Decisions:

• Faults 7 and 8: a quit sends no command for the session. A command cannot make the program wait. If the server does not answer, a quit now takes up to 5 seconds. Before, a quit with q ended immediately and lost the requests.
• Fault 9: the listening time does not come from the change of the position divided by the speed of the player model. Only the speed command calls SetSpeed (internal/player/commands.go). Inference from the code: after the start of a new session, mpv plays at the speed 1.0 while the model can have a different speed. No real playback checked this.
• Fault 9: the ticks are 500 ms apart. One pause can lose up to 1 second of listening time: the time before the tick that reports the pause, and the time before the first tick after the pause.

How it was tested

Fault	Tests
7	TestQuitWaitsForLastPosition (q, ctrl+c). Its server needs 100 ms for each request.
8	TestQuitSendsLastPositionOnce (q, ctrl+c), TestStopOfUntouchedSessionSendsNoProgress (new case: quit with ctrl+c)
9	TestListeningTimeIsTimeOfPlay (one minute at the speed 2.0, a pause of one minute, a tick after a suspend of the machine)

The tests for the faults 7 and 8 do what the program does at a quit (quitProgram): each command of the key runs in its own goroutine, the program returns at the QuitMsg, and then Cleanup runs on the final model.

Old tests that now assert the new contracts:

• A quit runs Cleanup: TestE2E_FullJourney and TestE2E_QQuitsAndStopsPlayback.
• The listening time is the time of the clock: TestPositionMsgUpdatesPlayer, TestPositionMsgTracksTimeListened, TestPositionMsgBackwardSeekAddsOnlyTimeOfPlay (before: TestPositionMsgBackwardSeekDoesNotAddTime), TestPlaybackLifecycleIntegration, TestPlaybackSeekBackwardThenForward, TestE2E_DetailToPlayback, and TestE2E_FullJourney.

Not tested

• No real ABS server ran, and no real playback ran. The statements about ABS come from its source, not from a request to a server.
• The position that libmpv reports for a paused session is not measured. If it is 1 second or more away from the start position of the session, pine sends that position at the stop, as it did before, but with no isFinished key.
• The MPRIS server test is for Linux only. It did not run on macOS.
• No real playback ran at a speed other than 1.0.
• No quit ran in a real terminal.

🤖 Generated with Claude Code