Multi-file delete test(s) are not reliable

[phil-davis]

This test scenario failed in the nightly run:

https://drone.owncloud.com/owncloud/web/12623/6/20

Scenario: Delete all except for a few files at once
  tests/acceptance/features/webUIDeleteFilesFolders/deleteFilesFolders.feature:79

    Given user "user1" has been created with default attributes
    And user "user1" has logged in using the webUI
√ Element <input[autocomplete="kopano-account username"]> was visible after 636 milliseconds.
√ Element <#oc-app-container> was visible after 2637 milliseconds.
√ Element <//button[@id="new-file-menu-btn" and contains(@class, "oc-button-primary") and not(@disabled)]> was present after 147 milliseconds.
√ Element <//div[contains(@class, "oc-file") and @data-preview-loaded="false"]> was not present after 879 milliseconds.
    And the user has browsed to the files page
√ Element <//button[@id="new-file-menu-btn" and contains(@class, "oc-button-primary") and not(@disabled)]> was present after 807 milliseconds.
√ Element <//div[contains(@class, "oc-file") and @data-preview-loaded="false"]> was not present after 25 milliseconds.
    When the user marks all files for batch action using the webUI
√ Element <#files-list, #shared-with-list> was visible after 36 milliseconds.
√ Element <#filelist-check-all> was visible after 50 milliseconds.
    And the user unmarks these files for batch action using the webUI
      │ name          │
      │ lorem.txt     │
      │ simple-folder │
√ Element <#files-list-container> was present after 17 milliseconds.
√ Element <.vue-recycle-scroller> was visible after 40 milliseconds.
√ Element <.vue-recycle-scroller> was visible after 30 milliseconds.
√ Element <//div[contains(@class, "file-row-name")][span/text()='lorem' and span/text()=".txt"]/ancestor::div[@data-is-visible="true"]//div[contains(@class, "oc-file") and (@data-preview-loaded="true" or @data-preview-loaded="disabled")]> was visible after 39 milliseconds.
√ Element <#files-list-container> was present after 15 milliseconds.
√ Element <.vue-recycle-scroller> was visible after 29 milliseconds.
√ Element <.vue-recycle-scroller> was visible after 23 milliseconds.
√ Element <//span[contains(@class, "oc-file-name") and text()='simple-folder' and not(../span[contains(@class, "oc-file-extension")])]/ancestor::div[@data-is-visible="true"]//div[contains(@class, "oc-file") and (@data-preview-loaded="true" or @data-preview-loaded="disabled")]> was visible after 127 milliseconds.
    And the user batch deletes the marked files using the webUI
√ Element <#delete-selected-btn> was visible after 36 milliseconds.
√ Element <.oc-modal> was visible after 42 milliseconds.
waiting for 500ms ...
√ Element <.oc-modal> was not present after 15 milliseconds.
    Then as "user1" file "lorem.txt" should exist
    And as "user1" folder "simple-folder" should exist
    And folder "simple-folder" should be listed on the webUI
√ Element <#files-list-container> was present after 9 milliseconds.
√ Element <.vue-recycle-scroller> was visible after 38 milliseconds.
√ Element <.vue-recycle-scroller> was visible after 29 milliseconds.
    And file "lorem.txt" should be listed on the webUI
√ Element <#files-list-container> was present after 13 milliseconds.
√ Element <.vue-recycle-scroller> was visible after 26 milliseconds.
√ Element <.vue-recycle-scroller> was visible after 26 milliseconds.
√ Element <//div[contains(@class, "file-row-name")][span/text()='lorem' and span/text()=".txt"]/ancestor::div[@data-is-visible="true"]//div[contains(@class, "oc-file") and (@data-preview-loaded="true" or @data-preview-loaded="disabled")]> was visible after 54 milliseconds.
    But as "user1" file "data.zip" should not exist
    And file "data.zip" should not be listed on the webUI
√ Element <#files-list-container> was present after 12 milliseconds.
√ Element <.vue-recycle-scroller> was visible after 37 milliseconds.
√ Element <.vue-recycle-scroller> was visible after 25 milliseconds.
√ Passed [ok]: File 'data.zip' is not listed on the filesList
    And the count of files and folders shown on the webUI should be 2
√ Element <#files-list-count-files> was visible after 48 milliseconds.
√ Element <#files-list-count-folders> was visible after 42 milliseconds.
Failed [equal]: (3 == 2) - expected "2" but got: "3" (undefinedms)
undefined    ✖ failed
      Error while running "equal" command: Failed [equal]: (3 == 2) - expected "2" but got: "3" (undefinedms)
          at _callee39$ (/var/www/owncloud/web/tests/acceptance/stepDefinitions/filesContext.js:774:24)
          at runMicrotasks (<anonymous>)
          at processTicksAndRejections (internal/process/task_queues.js:97:5)
    And no message should be displayed on the webUI
    - skipped

  Result: failed

