Database update never completing

[manichardtiger]

Hi all

I've observed the following when updating the database on v. 1.2.4, after adding / deleting / modifying a large number of tags or files:

The updater correctly identifies changed / deleted songs but never completes; sometimes the progress bar begins and then gets stuck but most of the times theres no progress bar.

Top shows php5-fpm using a lot of CPU (90-95% on BananaPi) and after a while nothing.

the error.log shows the following:

`2018-11-05 10:40:36 Error: Fatal Error (1): Maximum execution time of 30 seconds exceeded in [/var/www/sonerezh/app/Vendor/james-heinrich/getid3/getid3/getid3.php, line 1721]
2018-11-05 10:40:36 Error: [InternalErrorException] Internal Server Error
Request URL: /import
Stack Trace:
#0 /var/www/sonerezh/app/Vendor/cakephp/cakephp/lib/Cake/Error/ErrorHandler.php(212): ErrorHandler::handleFatalError(1, 'Maximum executi...', '/var/www/sonere...', 1721)
#1 [internal function]: ErrorHandler::handleError(1, 'Maximum executi...', '/var/www/sonere...', 1721, Array)
#2 /var/www/sonerezh/app/Vendor/cakephp/cakephp/lib/Cake/Core/App.php(970): call_user_func('ErrorHandler::h...', 1, 'Maximum executi...', '/var/www/sonere...', 1721, Array)
#3 /var/www/sonerezh/app/Vendor/cakephp/cakephp/lib/Cake/Core/App.php(943): App::_checkFatalError()
#4 [internal function]: App::shutdown()
``

Changing max_execution_time under /etc/php5/fpm/php.ini from 30 to 300 seconds helps but still doesnt completely solve the problem as you need to run the updater and after it gets stuck, clear the cache and rerun until it shows completed. This needs to be done a few times to show complete.

Would changing the max_execution_time to a larger number disrupt anything else?

On a related note, after showing that its finished and re-running, the updater now shows "36 songs updated on the system" and it doesnt go away after showing a successful result in scanning.

The error.log doesnt show anything after the last update. Is there anywhere else to check to see what might be causing this?

Thanks!

[Nizhile]

I felt into the same problem. Using a very simple app to just trigger getID3 library, reading information for several files is very long. Note that the getid3.lib.php line that triggers the maximum time exception refers to some encoding handler MultiByteCharString2HTML()

• Prologue/Alan Menken/Beauty and the beast, the whole script takes 5s.
• Isobel/Björk/Post, the script always takes more than 27s.

It is also noticeable with for MP3s:

• Sunshine Girl/Moumoon/Ice Candy takes about 4s
• Mon père il est tellement fort/Aldbert avec Sansévérino/Enfantillages 2

Thus the problem might occur depending of metadata encoding.

pi@framboise ~/src/sonerezh/app/Console $ time ./cake  testid3 image ~/Documents/Musique/post/isobel.ogg
real    0m27.258s
user    0m18.380s
sys     0m0.300s

pi@framboise ~/src/sonerezh/app/Console $ time ./cake  testid3 image ~/Documents/Musique/beauty_and_the_beast/prologue.ogg
real    0m4.636s
user    0m2.850s
sys     0m0.250s

[Nizhile]

The time to process depends on cover art. Cover is encoded as a string in the tag and is probably analysed for character conversion. I removed the tag for cover in one of the file and it's now really quick.

The origin of the problem is your cover art source. Here are the thumnails found by sonerezh on a fairly fresh install. The 652KB image is the 1500x1500 cover from album Post. It's time to check music metadata 😕

pi@framboise ~/src/sonerezh/app/Console $ identify ../webroot/img/thumbnails/*
../webroot/img/thumbnails/2e2aa06b857b43bd3b938f999c991b35.jpeg JPEG 500x495 500x495+0+0 8-bit DirectClass 58.2KB 0.010u 0:00.009
../webroot/img/thumbnails/6d26e7b31145e45aef18787e4bd24605.jpeg[1] JPEG 497x500 497x500+0+0 8-bit DirectClass 24.7KB 0.000u 0:00.000
../webroot/img/thumbnails/f39f06b4d3aeb0ae894ef3a80c070e68.jpeg[2] JPEG 1500x1500 1500x1500+0+0 8-bit DirectClass 652KB 0.010u 0:00.010

pi@framboise ~/src/sonerezh/app/Console $ time ./cake  testid3 image  ~/Documents/isobel.ogg

Welcome to CakePHP v2.10.11 Console
---------------------------------------------------------------
App : app
Path: /home/pi/src/sonerezh/app/
---------------------------------------------------------------
[INFO] Checking cover extraction
File /home/pi/Documents/isobel.ogg
Title Isobel
Artist Bjork
No cover found

real    0m2.429s
user    0m1.450s
sys     0m0.110s

[lGuillaume124]

Indeed, that what we discussed when we updated this third-party library.

@atomiix started to work on our own implementation of a metadata parsing library last year but he never finished it. He was stuck on the bitrate calculation I think or something like that. Unfortunately he has no time to spend on Sonerezh for the moment. May be I should publish his work and ask for contributions…

Anyway thanks a lot for the explanations!

[Nizhile]

One workaround could be to trigger clean up import lock using a shutdown function.
See https://stackoverflow.com/questions/277224/how-do-i-catch-a-php-fatal-error/2146171#2146171 for an example. This way, no need to clean up completely the cache to remove the lock.

[lGuillaume124]

Nice, I'll try to include it to the next major release.