Uploaded image for project: 'Nuxeo Platform'
  1. Nuxeo Platform
  2. NXP-26175

Failing to edit a Word file twice with WOPI

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Cannot Reproduce
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: WOPI

      Description

      The second time, though the "Saved in Nuxeo" message appears, the changes aren't saved and after a long while (~ 10 minutes) Office displays the attached error.
      See the logs below.

      Open file in edition with WOPI:

      2018-11-12T17:04:55,332 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-5] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=CheckFileInfo
2018-11-12T17:04:55,348 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-5] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=CheckFileInfo status=200 body={BreadcrumbBrandUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/, SupportsRename=true, Size=12605, BaseFileName=P-25.docx, CloseUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a, UserFriendlyName=Joe DiMaggio, SupportsGetLock=true, OwnerId=joe, Version=0.4, UserCanRename=true, UserCanNotWriteRelative=false, HostViewUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/view/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content, IsAnonymousUser=false, FileVersionUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a, DownloadUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/nxfile/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content/P-25.docx?changeToken=20-0, ReadOnly=false, SupportsLocks=true, SupportedShareUrlTypes=[ReadOnly, ReadWrite], SignoutUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/logout, SupportsExtendedLockLength=true, BreadcrumbFolderUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/e0fe9e9d-7137-434e-a486-3f57df0da9e0, UserCanWrite=true, SupportsUpdate=true, UserId=joe, HostEditUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/edit/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content, BreadcrumbBrandName=Nuxeo Platform, BreadcrumbFolderName=WOPI}
2018-11-12T17:04:55,558 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-2] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=CheckFileInfo
2018-11-12T17:04:55,562 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-2] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=CheckFileInfo status=200 body={BreadcrumbBrandUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/, SupportsRename=true, Size=12605, BaseFileName=P-25.docx, CloseUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a, UserFriendlyName=Joe DiMaggio, SupportsGetLock=true, OwnerId=joe, Version=0.4, UserCanRename=true, UserCanNotWriteRelative=false, HostViewUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/view/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content, IsAnonymousUser=false, FileVersionUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a, DownloadUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/nxfile/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content/P-25.docx?changeToken=20-0, ReadOnly=false, SupportsLocks=true, SupportedShareUrlTypes=[ReadOnly, ReadWrite], SignoutUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/logout, SupportsExtendedLockLength=true, BreadcrumbFolderUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/e0fe9e9d-7137-434e-a486-3f57df0da9e0, UserCanWrite=true, SupportsUpdate=true, UserId=joe, HostEditUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/edit/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content, BreadcrumbBrandName=Nuxeo Platform, BreadcrumbFolderName=WOPI}
2018-11-12T17:04:55,704 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-6] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=Lock headers={X-WOPI-Lock={"S":"e0526eef-c7a2-4365-a336-9fa9909ac8ac","F":4}}
2018-11-12T17:04:55,714 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-6] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 Document isn't locked or has another WOPI lock
2018-11-12T17:04:55,715 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-6] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 Document isn't locked
2018-11-12T17:04:55,721 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-6] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Nuxeo action: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 Locking document
2018-11-12T17:04:55,741 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-6] [org.nuxeo.wopi.lock.LockHelper] Locking: fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 Adding lock {"S":"e0526eef-c7a2-4365-a336-9fa9909ac8ac","F":4}
2018-11-12T17:04:55,747 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-6] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=Lock status=200 headers={X-WOPI-ItemVersion=0.4}
2018-11-12T17:04:56,004 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-1] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=GetFile headers={X-WOPI-MaxExpectedSize=2147483647}
2018-11-12T17:04:56,006 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-1] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=GetFile status=200 headers={X-WOPI-ItemVersion=0.4}
2018-11-12T17:04:56,029 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=UnlockAndRelock headers={X-WOPI-Lock={"S":"e0526eef-c7a2-4365-a336-9fa9909ac8ac","F":4,"E":1,"C":"DF1","M":"df-c3797902412e","P":"F856D989-5234-4171-9CCB-3935D899235E","W":"df-15184ed4ac0e","B":"40A0660A-EFF4-4C4D-B082-5CB79D7D26D6"}, X-WOPI-OldLock={"S":"e0526eef-c7a2-4365-a336-9fa9909ac8ac","F":4}}
2018-11-12T17:04:56,031 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 Document is locked
2018-11-12T17:04:56,039 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 X-WOPI-OldLock header is equal to current WOPI lock
2018-11-12T17:04:56,039 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.lock.LockHelper] Locking: fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 Updating lock {"S":"e0526eef-c7a2-4365-a336-9fa9909ac8ac","F":4,"E":1,"C":"DF1","M":"df-c3797902412e","P":"F856D989-5234-4171-9CCB-3935D899235E","W":"df-15184ed4ac0e","B":"40A0660A-EFF4-4C4D-B082-5CB79D7D26D6"}
2018-11-12T17:04:56,049 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=UnlockAndRelock status=200

      Note the first call to Lock then to UnlockAndRelock that updates the WOPI lock.

      Make the first change, less than 30 seconds after we can observe that the file has effectively been updated in Nuxeo and we get:

      2018-11-12T17:05:58,632 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-3] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=GetFile headers={X-WOPI-MaxExpectedSize=2147483647}