...
runsh: Total unexpected failed scenarios throughout the test run:
webUIDeleteFilesFolders/deleteFilesFolders.feature:79

Investigate the tests that work with multiple files "at once" and see if the timing can be improved, or if there really is a problem with the actual UI or backend server.

[dpakach]

@saw-jan

[saw-jan]

Batch deletion of selected files/folders using webui fails randomly. It seems to be that the problem might be with the backend server.
Server log on the failed case:

{
  "reqId": "c7e1225a-94a0-4394-8f17-fa8400cd1d7e",
  "level": 4,
  "time": "2021-01-05T09:45:41+00:00",
  "remoteAddr": "172.17.0.2",
  "user": "user1",
  "app": "webdav",
  "method": "DELETE",
  "url": "/core/remote.php/webdav/'single'quotes",
  "message": "Exception: An exception occurred while executing 'UPDATE `oc_filecache` SET `storage` =  ?, `path` = ?, `path_hash` = ?, `name` = ?, `parent` =? WHERE `fileid` = ?' with params [848, \"files_trashbin\\/files\\/'single'quotes.d1609839941\", \"15298c333f5696f0d3250ce21bed22ed\", \"'single'quotes.d1609839941\", 2147567358, 2147567251]:\n\nSQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry '848-15298c333f5696f0d3250ce21bed22ed' for key 'oc_filecache.fs_storage_path_hash': {\"Exception\":\"Doctrine\\\\DBAL\\\\Exception\\\\UniqueConstraintViolationException\",\"Message\":\"An exception occurred while executing 'UPDATE `oc_filecache` SET `storage` =  ?, `path` = ?, `path_hash` = ?, `name` = ?, `parent` =? WHERE `fileid` = ?' with params [848, \\\"files_trashbin\\\\\\/files\\\\\\/'single'quotes.d1609839941\\\", \\\"15298c333f5696f0d3250ce21bed22ed\\\", \\\"'single'quotes.d1609839941\\\", 2147567358, 2147567251]:\\n\\nSQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry '848-15298c333f5696f0d3250ce21bed22ed' for key 'oc_filecache.fs_storage_path_hash'\",\"Code\":0,\"Trace\":\"#0 \\/mnt\\/sda1\\/www\\/core\\/lib\\/composer\\/doctrine\\/dbal\\/lib\\/Doctrine\\/DBAL\\/DBALException.php(172): Doctrine\\\\DBAL\\\\Driver\\\\AbstractMySQLDriver->convertException()\\n#1 \\/mnt\\/sda1\\/www\\/core\\/lib\\/composer\\/doctrine\\/dbal\\/lib\\/Doctrine\\/DBAL\\/DBALException.php(151): Doctrine\\\\DBAL\\\\DBALException::wrapException()\\n#2 \\/mnt\\/sda1\\/www\\/core\\/lib\\/composer\\/doctrine\\/dbal\\/lib\\/Doctrine\\/DBAL\\/Connection.php(918): Doctrine\\\\DBAL\\\\DBALException::driverExceptionDuringQuery()\\n#3 \\/mnt\\/sda1\\/www\\/core\\/lib\\/private\\/DB\\/Connection.php(187): Doctrine\\\\DBAL\\\\Connection->executeQuery()\\n#4 \\/mnt\\/sda1\\/www\\/core\\/lib\\/private\\/Files\\/Cache\\/Cache.php(593): OC\\\\DB\\\\Connection->executeQuery()\\n#5 \\/mnt\\/sda1\\/www\\/core\\/lib\\/private\\/Files\\/Cache\\/Cache.php(535): OC\\\\Files\\\\Cache\\\\Cache->moveFromCache()\\n#6 \\/mnt\\/sda1\\/www\\/core\\/lib\\/private\\/Files\\/Cache\\/Updater.php(195): OC\\\\Files\\\\Cache\\\\Cache->move()\\n#7 \\/mnt\\/sda1\\/www\\/core\\/apps\\/files_trashbin\\/lib\\/Trashbin.php(345): OC\\\\Files\\\\Cache\\\\Updater->renameFromStorage()\\n#8 \\/mnt\\/sda1\\/www\\/core\\/apps\\/files_trashbin\\/lib\\/Storage.php(185): OCA\\\\Files_Trashbin\\\\Trashbin::move2trash()\\n#9 \\/mnt\\/sda1\\/www\\/core\\/apps\\/files_trashbin\\/lib\\/Storage.php(131): OCA\\\\Files_Trashbin\\\\Storage->doDelete()\\n#10 \\/mnt\\/sda1\\/www\\/core\\/lib\\/private\\/Files\\/View.php(1222): OCA\\\\Files_Trashbin\\\\Storage->rmdir()\\n#11 \\/mnt\\/sda1\\/www\\/core\\/lib\\/private\\/Files\\/View.php(367): OC\\\\Files\\\\View->basicOperation()\\n#12 \\/mnt\\/sda1\\/www\\/core\\/lib\\/public\\/Events\\/EventEmitterTrait.php(50): OC\\\\Files\\\\View->OC\\\\Files\\\\{closure}(*** sensitive parameters replaced ***)\\n#13 \\/mnt\\/sda1\\/www\\/core\\/lib\\/private\\/Files\\/View.php(378): OC\\\\Files\\\\View->emittingCall()\\n#14 \\/mnt\\/sda1\\/www\\/core\\/apps\\/dav\\/lib\\/Connector\\/Sabre\\/Directory.php(343): OC\\\\Files\\\\View->rmdir()\\n#15 \\/mnt\\/sda1\\/www\\/core\\/lib\\/composer\\/sabre\\/dav\\/lib\\/DAV\\/Tree.php(179): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->delete()\\n#16 \\/mnt\\/sda1\\/www\\/core\\/lib\\/composer\\/sabre\\/dav\\/lib\\/DAV\\/CorePlugin.php(281): Sabre\\\\DAV\\\\Tree->delete()\\n#17 \\/mnt\\/sda1\\/www\\/core\\/lib\\/composer\\/sabre\\/event\\/lib\\/WildcardEmitterTrait.php(89): Sabre\\\\DAV\\\\CorePlugin->httpDelete()\\n#18 \\/mnt\\/sda1\\/www\\/core\\/lib\\/composer\\/sabre\\/dav\\/lib\\/DAV\\/Server.php(472): Sabre\\\\DAV\\\\Server->emit()\\n#19 \\/mnt\\/sda1\\/www\\/core\\/lib\\/composer\\/sabre\\/dav\\/lib\\/DAV\\/Server.php(253): Sabre\\\\DAV\\\\Server->invokeMethod()\\n#20 \\/mnt\\/sda1\\/www\\/core\\/lib\\/composer\\/sabre\\/dav\\/lib\\/DAV\\/Server.php(321): Sabre\\\\DAV\\\\Server->start()\\n#21 \\/mnt\\/sda1\\/www\\/core\\/apps\\/dav\\/appinfo\\/v1\\/webdav.php(66): Sabre\\\\DAV\\\\Server->exec()\\n#22 \\/mnt\\/sda1\\/www\\/core\\/remote.php(165): require_once('\\/mnt\\/sda1\\/www\\/c...')\\n#23 {main}\",\"File\":\"\\/mnt\\/sda1\\/www\\/core\\/lib\\/composer\\/doctrine\\/dbal\\/lib\\/Doctrine\\/DBAL\\/Driver\\/AbstractMySQLDriver.php\",\"Line\":59}"
}

