local storage tests failing with user-key encryption

[phil-davis]

against 10.9.1RC1

https://drone.owncloud.com/owncloud/user_ldap/3689/142/16
and
https://drone.owncloud.com/owncloud/user_ldap/3690/142/16

runsh: Total unexpected failed scenarios throughout the test run:
cliLocalStorage/propfindOnLocalStorage.feature:32
cliLocalStorage/propfindOnLocalStorage.feature:51
cliLocalStorage/propfindOnLocalStorage.feature:52
cliLocalStorage/propfindOnLocalStorage.feature:65
cliLocalStorage/propfindOnLocalStorage.feature:66
cliLocalStorage/propfindOnLocalStorage.feature:80
cliLocalStorage/propfindOnLocalStorage.feature:81
cliLocalStorage/propfindOnLocalStorageOc10Issue39470.feature:31
cliLocalStorage/propfindOnLocalStorageOc10Issue39470.feature:32
cliLocalStorage/propfindOnLocalStorageOc10Issue39470.feature:53
cliLocalStorage/propfindOnLocalStorageOc10Issue39470.feature:54

Feature: get file info using PROPFIND

  Background:                                                                                                    # /var/www/owncloud/testrunner/tests/acceptance/features/cliLocalStorage/propfindOnLocalStorage.feature:4
    Given these users have been created with default attributes and without skeleton files:                      # FeatureContext::theseUsersHaveBeenCreatedWithDefaultAttributesAndWithoutSkeletonFiles()
      | username |
      | Alice    |
      | Brian    |
    And the administrator has created the local storage mount "local_storage2"                                   # OccContext::theAdministratorHasCreatedTheLocalStorageMountUsingTheOccCommand()
    And the administrator has created the local storage mount "local_storage3"                                   # OccContext::theAdministratorHasCreatedTheLocalStorageMountUsingTheOccCommand()
    And user "Alice" has uploaded file with content "some data" to "/local_storage2/textfile0.txt"               # FeatureContext::userHasUploadedAFileWithContentTo()
    And user "Alice" has created folder "/local_storage2/simple-folder"                                          # FeatureContext::userHasCreatedFolder()
    And user "Alice" has uploaded file with content "some data" to "/local_storage2/simple-folder/textfile1.txt" # FeatureContext::userHasUploadedAFileWithContentTo()
    And user "Alice" has created folder "/local_storage3/PARENT"                                                 # FeatureContext::userHasCreatedFolder()
    And user "Alice" has created folder "/FOLDER"                                                                # FeatureContext::userHasCreatedFolder()
    And user "Alice" has uploaded file with content "some data" to "/local_storage3/PARENT/PARENT.txt"           # FeatureContext::userHasUploadedAFileWithContentTo()

  Scenario Outline: list files on root folder with external storage with depth 1     # /var/www/owncloud/testrunner/tests/acceptance/features/cliLocalStorage/propfindOnLocalStorage.feature:19
    Given using <dav_version> DAV path                                               # FeatureContext::usingOldOrNewDavPath()
    When user "Alice" lists the resources in "/" with depth "1" using the WebDAV API # FeatureContext::userListsTheResourcesInPathWithDepthUsingTheWebdavApi()
    Then the HTTP status code should be "207"                                        # FeatureContext::thenTheHTTPStatusCodeShouldBe()
    And the propfind result of user "Alice" should contain only these entries:       # FeatureContext::thePropfindResultShouldContainOnlyEntries()
      | /               |
      | /local_storage2 |
      | /local_storage  |
      | /local_storage3 |
      | /FOLDER         |

    Examples:
      | dav_version |
      | old         |
      | new         |
        HTTP status code was not 201 or 204 while trying to upload file '/local_storage2/textfile0.txt' for user 'Alice'
        Failed asserting that an array contains 503.

  Scenario Outline: list files on root folder with external storage using depth infinity    # /var/www/owncloud/testrunner/tests/acceptance/features/cliLocalStorage/propfindOnLocalStorage.feature:34
    Given using <dav_version> DAV path                                                      # FeatureContext::usingOldOrNewDavPath()
    When user "Alice" lists the resources in "/" with depth "infinity" using the WebDAV API # FeatureContext::userListsTheResourcesInPathWithDepthUsingTheWebdavApi()
    Then the HTTP status code should be "207"                                               # FeatureContext::thenTheHTTPStatusCodeShouldBe()
    And the propfind result of user "Alice" should contain only these entries:              # FeatureContext::thePropfindResultShouldContainOnlyEntries()
      | /                                           |
      | /local_storage2                             |
      | /local_storage                              |
      | /local_storage3                             |
      | /FOLDER                                     |
      | /local_storage3/PARENT                      |
      | /local_storage3/PARENT/PARENT.txt           |
      | /local_storage2/textfile0.txt               |
      | /local_storage2/simple-folder               |
      | /local_storage2/simple-folder/textfile1.txt |

    Examples:
      | dav_version |
      | old         |
        HTTP status code was not 201 or 204 while trying to upload file '/local_storage2/textfile0.txt' for user 'Alice'
        Failed asserting that an array contains 503.
      | new         |
        HTTP status code was not 201 or 204 while trying to upload file '/local_storage2/textfile0.txt' for user 'Alice'
        Failed asserting that an array contains 503.

