Could not delete files from WebDAV server

warwickmm
Recently I have been seeing the following error upon syncing with the iOS app (169):

"Could not delete 6 file(s) from your WebDAV server."

I do not see any errors when syncing with the desktop app (5.0.97-beta.57+07df7d0de).

I have a Debug ID that is hopefully relevant: D2119658395

I don't see any entries in the Trash on either the iOS or desktop app. How can I remove this error message?
  • warwickmm
    I just tried deleting an additional 3 files from iOS, and now the error is

    "Could not delete 9 file(s) from your WebDAV server."

    The files do appear to have been deleted. When I later synced from the desktop app, the trash is empty (it's empty on iOS as well).

    Is there a know issue with deleting WebDAV files from the iOS app?
  • dstillman
    edited December 21, 2021
    (+0000015): HTTP DELETE http://192.168.[…]:8080/zotero/5XND67FY.prop

    (+0000000): HTTP DELETE http://192.168.[…]:8080/zotero/AB4LTGL2.zip

    (+0000000): HTTP DELETE http://192.168.[…]:8080/zotero/AB4LTGL2.prop

    (+0000000): HTTP DELETE http://192.168.[…]:8080/zotero/5XND67FY.zip

    (+0000030): HTTP DELETE http://192.168.[…]:8080/zotero/5XND67FY.prop failed with 401
    [ERROR] Zotero(+0000000): No Response

    (+0000001): HTTP DELETE http://192.168.[…]:8080/zotero/BK6GCLKA.prop

    (+0000034): HTTP DELETE http://192.168.[…]:8080/zotero/AB4LTGL2.zip failed with 401
    [ERROR] Zotero(+0000000): No Response

    (+0000034): HTTP DELETE http://192.168.[…]:8080/zotero/AB4LTGL2.prop failed with 401
    This suggests that your WebDAV server is returning a 401 Unauthorized for DELETE requests. @michalrentka can look into this and confirm that we're properly sending authenticated requests for these, but if not we'd likely have many more reports. If this is your server, you should check the server logs for these requests.
  • warwickmm
    edited December 21, 2021
    Thanks @dstillman. Regarding the 5XND67FY.prop error you posted above, I see this in my server logs:

    webdav_error.log:7307754:2021/12/20 17:07:23 [info] 13#13: *2064 no user/password was provided for basic authentication, client: 192.168.143.94, server: , request: "DELETE /zotero/5XND67FY.prop HTTP/1.1", host: "192.168.143.224:8080"
  • warwickmm
    Here are some more logs for the AB4LTGL2.zip and AB4LTGL2.prop failures:

    webdav_error.log:7307807:2021/12/20 17:07:23 [info] 13#13: *2065 no user/password was provided for basic authentication, client: 192.168.143.94, server: , request: "DELETE /zotero/AB4LTGL2.zip HTTP/1.1", host: "192.168.143.224:8080"
    webdav_error.log:7307808:2021/12/20 17:07:23 [debug] 13#13: *2065 http finalize request: 401, "/zotero/AB4LTGL2.zip?" a:1, c:1
    webdav_error.log:7307809:2021/12/20 17:07:23 [debug] 13#13: *2065 http special response: 401, "/zotero/AB4LTGL2.zip?"
    webdav_error.log:7307825:2021/12/20 17:07:23 [debug] 13#13: *2065 http output filter "/zotero/AB4LTGL2.zip?"
    webdav_error.log:7307826:2021/12/20 17:07:23 [debug] 13#13: *2065 http copy filter: "/zotero/AB4LTGL2.zip?"
    webdav_error.log:7307829:2021/12/20 17:07:23 [debug] 13#13: *2065 http postpone filter "/zotero/AB4LTGL2.zip?" 0000561206D9DC90
    webdav_error.log:7307837:2021/12/20 17:07:23 [debug] 13#13: *2065 http copy filter: 0 "/zotero/AB4LTGL2.zip?"
    webdav_error.log:7307838:2021/12/20 17:07:23 [debug] 13#13: *2065 http finalize request: 0, "/zotero/AB4LTGL2.zip?" a:1, c:1
    webdav_error.log:7307971:2021/12/20 17:07:23 [info] 13#13: *2067 no user/password was provided for basic authentication, client: 192.168.143.94, server: , request: "DELETE /zotero/AB4LTGL2.prop HTTP/1.1", host: "192.168.143.224:8080"
    webdav_error.log:7307972:2021/12/20 17:07:23 [debug] 13#13: *2067 http finalize request: 401, "/zotero/AB4LTGL2.prop?" a:1, c:1
    webdav_error.log:7307973:2021/12/20 17:07:23 [debug] 13#13: *2067 http special response: 401, "/zotero/AB4LTGL2.prop?"
    webdav_error.log:7307989:2021/12/20 17:07:23 [debug] 13#13: *2067 http output filter "/zotero/AB4LTGL2.prop?"
    webdav_error.log:7307990:2021/12/20 17:07:23 [debug] 13#13: *2067 http copy filter: "/zotero/AB4LTGL2.prop?"
    webdav_error.log:7307993:2021/12/20 17:07:23 [debug] 13#13: *2067 http postpone filter "/zotero/AB4LTGL2.prop?" 0000561206D9DC90
    webdav_error.log:7308001:2021/12/20 17:07:23 [debug] 13#13: *2067 http copy filter: 0 "/zotero/AB4LTGL2.prop?"
    webdav_error.log:7308002:2021/12/20 17:07:23 [debug] 13#13: *2067 http finalize request: 0, "/zotero/AB4LTGL2.prop?" a:1, c:1
  • warwickmm
    Here are some related entries in webdav_access.log:

    192.168.143.94 - - [20/Dec/2021:17:07:23 -0800] "DELETE /zotero/5XND67FY.prop HTTP/1.1" 401 195 "-" "Zotero/169 CFNetwork/1327.0.4 Darwin/21.2.0"
    192.168.143.94 - - [20/Dec/2021:17:07:23 -0800] "DELETE /zotero/5XND67FY.zip HTTP/1.1" 401 195 "-" "Zotero/169 CFNetwork/1327.0.4 Darwin/21.2.0"
    192.168.143.94 - - [20/Dec/2021:17:07:23 -0800] "DELETE /zotero/5XND67FY.prop HTTP/1.1" 401 195 "-" "Zotero/169 CFNetwork/1327.0.4 Darwin/21.2.0"
    192.168.143.94 - - [20/Dec/2021:17:07:23 -0800] "DELETE /zotero/5XND67FY.zip HTTP/1.1" 401 195 "-" "Zotero/169 CFNetwork/1327.0.4 Darwin/21.2.0"


    192.168.143.94 - - [20/Dec/2021:17:07:23 -0800] "DELETE /zotero/AB4LTGL2.zip HTTP/1.1" 401 195 "-" "Zotero/169 CFNetwork/1327.0.4 Darwin/21.2.0"
    192.168.143.94 - - [20/Dec/2021:17:07:23 -0800] "DELETE /zotero/AB4LTGL2.prop HTTP/1.1" 401 195 "-" "Zotero/169 CFNetwork/1327.0.4 Darwin/21.2.0"
    192.168.143.94 - - [20/Dec/2021:17:07:23 -0800] "DELETE /zotero/AB4LTGL2.zip HTTP/1.1" 401 195 "-" "Zotero/169 CFNetwork/1327.0.4 Darwin/21.2.0"
    192.168.143.94 - - [20/Dec/2021:17:07:23 -0800] "DELETE /zotero/AB4LTGL2.prop HTTP/1.1" 401 195 "-" "Zotero/169 CFNetwork/1327.0.4 Darwin/21.2.0"
  • warwickmm
    > "The files do appear to have been deleted."

    My earlier comment might be incorrect. The files don't appear in Zotero's trash (in both the desktop and iOS apps). However, many of these files still appear to exist on the server.
  • warwickmm
    edited December 21, 2021
    I just ran a few more experiments. Using the desktop app, I added a file, moved it to the trash, and emptied the trash. No errors appear in my servers logs. If I add the file and move it to the trash with the desktop app, but then empty the trash using the iOS app, I get errors in the logs:

    2021/12/21 15:26:42 [info] 13#13: *2143 no user/password was provided for basic authentication, client: 192.168.143.94, server: , request: "DELETE /zotero/ZGVUR8UB.zip HTTP/1.1", host: "192.168.143.224:8080"
    2021/12/21 15:26:42 [info] 13#13: *2144 no user/password was provided for basic authentication, client: 192.168.143.94, server: , request: "DELETE /zotero/ZGVUR8UB.prop HTTP/1.1", host: "192.168.143.224:8080"

    The files ZGVUR8UB.zip and ZGVUR8UB.prop still exist on the WebDAV server.

    @dstillman, @michalrentka, let me know if there are more details you'd like me to provide.
  • dstillman
    If you're able to easily log the full headers (ngrep, mitmproxy, Nginx logging), we'd be curious to know if the Authorization header is actually missing or the encoded value is incomplete, as the Nginx error suggests. It looks like that log entry can result from any of the NGX_DECLINED returns here.

    If that's not trivial to do, you can just wait and we'll see if we can reproduce.
  • warwickmm
    Thanks. My attempts to log the full headers just creates empty log files, so I'm not having much luck there. I'll leave it for others to try and reproduce.
  • warwickmm
    I'm not sure if this helps, but the entries in the access log from the desktop app show the username (masked by 'username' below):

    192.168.143.95 - username [21/Dec/2021:15:36:20 -0800] "DELETE /zotero/LE354FCQ.zip HTTP/1.1" 204 0 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101 Firefox/60.0"
    192.168.143.95 - username [21/Dec/2021:15:36:20 -0800] "DELETE /zotero/LE354FCQ.prop HTTP/1.1" 204 0 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101 Firefox/60.0"

    The entries in the access log from the iOS app have an empty entry in the same location (just prior to the timestamp)

    192.168.143.94 - - [21/Dec/2021:17:14:48 -0800] "DELETE /zotero/ZGVUR8UB.prop HTTP/1.1" 401 195 "-" "Zotero/169 CFNetwork/1327.0.4 Darwin/21.2.0"
    192.168.143.94 - - [21/Dec/2021:17:14:48 -0800] "DELETE /zotero/ZGVUR8UB.zip HTTP/1.1" 401 195 "-" "Zotero/169 CFNetwork/1327.0.4 Darwin/21.2.0"
  • dstillman
    This should be fixed in the latest beta. Thanks for reporting.
  • warwickmm
    Confirmed. Thanks for the fast turnaround!
Sign In or Register to comment.