[NXP-26175] Failing to edit a Word file twice with WOPI - Nuxeo Issue Tracker

XML

Word

Printable

Details

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

Epic Link:
WOPI
Tags:
- nxfit
Sprint:
nxfit 10.10.2

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

Options
- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

Attachments

screenshot-1.png
27 kB
2018-11-12 16:20

Activity

People

Assignee:

Unassigned

Reporter:

Antoine Taillefer

Participants:

Antoine Taillefer

Votes:

0 Vote for this issue

Watchers:

1 Start watching this issue

Dates

Created:

2018-11-12 16:20

Updated:

2018-11-21 10:41

Resolved:

2018-11-21 10:41

Time Tracking

Estimated:

Not Specified

Remaining:

Logged: