Providing default audio files crashes user creation

[n00bundercover]

When providing audio files in the default files (https://docs.nextcloud.com/server/13/admin_manual/configuration_files/default_files_configuration.html), after first user login, default file providing will crash!
The user will see a nextcloud error screen. When login in for a second time, it will work, but only a part of default files will be copied to the user folder, depending on where the audio files are located.
When the Music app is disabled, this does not happen.

Im using:

• arch
• nginx
• postgresql
• php 7.2
• nextcloud 13 production channel stable channel
• Music app, latest version

To reproduce:

1. Have Music app installed and activated for the user you will create later.
2. Put audio files (mp3 and wma tested) and a few random files in default files like explained in the link above.
3. Create new user.
4. Try login in a webbrowser with new user: You will receive an error message.
5. Login again in webbrowser. Login should work. You will see just part of the default files where transmitted to new user folder.
6. Check nextcloud log: You will see error messages regarding the Music app, resulting in error while transfering default files.

Sorry if something is hard to understand, I am not a native speaker. Thanks for the great app!

[paulijar]

Thanks for the report. This might be the same issue as #636, or at least related to it, but I still need to check this.

Whenever you report a bug involving some error messages in the log file(s), it is usually a good idea to attach those log files or at least the relevant parts of them.

[n00bundercover]

Sorry this took me so long, anyways here we go.
This is what you see when, after adding music file to the default files, you try to log in a new user for the first time.

It is a default error message, rough translation: "Server could not handle the request. If this happens again, contact your administrator..."

This is what appears in nextcloud log:

Error	index	OCP\Lock\LockedException: "Musik/Broke_For_Free_-_02_-_My_Always_Mood.mp3" is locked

    /usr/share/webapps/nextcloud/lib/private/Files/View.php - line 2036: OC\Files\View->lockPath('/testuser/files...', 1, false)
    /usr/share/webapps/nextcloud/lib/private/Files/View.php - line 1134: OC\Files\View->lockFile('/testuser/files...', 1)
    /usr/share/webapps/nextcloud/lib/private/Files/View.php - line 987: OC\Files\View->basicOperation('fopen', '/testuser/files...', Array, 'r')
    /usr/share/webapps/nextcloud/lib/private/Files/Node/File.php - line 104: OC\Files\View->fopen('/testuser/files...', 'r')
    /usr/share/webapps/nextcloud/apps2/music/utility/extractorgetid3.php - line 46: OC\Files\Node\File->fopen('r')
    /usr/share/webapps/nextcloud/apps2/music/utility/scanner.php - line 184: OCA\Music\Utility\ExtractorGetID3->extract(Object(OC\Files\Node\File))
    /usr/share/webapps/nextcloud/apps2/music/utility/scanner.php - line 139: OCA\Music\Utility\Scanner->extractMetadata(Object(OC\Files\Node\File), Object(OC\Files\Node\Folder), '/testuser/files...')
    /usr/share/webapps/nextcloud/apps2/music/utility/scanner.php - line 115: OCA\Music\Utility\Scanner->updateAudio(Object(OC\Files\Node\File), 'testuser', Object(OC\Files\Node\Folder), '/testuser/files...', 'audio/mpeg')
    /usr/share/webapps/nextcloud/apps2/music/hooks/filehooks.php - line 67: OCA\Music\Utility\Scanner->update(Object(OC\Files\Node\File), 'testuser', Object(OC\Files\Node\Folder))
    [internal function] OCA\Music\Hooks\FileHooks updated(Object(OC\Files\Node\File))
    /usr/share/webapps/nextcloud/lib/private/Hooks/EmitterTrait.php - line 99: call_user_func_array(Array, Array)
    /usr/share/webapps/nextcloud/lib/private/Hooks/PublicEmitter.php - line 36: OC\Hooks\BasicEmitter->emit('\\OC\\Files', 'postWrite', Array)
    /usr/share/webapps/nextcloud/lib/private/Files/Node/Root.php - line 136: OC\Hooks\PublicEmitter->emit('\\OC\\Files', 'postWrite', Array)
    /usr/share/webapps/nextcloud/lib/private/Files/Node/Node.php - line 108: OC\Files\Node\Root->emit('\\OC\\Files', 'postWrite', Array)
    /usr/share/webapps/nextcloud/lib/private/Files/Node/File.php - line 105: OC\Files\Node\Node->sendHooks(Array)
    /usr/share/webapps/nextcloud/lib/private/legacy/util.php - line 452: OC\Files\Node\File->fopen('w')
    /usr/share/webapps/nextcloud/lib/private/legacy/util.php - line 443: OC_Util copyr('/usr/share/weba...', Object(OC\Files\Node\Folder))
    /usr/share/webapps/nextcloud/lib/private/legacy/util.php - line 415: OC_Util copyr('/usr/share/weba...', Object(OC\Files\Node\Folder))
    /usr/share/webapps/nextcloud/lib/private/User/Session.php - line 503: OC_Util copySkeleton('testuser', Object(OC\Files\Node\Folder))
    /usr/share/webapps/nextcloud/lib/private/User/Session.php - line 370: OC\User\Session->prepareUserLogin(true, true)
    /usr/share/webapps/nextcloud/core/Controller/LoginController.php - line 282: OC\User\Session->completeLogin(*** sensitive parameters replaced ***)
    [internal function] OC\Core\Controller\LoginController->tryLogin(*** sensitive parameters replaced ***)
    /usr/share/webapps/nextcloud/lib/private/AppFramework/Http/Dispatcher.php - line 161: call_user_func_array(Array, Array)
    /usr/share/webapps/nextcloud/lib/private/AppFramework/Http/Dispatcher.php - line 91: OC\AppFramework\Http\Dispatcher->executeController(Object(OC\Core\Controller\LoginController), 'tryLogin')
    /usr/share/webapps/nextcloud/lib/private/AppFramework/App.php - line 115: OC\AppFramework\Http\Dispatcher->dispatch(Object(OC\Core\Controller\LoginController), 'tryLogin')
    /usr/share/webapps/nextcloud/lib/private/AppFramework/Routing/RouteActionHandler.php - line 47: OC\AppFramework\App main('OC\\Core\\Control...', 'tryLogin', Object(OC\AppFramework\DependencyInjection\DIContainer), Array)
    [internal function] OC\AppFramework\Routing\RouteActionHandler->__invoke(Array)
    /usr/share/webapps/nextcloud/lib/private/Route/Router.php - line 297: call_user_func(Object(OC\AppFramework\Routing\RouteActionHandler), Array)
    /usr/share/webapps/nextcloud/lib/base.php - line 999: OC\Route\Router->match('/login')
    /usr/share/webapps/nextcloud/index.php - line 37: OC handleRequest()
    {main}

[paulijar]

Thanks. The root cause seems to be that the Nextcloud/ownCloud core fires the postWrite hook while it still has the new file locked for exclusive access (and actually before it has really written anything to the file). The Music app is attached to this hook and tries to open the new file for reading to extract its metadata, but this fails because the file is locked.

I don't think that the core's behavior here makes much sense, but we can prevent the crash by catching the exception within the Music app. However, there will then be a residual error: the metadata of the default files is not extracted and those files are shown under Unknown artist and Unknown album in the Music app. To fix this, the core should be fixed to fire the hooks only after it has written and closed the default files.

[n00bundercover]

I should also mention I enabled encryption like explained here. Maybe this is related to the behaviour of core.

Is there another hook for "first login done"? So maybe catching exception for postWrite and then extracting music metadata after first login just like after postWrite would be a work around? But I really did not look at the code so no idea.

[paulijar]

The encryption is not relevant here, I tested this and could reproduce the problem without any encryption. I'm not aware of any "first login done" hook, but there probably are many hooks which I don't know.

[paulijar]

I now made such a workaround that the postWrite hooks are ignored until the user has scanned his/her music library. Hence, any default audio files are not automatically added to the music library. Instead, the first time the user opens the Music app, the app prompts the user to start scanning the music library.

[paulijar]

The workaround is now also published as part of the brand new release v0.6.0.