Deadlock in scan / rescan

[frake65]

Scanning / rescanning my larger (approx. 25,000 files) music collection I frequently get the following messages:

Command line I use is:

sudo -u www-data php occ music:scan --clean-obsolete --all

_In ExceptionConverter.php line 37:

An exception occurred while executing a query: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get l
ock; try restarting transaction

In Exception.php line 26:

SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction

In Statement.php line 92:

SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction_

Using Nextcloud 22, PHP 8.0, mariadb, latest Music app 1.4.1

[paulijar]

Thanks for the report. This is something I have never seen and no-one else has reported for the Music app before. But there is a report with similar error messages on the Nextcloud server: https://github.com/nextcloud/server/issues/6899. That issue has been closed after some fixes were made on the Nextcloud server a long time ago. But there are also comments, that problems like this have resurfaced in NC22.

Edit: However, as this happens while Music is updating its own DB tables, it's probably more likely that this does not have the same root cause as the Nextcloud server issues with the same error message, but rather this is now caused by the Music app itself. One guess could be that this is interference between the automatic cleanup task running periodically in the background and the scanning process.

[frake65]

Is there any way I could support to find the root cause e.g. by changing the log level? Or should I disable the nextcloud cron while doing the re-scan?

[paulijar]

Enabling this option and checking the MariaDB error.log might give us some hints: https://dev.mysql.com/doc/refman/8.0/en/innodb-parameters.html#sysvar_innodb_print_all_deadlocks

Also, if you can systematically reproduce the error, then testing the scanning with nextcloud cron disabled could prove my previous theory right or wrong.

[frake65]

I could now reproduce the deadlock - it is happening the very same moment, the scheduled cron job of nextcloud (cron.php) starts running. Disabling the cron job of nextcloud while doing the rescan helped out and the deadlock disappears. - So this is working as a valid workaround for me.

[paulijar]

Okay, thanks, that's valuable information. One way or another, I'll need to prevent the cleanup task from accessing the same DB rows which are being modified by the scan task. However, as I can't reproduce the issue myself, I will not be able to tell if any changes made actually solve the problem. That will be found out only afterwards.

[vasilisvg]

I had a deadlock as well. I ran

sudo -u www-data php occ music:scan myusername --rescan

It kept scanning without any errors, but when it reached this song

Scanning /myusername/files/Music/R. Crumb and his Cheap Suit Serenaders/Chasin' Rainbows/02 Chasin' Rainbows.m4a

I received this error:

In ExceptionConverter.php line 37:
  An exception occurred while executing a query: SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction
In Exception.php line 26:
  SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction
In Statement.php line 92:
  SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction

I though it was caused by the quotes in both the directory name and the quote in the file name. So I removed both quotes and ran the command again. This solved it. Which is a bit surprising because this is not the only song with quotes in the directory and in a file name. Maybe it’s both the dot and the quote in the name?

[paulijar]

@vasilisvg Did you try it several times so that you always got the problem on this same file? Because if this happened only once, then the chances are that the file or its name were not important, but this was rather a random timing issue. And the likely explanation would be, that the automatic background cleanup task just happened to start at that time and cause the issue like with the original reporter.

[mybuntu-git2]

having the same issue today after adding a big bunch of songs and "reshaping" the library with beets. occ music:scan myuser --rescan --clean-obsolete

I got serialisation failure when running this: An exception occurred while executing 'UPDATE oc_music_albums SET cover_file_id = ? WHERE id = ?' with params [9836, 1083]:

EDIT: this happened multiple times. now I am testing after running an OCC files:scan, because I did not do that and this is clearly a mistake because music reads OC files not filesystem files.

EDIT 2: after files:scan reexecuting music:scan the error goes away.