2018-11-12T17:05:58,633 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-3] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=GetFile status=200 headers={X-WOPI-ItemVersion=0.4}
2018-11-12T17:05:59,415 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-2] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=PutFile headers={X-WOPI-Lock={"S":"e0526eef-c7a2-4365-a336-9fa9909ac8ac","F":4}}
2018-11-12T17:05:59,416 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-2] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=PutFile status=409 headers={X-WOPI-Lock={"S":"e0526eef-c7a2-4365-a336-9fa9909ac8ac","F":4,"E":1,"C":"DF1","M":"df-c3797902412e","P":"F856D989-5234-4171-9CCB-3935D899235E","W":"df-15184ed4ac0e","B":"40A0660A-EFF4-4C4D-B082-5CB79D7D26D6"}}
2018-11-12T17:05:59,857 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=PutFile headers={X-WOPI-Lock={"S":"e0526eef-c7a2-4365-a336-9fa9909ac8ac","F":4,"E":1,"C":"DF1","M":"df-c3797902412e","P":"F856D989-5234-4171-9CCB-3935D899235E","W":"df-15184ed4ac0e","B":"40A0660A-EFF4-4C4D-B082-5CB79D7D26D6"}}
2018-11-12T17:05:59,857 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 X-WOPI-Lock header is equal to current WOPI lock
2018-11-12T17:05:59,858 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Nuxeo action: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 Updating blob
2018-11-12T17:05:59,910 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=PutFile status=200 headers={X-WOPI-ItemVersion=0.5}

      Note the strange fact that the first call made to PutFile sends the old lock header, receives a 409, then another call is made with the right lock header resulting in a 200.

      Make the second change, then, 3 minutes later:

      2018-11-12T17:09:58,151 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-6] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=CheckFileInfo
2018-11-12T17:09:58,152 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-6] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=CheckFileInfo status=200 body={BreadcrumbBrandUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/, SupportsRename=true, Size=12638, BaseFileName=P-25.docx, CloseUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a, UserFriendlyName=Joe DiMaggio, SupportsGetLock=true, OwnerId=joe, Version=0.5, UserCanRename=true, UserCanNotWriteRelative=false, HostViewUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/view/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content, IsAnonymousUser=false, FileVersionUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a, DownloadUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/nxfile/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content/P-25.docx?changeToken=25-0, ReadOnly=false, SupportsLocks=true, SupportedShareUrlTypes=[ReadOnly, ReadWrite], SignoutUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/logout, SupportsExtendedLockLength=true, BreadcrumbFolderUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/e0fe9e9d-7137-434e-a486-3f57df0da9e0, UserCanWrite=true, SupportsUpdate=true, UserId=joe, HostEditUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/edit/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content, BreadcrumbBrandName=Nuxeo Platform, BreadcrumbFolderName=WOPI}

      6 minutes later:

      2018-11-12T17:15:02,019 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=CheckFileInfo
