Uploaded image for project: 'Nuxeo Drive '
  1. Nuxeo Drive
  2. NXDRIVE-1824

Resuming a download fails if the temporary file was deleted

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: 4.1.4
    • Fix Version/s: 4.2.0
    • Component/s: Synchronizer

      Description

      Issue

      Resuming a download fails if the temporary file was deleted:

      2019-09-09 10:35:17 22891 140474035803968 INFO     nxdrive.gui.api    Resume download 1 for engine '0b048292d2dc11e9852c001fc69c810a'
      2019-09-09 10:35:17 22891 140474035803968 DEBUG    nxdrive.engine.queue_manager Pushing <DocPair[3] local_path=PosixPath('de/100gb.bin'), local_parent_path=PosixPath('de'), remote_ref='defaultFileSystemItemFactory#default#7a586b58-dc88-45f2-9621-9fb09ad3be6a', local_state='unknown', remote_state='created', pair_state='remotely_created',>
      2019-09-09 10:35:17 22891 140474035803968 DEBUG    nxdrive.engine.queue_manager Pushed to _remote_file_queue, now of size: 1
      2019-09-09 10:35:17 22891 140471577855744 DEBUG    nxdrive.engine.workers Thread END
      2019-09-09 10:35:17 22891 140471577855744 DEBUG    nxdrive.engine.workers Thread END
      2019-09-09 10:35:17 22891 140471577855744 DEBUG    nxdrive.engine.workers Thread END
      2019-09-09 10:35:17 22891 140471569463040 INFO     nxdrive.engine.processor Executing processor on <DocPair[3] local_path=PosixPath('de/100gb.bin'), local_parent_path=PosixPath('de'), remote_ref='defaultFileSystemItemFactory#default#7a586b58-dc88-45f2-9621-9fb09ad3be6a', local_state='unknown', remote_state='created', pair_state='remotely_created',>(0)
      2019-09-09 10:35:17 22891 140471569463040 DEBUG    nxdrive.engine.processor Calling _synchronize_remotely_created() on doc pair <DocPair[3] local_path=PosixPath('de/100gb.bin'), local_parent_path=PosixPath('de'), remote_ref='defaultFileSystemItemFactory#default#7a586b58-dc88-45f2-9621-9fb09ad3be6a', local_state='unknown', remote_state='created', pair_state='remotely_created',>
      2019-09-09 10:35:17 22891 140471569463040 DEBUG    nxdrive.engine.processor Soft locking PosixPath('de/100gb.bin')
      2019-09-09 10:35:17 22891 140471569463040 DEBUG    nxdrive.client.local_client Getting xattr 'ndrive' from PosixPath('/home/tiger-222/Nuxeo Drive/de'): 'defaultSyncRootFolderItemFactory#default#b43cb01d-af6d-4e86-8b50-153478386a46'
      2019-09-09 10:35:17 22891 140471569463040 DEBUG    nxdrive.engine.processor Readonly unlock: unlock on PosixPath('de') with 2
      2019-09-09 10:35:17 22891 140472903247616 DEBUG    watchdog.observers.inotify_buffer in-event <InotifyEvent: src_path=b'/home/tiger-222/Nuxeo Drive', wd=1, mask=IN_ATTRIB|IN_ISDIR, cookie=0, name=Nuxeo Drive>
      2019-09-09 10:35:17 22891 140472928425728 DEBUG    watchdog.observers.inotify_buffer in-event <InotifyEvent: src_path=b'/home/tiger-222/Nuxeo Drive', wd=1, mask=IN_ATTRIB|IN_ISDIR, cookie=0, name=>
      2019-09-09 10:35:17 22891 140471569463040 INFO     nxdrive.engine.processor Creating local file '100gb.bin' in PosixPath('/home/tiger-222/Nuxeo Drive/de')
      2019-09-09 10:35:17 22891 140472911640320 DEBUG    nxdrive.engine.watcher.local_watcher Queueing watchdog: <DirModifiedEvent: src_path='/home/tiger-222/Nuxeo Drive'>
      2019-09-09 10:35:17 22891 140471569463040 DEBUG    nuxeo.client       Calling 'http://127.0.0.1:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with headers={'Content-Type': 'application/json', 'X-NXproperties': '*', 'X-NXDocumentProperties': '*', 'X-NXRepository': 'default', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '4.2.0', 'User-Agent': 'Nuxeo Drive/4.2.0', 'Accept': 'application/json, */*', 'X-User-Id': 'Administrator', 'X-Device-Id': '2bd538fac99411e98630001fc69c810a', 'Cache-Control': 'no-cache'}, params='{"params": {"id": "defaultFileSystemItemFactory#default#7a586b58-dc88-45f2-9621-9fb09ad3be6a", "parentId": "defaultSyncRootFolderItemFactory#default#b43cb01d-af6d-4e86-8b50-153478386a46"}}' and cookies=<RequestsCookieJar[Cookie(version=0, name='X-Authentication-Token', value='9ca153c2-a2fb-404e-940f-bfe7b799a317', port=None, port_specified=False, domain='127.0.0.1', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=False, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]>
      2019-09-09 10:35:17 22891 140472945211136 INFO     nxdrive.engine.watcher.local_watcher Handling watchdog event [modified] on '/home/tiger-222/Nuxeo Drive'
      2019-09-09 10:35:17 22891 140471569463040 DEBUG    nuxeo.client       Response from 'http://127.0.0.1:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem': '{"id":"defaultFileSystemItemFactory#default#7a586b58-dc88-45f2-9621-9fb09ad3be6a","parentId":"defaultSyncRootFolderItemFactory#default#b43cb01d-af6d-4e86-8b50-153478386a46","name":"100gb.bin","folder":false,"creator":"Administrator","lastContributor":"Administrator","creationDate":1567607335771,"lastModificationDate":1567607335771,"canRename":true,"canDelete":true,"lockInfo":null,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#b43cb01d-af6d-4e86-8b50-153478386a46/defaultFileSystemItemFactory#default#7a586b58-dc88-45f2-9621-9fb09ad3be6a","userName":"Administrator","downloadURL":"nxfile/default/7a586b58-dc88-45f2-9621-9fb09ad3be6a/blobholder:0/100gb.bin","digestAlgorithm":"MD5","digest":"8c2cd4442cec477b9dec7276a5971708","canUpdate":true}' with headers {'Set-Cookie': 'X-Authentication-Token=9ca153c2-a2fb-404e-940f-bfe7b799a317; Path=/nuxeo', 'X-Frame-Options': 'SAMEORIGIN', 'X-UA-Compatible': 'IE=10; IE=11', 'Cache-Control': 'no-cache', 'X-Content-Type-Options': 'nosniff', 'Content-Security-Policy': "img-src data: blob: *; default-src blob: *; script-src 'unsafe-inline' 'unsafe-eval' data: *; style-src 'unsafe-inline' *; font-src data: *", 'X-XSS-Protection': '1; mode=block', 'ETag': '"04431989a44333463813ea291e4e63e6"', 'Content-Disposition': "attachment; filename*=UTF-8''file", 'Accept-Ranges': 'bytes', 'Content-Type': 'application/json;charset=UTF-8', 'Content-Length': '811', 'Date': 'Mon, 09 Sep 2019 08:35:17 GMT'} and cookies <RequestsCookieJar[Cookie(version=0, name='X-Authentication-Token', value='9ca153c2-a2fb-404e-940f-bfe7b799a317', port=None, port_specified=False, domain='127.0.0.1', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=False, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]>
      2019-09-09 10:35:17 22891 140471569463040 DEBUG    nxdrive.client.remote_client Downloading file from 'http://127.0.0.1:8080/nuxeo/nxfile/default/7a586b58-dc88-45f2-9621-9fb09ad3be6a/blobholder:0/100gb.bin' to PosixPath('/home/tiger-222/.nuxeo-drive/.tmp/0b048292d2dc11e9852c001fc69c810a/7a586b58-dc88-45f2-9621-9fb09ad3be6a/100gb.bin') with digest='8c2cd4442cec477b9dec7276a5971708'
      2019-09-09 10:35:17 22891 140471569463040 DEBUG    nuxeo.client       Calling 'http://127.0.0.1:8080/nuxeo/nxfile/default/7a586b58-dc88-45f2-9621-9fb09ad3be6a/blobholder:0/100gb.bin' with headers={'Content-Type': 'application/json', 'X-NXDocumentProperties': '*', 'X-NXRepository': 'default', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '4.2.0', 'User-Agent': 'Nuxeo Drive/4.2.0', 'Accept': 'application/json, */*', 'X-User-Id': 'Administrator', 'X-Device-Id': '2bd538fac99411e98630001fc69c810a', 'Cache-Control': 'no-cache'}, params=None and cookies=<RequestsCookieJar[Cookie(version=0, name='X-Authentication-Token', value='9ca153c2-a2fb-404e-940f-bfe7b799a317', port=None, port_specified=False, domain='127.0.0.1', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=False, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]>
      2019-09-09 10:35:25 22891 140471569463040 DEBUG    nuxeo.client       Response from 'http://127.0.0.1:8080/nuxeo/nxfile/default/7a586b58-dc88-45f2-9621-9fb09ad3be6a/blobholder:0/100gb.bin': '<binary data>' with headers {'X-Frame-Options': 'SAMEORIGIN', 'X-UA-Compatible': 'IE=10; IE=11', 'Cache-Control': 'private, max-age=0', 'X-Content-Type-Options': 'nosniff', 'Content-Security-Policy': "img-src data: blob: *; default-src blob: *; script-src 'unsafe-inline' 'unsafe-eval' data: *; style-src 'unsafe-inline' *; font-src data: *", 'X-XSS-Protection': '1; mode=block', 'Expires': 'Mon, 09 Sep 2019 08:35:17 GMT', 'Set-Cookie': 'X-Authentication-Token=9ca153c2-a2fb-404e-940f-bfe7b799a317; Path=/nuxeo', 'ETag': '"8c2cd4442cec477b9dec7276a5971708"', 'Content-Disposition': "attachment; filename*=UTF-8''100gb.bin", 'Accept-Ranges': 'bytes', 'Content-Type': 'application/octet-stream', 'Content-Length': '2610954240', 'Date': 'Mon, 09 Sep 2019 08:35:17 GMT'} and cookies <RequestsCookieJar[Cookie(version=0, name='X-Authentication-Token', value='9ca153c2-a2fb-404e-940f-bfe7b799a317', port=None, port_specified=False, domain='127.0.0.1', domain_specified=False, domain_initial_dot=False, path='/nuxeo', path_specified=True, secure=False, expires=None, discard=True, comment=None, comment_url=None, rest={}, rfc2109=False)]>
      2019-09-09 10:35:25 22891 140471569463040 DEBUG    nxdrive.engine.processor Readonly lock: update lock count on PosixPath('de') to 0
      2019-09-09 10:35:25 22891 140471569463040 DEBUG    nxdrive.engine.processor Readonly lock: relocked PosixPath('de') with 2
      2019-09-09 10:35:25 22891 140472903247616 DEBUG    watchdog.observers.inotify_buffer in-event <InotifyEvent: src_path=b'/home/tiger-222/Nuxeo Drive', wd=1, mask=IN_ATTRIB|IN_ISDIR, cookie=0, name=Nuxeo Drive>
      2019-09-09 10:35:25 22891 140472928425728 DEBUG    watchdog.observers.inotify_buffer in-event <InotifyEvent: src_path=b'/home/tiger-222/Nuxeo Drive', wd=1, mask=IN_ATTRIB|IN_ISDIR, cookie=0, name=>
      2019-09-09 10:35:25 22891 140472911640320 DEBUG    nxdrive.engine.watcher.local_watcher Queueing watchdog: <DirModifiedEvent: src_path='/home/tiger-222/Nuxeo Drive'>
      2019-09-09 10:35:25 22891 140472945211136 INFO     nxdrive.engine.watcher.local_watcher Handling watchdog event [modified] on '/home/tiger-222/Nuxeo Drive'
      2019-09-09 10:35:25 22891 140471569463040 ERROR    nxdrive.engine.processor Unknown error
      Traceback (most recent call last):
        File "engine/processor.py", line 270, in _execute
          sync_handler(doc_pair)
        File "engine/processor.py", line 1178, in _synchronize_remotely_created
          path = self._create_remotely(doc_pair, parent_pair, name)
        File "engine/processor.py", line 1245, in _create_remotely
          tmp_file = self._download_content(doc_pair, os_path)
        File "engine/processor.py", line 1000, in _download_content
          doc_pair_id=doc_pair.id,
        File "client/remote_client.py", line 632, in stream_content
          **kwargs,
        File "client/remote_client.py", line 298, in download
          self.dao.save_download(download)
        File "engine/dao/sqlite.py", line 2039, in save_download
          c.execute(sql, values)
        File "engine/dao/sqlite.py", line 136, in execute
          return super().execute(*args, **kwargs)
      sqlite3.IntegrityError: UNIQUE constraint failed: Downloads.doc_pair
      

      Analyse

      The faultive code is here:

      if download and download.tmpname and not isfile(download.tmpname):
          # Reset if the TMP file does not exist anymore
          download = None
      

      The reset should not be done.

      Fix

      Instead of resetting the entire download, restting only its progression would fix the issue.

        Attachments

          Issue Links

            Activity

              People

              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 30 minutes
                  30m

                    PagerDuty