[Bug]: Server crash when iOS app connects to server, unique constraint violation -

[rakorea]

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:

2024-02-25 10:29:41.260 DEBUG [PlaybackSessionManager] Inserting new session for "bookname" (2899EE32-E3FB-4B6F-A5A1-00714B601EB6)
2024-02-25 10:29:41.274 DEBUG [PlaybackSessionManager] Inserting new session for "bookname" (2899EE32-E3FB-4B6F-A5A1-00714B601EB6)
2024-02-25 10:29:41.332 INFO  [SocketAuthority] Socket Connected wSQqgXy-5QyV7_NgAAAH
2024-02-25 10:29:41.382 DEBUG [ApiCacheManager] playbackSession.afterCreate: Clearing cache
2024-02-25 10:29:41.384 DEBUG [PlaybackSessionManager] Updating progress for "bookname" with current time 35347.918750856 (previously 10440.017594017)
2024-02-25 10:29:41.407 FATAL [Server] Unhandled rejection: SequelizeUniqueConstraintError: Validation error, promise: Promise { <rejected> 
Error at Database.<anonymous> (/share/CACHEDEV1_DATA/.qpkg/Audiobookshelf/audiobookshelf/node_modules/sequelize/lib/dialects/sqlite/query.js:185:27) at Database.serialize 
(<anonymous>) at /share/CACHEDEV1_DATA/.qpkg/Audiobookshelf/audiobookshelf/node_modules/sequelize/lib/dialects/sqlite/query.js:183:50 at new Promise (<anonymous>) at Query.run 
(/share/CACHEDEV1_DATA/.qpkg/Audiobookshelf/audiobookshelf/node_modules/sequelize/lib/dialects/sqlite/query.js:183:12) at /share/CACHEDEV1_DATA/.qpkg/Audiobookshelf/audiobookshelf/node_modules/sequelize/lib/sequelize.js:315:28
 at async SQLiteQueryInterface.insert (/share/CACHEDEV1_DATA/.qpkg/Audiobookshelf/audiobookshelf/node_modules/sequelize/lib/dialects/abstract/query-interface.js:308:21) at async PlaybackSession.save 
 (/share/CACHEDEV1_DATA/.qpkg/Audiobookshelf/audiobookshelf/node_modules/sequelize/lib/model.js:2490:35) at async Function.create (/share/CACHEDEV1_DATA/.qpkg/Audiobookshelf/audiobookshelf/node_modules/sequelize/lib/model.js:1362:12) 
 at async PlaybackSessionManager.syncLocalSession (/share/CACHEDEV1_DATA/.qpkg/Audiobookshelf/audiobookshelf/server/managers/PlaybackSessionManager.js:142:7) { 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`,`duration`,`playMethod`,`mediaPlayer`,`startTime`,`currentTime`,`serverVersion`,`coverPath`,`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,$20,$21,$22);' }, original: [Error: SQLITE_CONSTRAINT: UNIQUE constraint failed: playbackSessions.id] { errno: 19, code: 'SQLITE_CONSTRAINT', sql: 'INSERT INTO `playbackSessions` (`id`,`mediaItemId`,`mediaItemType`,`displayTitle`,`displayAuthor`,`duration`,`playMethod`,`mediaPlayer`,`startTime`,`currentTime`,`serverVersion`,`coverPath`,`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,$20,$21,$22);' }, fields: [ 'id' ], sql: 'INSERT INTO `playbackSessions` (`id`,`mediaItemId`,`mediaItemType`,`displayTitle`,`displayAuthor`,`duration`,`playMethod`,`mediaPlayer`,`startTime`,`currentTime`,`serverVersion`,`coverPath`,`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,$20,$21,$22);' } }

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.

https://github.com/advplyr/audiobookshelf/blob/d8b9f08e5a00b113e33367e1d4ed5ef593d02b18/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:

1. listen to local book on iOS for more than one session offline
2. return app device to network
3. open app

This results to server crashing almost daily.

Audiobookshelf version

2.8.0

How are you running audiobookshelf?

Other

[advplyr]

Is the /config folder on a network drive?

[rakorea]

Is the /config folder on a network drive?

No, everything is local on the server

[mikiher]

What seems suspicious about log above is that the same line appears twice in succession within a short timeframe:

2024-02-25 10:29:41.260 DEBUG [PlaybackSessionManager] Inserting new session for "bookname" (2899EE32-E3FB-4B6F-A5A1-00714B601EB6)
2024-02-25 10:29:41.274 DEBUG [PlaybackSessionManager] Inserting new session for "bookname" (2899EE32-E3FB-4B6F-A5A1-00714B601EB6)

It does smell like a race condition...

[zugao]

I also encountered the same issue after connecting to the server

[TobiasDax]

Still the same issue