https://drone.owncloud.com/owncloud/user_ldap/3689/142/10

{"reqId":"n9H0t1iPXADfk60159Pi","level":4,"time":"2022-01-02T00:45:41+00:00","remoteAddr":"192.168.19.7","user":"Alice","app":"webdav","method":"PUT",
"url":"\/remote.php\/webdav\/local_storage2\/textfile0.txt",
"message":"Exception: HTTP\/1.1 503 Encryption not ready: multikeydecrypt with share key failed:error:0909006C:PEM routines:get_name:no start line: 
{\"Exception\":\"Sabre\\\\DAV\\\\Exception\\\\ServiceUnavailable\",
\"Message\":\"Encryption not ready: multikeydecrypt with share key failed:error:0909006C:PEM routines:get_name:no start line\",\"Code\":0,\"Trace\":\"
#0 \\\/var\\\/www\\\/owncloud\\\/server\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php(243): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->convertToSabreException(Object(OCA\\\\Encryption\\\\Exceptions\\\\MultiKeyDecryptException))\\n
owncloud/user_ldap#1 \\\/var\\\/www\\\/owncloud\\\/server\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php(173): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->put(Resource id owncloud/user_ldap#549)\\n
owncloud/user_ldap#2 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(1098): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->createFile('textfile0.txt', Resource id owncloud/user_ldap#549)\\n
owncloud/user_ldap#3 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(504): Sabre\\\\DAV\\\\Server->createFile('local_storage2\\\/...', Resource id owncloud/user_ldap#549, NULL)\\n
owncloud/user_ldap#4 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/event\\\/lib\\\/WildcardEmitterTrait.php(89): Sabre\\\\DAV\\\\CorePlugin->httpPut(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n
owncloud/user_ldap#5 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(472): Sabre\\\\DAV\\\\Server->emit('method:PUT', Array)\\n
owncloud/user_ldap#6 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(253): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n
owncloud/user_ldap#7 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(321): Sabre\\\\DAV\\\\Server->start()\\n
owncloud/user_ldap#8 \\\/var\\\/www\\\/owncloud\\\/server\\\/apps\\\/dav\\\/appinfo\\\/v1\\\/webdav.php(67): Sabre\\\\DAV\\\\Server->exec()\\n
owncloud/user_ldap#9 \\\/var\\\/www\\\/owncloud\\\/server\\\/remote.php(165): require_once('\\\/var\\\/www\\\/ownclo...')\\n
owncloud/user_ldap#10 {main}\",\"File\":\"\\\/var\\\/www\\\/owncloud\\\/server\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php\",\"Line\":696}"}

Notes:

• the tests pass with user_ldap and master-key encryption https://drone.owncloud.com/owncloud/user_ldap/3690/167/16
• the first scenario is passing, so there might be some problem with deleting and re-creating the local storage between scenarios

[phil-davis]

These tests fail in encryption CI with user-key encryption:
See test PR #319
https://drone.owncloud.com/owncloud/encryption/2254/55/13

runsh: Total unexpected failed scenarios throughout the test run:
cliLocalStorage/propfindOnLocalStorage.feature:32
cliLocalStorage/propfindOnLocalStorage.feature:51
cliLocalStorage/propfindOnLocalStorage.feature:52
cliLocalStorage/propfindOnLocalStorage.feature:65
cliLocalStorage/propfindOnLocalStorage.feature:66
cliLocalStorage/propfindOnLocalStorage.feature:80
cliLocalStorage/propfindOnLocalStorage.feature:81
cliLocalStorage/propfindOnLocalStorageOc10Issue39470.feature:31
cliLocalStorage/propfindOnLocalStorageOc10Issue39470.feature:32
cliLocalStorage/propfindOnLocalStorageOc10Issue39470.feature:53
cliLocalStorage/propfindOnLocalStorageOc10Issue39470.feature:54

So this is a user-key encryption issue. I will transfer the issue.

[saw-jan]

Steps: (core latest, coreRC1)

1. Enable encryption with user-specific key
2. Run localStorage cli tests

I looked through the issue and the following are my findings:

• first test gets passed
• the later tests will fail in step user "Alice" has uploaded file with content "some data" to "/local_storage2/textfile0.txt" with 503 status code
  server log:

{"reqId":"n9H0t1iPXADfk60159Pi","level":4,"time":"2022-01-02T00:45:41+00:00","remoteAddr":"192.168.19.7","user":"Alice","app":"webdav","method":"PUT",
"url":"\/remote.php\/webdav\/local_storage2\/textfile0.txt",
"message":"Exception: HTTP\/1.1 503 Encryption not ready: multikeydecrypt with share key failed:error:0909006C:PEM routines:get_name:no start line: 
{\"Exception\":\"Sabre\\\\DAV\\\\Exception\\\\ServiceUnavailable\",
\"Message\":\"Encryption not ready: multikeydecrypt with share key failed:error:0909006C:PEM routines:get_name:no start line\",\"Code\":0,\"Trace\":\"
#0 \\\/var\\\/www\\\/owncloud\\\/server\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php(243): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->convertToSabreException(Object(OCA\\\\Encryption\\\\Exceptions\\\\MultiKeyDecryptException))\\n
owncloud/user_ldap#1 \\\/var\\\/www\\\/owncloud\\\/server\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/Directory.php(173): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\File->put(Resource id owncloud/user_ldap#549)\\n
owncloud/user_ldap#2 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(1098): OCA\\\\DAV\\\\Connector\\\\Sabre\\\\Directory->createFile('textfile0.txt', Resource id owncloud/user_ldap#549)\\n
owncloud/user_ldap#3 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/CorePlugin.php(504): Sabre\\\\DAV\\\\Server->createFile('local_storage2\\\/...', Resource id owncloud/user_ldap#549, NULL)\\n
owncloud/user_ldap#4 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/event\\\/lib\\\/WildcardEmitterTrait.php(89): Sabre\\\\DAV\\\\CorePlugin->httpPut(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n
owncloud/user_ldap#5 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(472): Sabre\\\\DAV\\\\Server->emit('method:PUT', Array)\\n
owncloud/user_ldap#6 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(253): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n
owncloud/user_ldap#7 \\\/var\\\/www\\\/owncloud\\\/server\\\/lib\\\/composer\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(321): Sabre\\\\DAV\\\\Server->start()\\n
owncloud/user_ldap#8 \\\/var\\\/www\\\/owncloud\\\/server\\\/apps\\\/dav\\\/appinfo\\\/v1\\\/webdav.php(67): Sabre\\\\DAV\\\\Server->exec()\\n
owncloud/user_ldap#9 \\\/var\\\/www\\\/owncloud\\\/server\\\/remote.php(165): require_once('\\\/var\\\/www\\\/ownclo...')\\n
owncloud/user_ldap#10 {main}\",\"File\":\"\\\/var\\\/www\\\/owncloud\\\/server\\\/apps\\\/dav\\\/lib\\\/Connector\\\/Sabre\\\/File.php\",\"Line\":696}"}

Checks:

• created local-storage folders have been deleted after a test scenario ends
• server shows no local storage after a test scenario ends
• getting local storages from cli (occ files_external:list) returns No admin mounts configured after a test scenario ends

Looks like the test code is doing cleanup properly.
Cannot find what was causing the problem.

CC @phil-davis

[phil-davis]

Thanks @saw-jan

It seems that if we create a local storage mount, use it, then delete it (and delete users), then create the local storage again, make it available to some user. Then when the user tries to upload to that storage they get this 503 Encryption not ready failure.

Maybe there is a simpler sequence that will cause this to happen?

I will ping developers about this and see if they need more investigation or...

[phil-davis]

Note: https://drone.owncloud.com/owncloud/user_ldap/3710/142/16

user-key encryption plus user_ldap gets run each night, and of course it fails because of this issue.

I will sort out some relevant skipping so we can get CI runs to to pass.

FYI, the pipeline runs with these filter tags:

~@skipWhenTestingRemoteSystems&&
~@skipOnAllVersionsGreaterThanOcV10.8.0&&
~@skipOnOcV10&&
~@skipOnOcV10.9&&
~@skipOnOcV10.9.1&&
~@skipOnLDAP&&
~@skip&&
~@skipOnEncryption&&
~@skipOnEncryptionType:user-keys&&
~@skip&&
~@app-required&&
~@dbConversion&&
@cli

I will add @skipOnEncryptionType:user-keys to the core scenarios.