Highlight:

Exception: An exception occurred while executing 
'UPDATE `oc_filecache` SET `storage` =  ?, `path` = ?, `path_hash` = ?, `name` = ?, `parent` =? WHERE `fileid` = ?' 
with params 
[848, \"files_trashbin\\/files\\/'single'quotes.d1609839941\", \"15298c333f5696f0d3250ce21bed22ed\", \"'single'quotes.d1609839941\", 2147567358, 2147567251]
SQLSTATE[23000]: 
Integrity constraint violation: 1062 Duplicate entry '848-15298c333f5696f0d3250ce21bed22ed' for key 'oc_filecache.fs_storage_path_hash'

[individual-it]

this sounds like an issue in core, here a similar issue when restoring owncloud/core#38039

[individual-it]

we had that kind on issue in 2018, did it come back? owncloud/core#33325

[saw-jan]

we had that kind on issue in 2018, did it come back? owncloud/core#33325

@individual-it @phil-davis looks similar and the server log also looks the same

[pascalwengerter]

@phil-davis how's that one looking? From my recent involvement with merging back the a11y-branch the CI has been pretty solid recently!

[pascalwengerter]

Closing as fixed/unresponsive

[saw-jan]

Public link: delete multiple files test fails sometimes due to this issue.
#6707

Server: oCIS

Screenshot:

[saw-jan]

Some other fails due to some error while doing batch action:
https://drone.owncloud.com/owncloud/web/24385/67/15
https://drone.owncloud.com/owncloud/web/24385/53/15
https://drone.owncloud.com/owncloud/web/24755/68/15

[saw-jan]

closing this in favour of owncloud/ocis#3612