mirror of
https://github.com/advplyr/audiobookshelf.git
synced 2026-03-02 22:46:56 -05:00
[Bug]: Server crash when iOS app connects to server, unique constraint violation - #1936
Labels
No labels
authentication
awaiting release
backlog
bug
chapter editor
config-issue
ebooks
encoding/embedding
enhancement
help wanted
listening sessions & progress
planned
possible plugin
progress sync
sorting/filtering/searching
unable to reproduce
upload
users & permissions
waiting
No milestone
No project
No assignees
1 participant
Notifications
Due date
No due date set.
Dependencies
No dependencies set.
Reference
starred/audiobookshelf#1936
Loading…
Add table
Add a link
Reference in a new issue
No description provided.
Delete branch "%!s()"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Originally created by @rakorea on GitHub (Feb 25, 2024).
Describe the issue
When connecting iOS Application v0.9.72-beta to server 2.8.0, server crashes.
Checked that the server code in question does seem to check if session exists, but I still get the following log:
After app restart the connection works fine. Looks like race condition to me, but I'm not a Node dev. Whether this is mobile app misbehaving and somehow throwing 2 concurrent threads to server is beyond me, server crashing here is obviously not ideal.
github.com/advplyr/audiobookshelf@d8b9f08e5a/server/managers/PlaybackSessionManager.js (L136)Running the server on Qnap NAS, installed via .qpkg package from https://www.myqnap.org/product/audiobookshelf/
Steps to reproduce the issue
Unfortunately have not found bullet proof way to reproduce. Usage pattern is usually:
This results to server crashing almost daily.
Audiobookshelf version
2.8.0
How are you running audiobookshelf?
Other
@advplyr commented on GitHub (Feb 25, 2024):
Is the
/configfolder on a network drive?@rakorea commented on GitHub (Feb 25, 2024):
No, everything is local on the server
@mikiher commented on GitHub (Mar 1, 2024):
What seems suspicious about log above is that the same line appears twice in succession within a short timeframe:
It does smell like a race condition...
@zugao commented on GitHub (Mar 19, 2024):
I also encountered the same issue after connecting to the server
@TobiasDax commented on GitHub (Jul 11, 2024):
Still the same issue
@Marvin-D-Martian commented on GitHub (Sep 14, 2024):
I think I have the same issue. My docker crashes without any info in the docker log. I posted about this on r/audiobookshelf and just including my data here in case it helps...
All latest versions
All works well, until it doesn't.
When using Shelf Player, I can see
Device - Audiobooks iOS 2.13.4 Play method - Direct Play
When using Plappa:
Device - plappa 1.4.2 Play method - unknown
All the duplicate listening session have variious play times. I am obviously only using Plappa, just tried ShelfPlayer to see if it actually recognises play method.
Log is attached below, but from what I can see, there is abunch of Listening Session for the same user and book, with various times.
FATAL [Server] Unhandled rejection: SequelizeUniqueConstraintError: Validation error, promise: Promise { <rejected> Error at Database.<anonymous> (/node_modules/sequelize/lib/dialects/sqlite/query.js:185:27) at /node_moduIes/sequelize/Iib/dialects/sqlite/query.js:183:50 at new Promise (<anonymous>) at Query.run (/node_modules/sequelize/Iib/dialects/sqlite/query.js:183:12) at /node_modules/sequelize/lib/sequelize.js:315:28 at async SQLiteQuerylnterface.insert (/node_modules/sequelize/lib/dialects/abstract/query-interface.js:308:21) at async PlaybackSession.save at async playbackSession.create at async PlaybackSessionManager.syncLocalSession (/server/managers/PlaybackSessionManager.js:168:7) at async PlaybackSessionManager.syncLocalSessionRequest { name: 'SequelizeUniqueConstraintErrorj, errors: [ [ValidationErrorltem] l, parent: [Error: SQLITE_CONSTRAINT: UNIQUE constraint failed: playbackSessions.id] { errno: 19, code: 'SQLITE_CONSTRAINT', sql: 'INSERT INTO playbackSessionss ( • id , & medialtemld , medialtemType' , s displayTitle& , s displayAuthor' , • mediaPlayeö , startTime& , s currentT VALUES 1, original: [Error: SQLITE_CONSTRAINT: UNIQUE constraint failed: playbacksessions.id] { errno: 19, code: 'SQLITE_CONSTRAINT', sql: 'INSERT INTO playbackSessionss ( • id , s medialtemld , medialtemTypes , s displayTitles , s displayAuthoö , ' mediaPlayers , startTimes , s currentT VALUES 1, fields: [ 'id' l, sql: 'INSERT INTO playbackSessions' ( • id , s medialtemld , medialtemTypes displayTitles , s displayAuthoö , ' mediaPlayers , startTimes , s currentT VALUES } }Debug log:
2024-09-13 21:27:05.741 DEBUG [ApiCacheManager] mediaProgress.afterUpdate: Clearing cache 2024-09-13 21:27:05.741 DEBUG [SocketAuthority] clientEmitter - no clients found for user a4031e86-929c-48b7-bb98-49e2715f5432 2024-09-13 21:27:05.824 DEBUG [ApiCacheManager] mediaProgress.afterUpdate: Clearing cache 2024-09-13 21:27:05.824 DEBUG [SocketAuthority] clientEmitter - no clients found for user a4031e86-929c-48b7-bb98-49e2715f5432 2024-09-13 21:42:07.577 DEBUG Set Log Level to DEBUG 2024-09-13 21:42:07.629 DEBUG [ApiCacheManager] Array.afterUpsert: Clearing cache@Marvin-D-Martian commented on GitHub (Sep 17, 2024):
Crashed again this morning. No book was playing, no user connected.
`FATAL
[Server] Unhandled rejection: SequelizeUniqueConstraintError: Validation error, promise: Promise { Error at Database. (/node_modules/sequelize/lib/dialects/sqlite/query.js:185:27) at /node_modules/sequelize/lib/dialects/sqlite/query.js:183:50 at new Promise () at Query.run (/node_modules/sequelize/lib/dialects/sqlite/query.js:183:12) at /node_modules/sequelize/lib/sequelize.js:315:28 at async SQLiteQueryInterface.insert (/node_modules/sequelize/lib/dialects/abstract/query-interface.js:308:21) at async PlaybackSession.save (/node_modules/sequelize/lib/model.js:2490:35) at async playbackSession.create (/node_modules/sequelize/lib/model.js:1362:12) at async PlaybackSessionManager.syncLocalSession (/server/managers/PlaybackSessionManager.js:168:7) at async PlaybackSessionManager.syncLocalSessionRequest (/server/managers/PlaybackSessionManager.js:242:20) { name: 'SequelizeUniqueConstraintError', errors: [ [ValidationErrorItem] ], parent: [Error: SQLITE_CONSTRAINT: UNIQUE constraint failed: playbackSessions.id] { errno: 19, code: 'SQLITE_CONSTRAINT', sql: 'INSERT INTO
playbackSessions(id,mediaItemId,mediaItemType,displayTitle,displayAuthor,mediaPlayer,startTime,currentTime,serverVersion,timeListening,mediaMetadata,date,dayOfWeek,extraData,createdAt,updatedAt,userId,deviceId,libraryId) VALUES ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,$14,$15,$16,$17,$18,$19);' }, original: [Error: SQLITE_CONSTRAINT: UNIQUE constraint failed: playbackSessions.id] { errno: 19, code: 'SQLITE_CONSTRAINT', sql: 'INSERT INTOplaybackSessions(id,mediaItemId,mediaItemType,displayTitle,displayAuthor,mediaPlayer,startTime,currentTime,serverVersion,timeListening,mediaMetadata,date,dayOfWeek,extraData,createdAt,updatedAt,userId,deviceId,libraryId) VALUES ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,$14,$15,$16,$17,$18,$19);' }, fields: [ 'id' ], sql: 'INSERT INTOplaybackSessions(id,mediaItemId,mediaItemType,displayTitle,displayAuthor,mediaPlayer,startTime,currentTime,serverVersion,timeListening,mediaMetadata,date,dayOfWeek,extraData,createdAt,updatedAt,userId,deviceId,libraryId) VALUES ($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11,$12,$13,$14,$15,$16,$17,$18,$19);' } }`@rakorea commented on GitHub (Sep 17, 2024):
I still think it is race condition. I just don't have the Node knowledge to fix this correctly.
It is my understanding that Node is single threaded so generally you do not need to think about concurrency. But whenever you await, then it might give another task (or whatever they are called) priority.
I think in current PlaybackSessionManager.js:162 is where it goes wrong. Any number of these processes can get through line 163 and await again on line 169.
@mikiher commented on GitHub (Sep 17, 2024):
Sorry, this dropped out of my radar for a while.
Thanks for the reports and suggestions. I will investigate this week.
@mikiher commented on GitHub (Sep 18, 2024):
You were right about the race condition. Sent a fix.
@github-actions[bot] commented on GitHub (Oct 5, 2024):
Fixed in v2.14.0.