2018-11-12T17:15:02,021 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=CheckFileInfo status=200 body={BreadcrumbBrandUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/, SupportsRename=true, Size=12638, BaseFileName=P-25.docx, CloseUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a, UserFriendlyName=Joe DiMaggio, SupportsGetLock=true, OwnerId=joe, Version=0.5, UserCanRename=true, UserCanNotWriteRelative=false, HostViewUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/view/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content, IsAnonymousUser=false, FileVersionUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a, DownloadUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/nxfile/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content/P-25.docx?changeToken=25-0, ReadOnly=false, SupportsLocks=true, SupportedShareUrlTypes=[ReadOnly, ReadWrite], SignoutUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/logout, SupportsExtendedLockLength=true, BreadcrumbFolderUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/e0fe9e9d-7137-434e-a486-3f57df0da9e0, UserCanWrite=true, SupportsUpdate=true, UserId=joe, HostEditUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/edit/default/7d4d1726-7c9a-4a70-84ea-ae29568ac00a/file:content, BreadcrumbBrandName=Nuxeo Platform, BreadcrumbFolderName=WOPI}
2018-11-12T17:15:02,860 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-1] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=Unlock headers={X-WOPI-Lock={"S":"e0526eef-c7a2-4365-a336-9fa9909ac8ac"}}
2018-11-12T17:15:02,862 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-1] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=Unlock status=409 headers={X-WOPI-Lock={"S":"e0526eef-c7a2-4365-a336-9fa9909ac8ac","F":4,"E":1,"C":"DF1","M":"df-c3797902412e","P":"F856D989-5234-4171-9CCB-3935D899235E","W":"df-15184ed4ac0e","B":"40A0660A-EFF4-4C4D-B082-5CB79D7D26D6"}}
2018-11-12T17:15:03,095 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-3] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=Unlock headers={X-WOPI-Lock={"S":"e0526eef-c7a2-4365-a336-9fa9909ac8ac","F":4,"E":1,"C":"DF1","M":"df-c3797902412e","P":"F856D989-5234-4171-9CCB-3935D899235E","W":"df-15184ed4ac0e","B":"40A0660A-EFF4-4C4D-B082-5CB79D7D26D6"}}
2018-11-12T17:15:03,099 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-3] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 X-WOPI-Lock header is equal to current WOPI lock
2018-11-12T17:15:03,100 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-3] [org.nuxeo.wopi.lock.LockHelper] Locking: fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 Removing lock
2018-11-12T17:15:03,107 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-3] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 Found no WOPI lock
2018-11-12T17:15:03,107 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-3] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Nuxeo action: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 Unlocking document with a privileged session
2018-11-12T17:15:03,122 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-3] [org.nuxeo.wopi.lock.LockHelper] Locking: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a Document was unlocked in Nuxeo, removing related WOPI locks
2018-11-12T17:15:03,127 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-3] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=Unlock status=200 headers={X-WOPI-ItemVersion=0.5}
2018-11-12T17:15:03,530 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-9] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=GetLock
2018-11-12T17:15:03,531 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-9] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 Document isn't locked
2018-11-12T17:15:03,531 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-9] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=7d4d1726-7c9a-4a70-84ea-ae29568ac00a xpath=file:content user=joe fileId=ZGVmYXVsdC83ZDRkMTcyNi03YzlhLTRhNzAtODRlYS1hZTI5NTY4YWMwMGEvZmlsZTpjb250ZW50 operation=GetLock status=200 headers={X-WOPI-Lock=}

      A first call is made to Unlock with the old lock header, receives a 409, then another call is made with the right lock header resulting in removing the WOPI lock and unlocking the document.

      Maybe (hopefully) linked to the Office dogfooding server?

      Needs to be re-checked on https://wopi-demo.nuxeo.com/:

      • vs the dogfooding Office server
      • vs the prod Office server when went live to see how it behaves
      • with Excel & PowerPoint

        Attachments

          Activity

            People

            • Votes:
              0 Vote for this issue
              Watchers:
              1 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 - 4 hours
                4h