Edit the main file with WOPI, see related logs:
2018-11-07T10:31:40,988 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-4] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 operation=CheckFileInfo 2018-11-07T10:31:40,989 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-4] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 operation=CheckFileInfo status=200 body={BreadcrumbBrandUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/, SupportsRename=true, Size=66318, BaseFileName=article_653967.docx, CloseUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8, UserFriendlyName=Joe DiMaggio, SupportsGetLock=true, OwnerId=joe, Version=0.64, UserCanRename=true, UserCanNotWriteRelative=false, HostViewUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/view/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/file:content, IsAnonymousUser=false, FileVersionUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8, DownloadUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/nxfile/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/file:content/article_653967.docx?changeToken=357-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/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/file:content, BreadcrumbBrandName=Nuxeo Platform, BreadcrumbFolderName=WOPI} 2018-11-07T10:31:41,325 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-9] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 operation=Lock headers={X-WOPI-Lock={"S":"c85fec87-cc91-4e9b-aa70-ab56a23549f4","F":4}, X-WOPI-OldLock=null} 2018-11-07T10:31:41,326 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-9] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 Document isn't locked or has another WOPI lock 2018-11-07T10:31:41,327 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-9] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 Document isn't locked 2018-11-07T10:31:41,327 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-9] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Nuxeo action: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 Locking document 2018-11-07T10:31:41,341 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-9] [org.nuxeo.wopi.lock.LockHelper] Locking: fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 Adding lock {"S":"c85fec87-cc91-4e9b-aa70-ab56a23549f4","F":4} 2018-11-07T10:31:41,346 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-9] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 operation=Lock status=200 headers={X-WOPI-ItemVersion=0.64} 2018-11-07T10:31:41,355 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-8] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 operation=GetFile headers={X-WOPI-MaxExpectedSize=2147483647} 2018-11-07T10:31:41,356 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-8] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 operation=GetFile status=200 headers={X-WOPI-ItemVersion=0.64} 2018-11-07T10:31:42,030 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 operation=Lock headers={X-WOPI-Lock={"S":"c85fec87-cc91-4e9b-aa70-ab56a23549f4","F":4,"E":1,"C":"DF1","M":"df-15184ed4ac0e","P":"18C75DD5-853B-4156-8674-1314D6B08844","W":"df-4b5b3d19eb18","B":"69EBC40C-54D8-49BE-AC55-03AB68264E32"}, X-WOPI-OldLock={"S":"c85fec87-cc91-4e9b-aa70-ab56a23549f4","F":4}} 2018-11-07T10:31:42,032 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 X-WOPI-OldLock header is equal to current WOPI lock 2018-11-07T10:31:42,033 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.wopi.lock.LockHelper] Locking: fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 Updating lock {"S":"c85fec87-cc91-4e9b-aa70-ab56a23549f4","F":4,"E":1,"C":"DF1","M":"df-15184ed4ac0e","P":"18C75DD5-853B-4156-8674-1314D6B08844","W":"df-4b5b3d19eb18","B":"69EBC40C-54D8-49BE-AC55-03AB68264E32"} 2018-11-07T10:31:42,034 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=file:content user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZTpjb250ZW50 operation=Lock status=200
Edit an attachement with WOPI, see related logs:
2018-11-07T10:32:13,892 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-2] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=CheckFileInfo 2018-11-07T10:32:13,896 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-2] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=CheckFileInfo status=200 body={BreadcrumbBrandUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/, SupportsRename=true, Size=52103, BaseFileName=308 SW Bus Pack.docx, CloseUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8, UserFriendlyName=Joe DiMaggio, SupportsGetLock=true, OwnerId=joe, Version=0.64, UserCanRename=true, UserCanNotWriteRelative=false, HostViewUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/view/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/files:files/0/file, IsAnonymousUser=false, FileVersionUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8, DownloadUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/nxfile/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/files:files/0/file/308%20SW%20Bus%20Pack.docx?changeToken=357-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/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/files:files/0/file, BreadcrumbBrandName=Nuxeo Platform, BreadcrumbFolderName=WOPI} 2018-11-07T10:32:14,228 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-1] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=Lock headers={X-WOPI-Lock={"S":"94856614-2a56-457a-b02f-41f2e3b01ef5","F":4}, X-WOPI-OldLock=null} 2018-11-07T10:32:14,230 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-1] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl Document isn't locked or has another WOPI lock 2018-11-07T10:32:14,231 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-1] [org.nuxeo.wopi.lock.LockHelper] Locking: fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl Adding lock {"S":"94856614-2a56-457a-b02f-41f2e3b01ef5","F":4} 2018-11-07T10:32:14,243 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-1] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=Lock status=200 headers={X-WOPI-ItemVersion=0.64} 2018-11-07T10:32:14,254 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-6] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=CheckFileInfo 2018-11-07T10:32:14,256 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-6] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=CheckFileInfo status=200 body={BreadcrumbBrandUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/, SupportsRename=true, Size=52103, BaseFileName=308 SW Bus Pack.docx, CloseUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8, UserFriendlyName=Joe DiMaggio, SupportsGetLock=true, OwnerId=joe, Version=0.64, UserCanRename=true, UserCanNotWriteRelative=false, HostViewUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/view/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/files:files/0/file, IsAnonymousUser=false, FileVersionUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8, DownloadUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/nxfile/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/files:files/0/file/308%20SW%20Bus%20Pack.docx?changeToken=357-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/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/files:files/0/file, BreadcrumbBrandName=Nuxeo Platform, BreadcrumbFolderName=WOPI} 2018-11-07T10:32:14,520 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=Lock headers={X-WOPI-Lock={"S":"94856614-2a56-457a-b02f-41f2e3b01ef5","F":4,"E":1,"C":"DF1","M":"df-c3797902412e","P":"54EE3058-6B34-4F0A-88EE-482C7D5AFFB4","W":"df-15184ed4ac0e","B":"4282934A-6F26-468D-8269-4B22F83509B8"}, X-WOPI-OldLock={"S":"94856614-2a56-457a-b02f-41f2e3b01ef5","F":4}} 2018-11-07T10:32:14,523 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl Document isn't locked or has another WOPI lock 2018-11-07T10:32:14,523 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl X-WOPI-OldLock header is present 2018-11-07T10:32:14,524 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=Lock status=409 headers={X-WOPI-Lock=} 2018-11-07T10:32:14,546 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=GetFile headers={X-WOPI-MaxExpectedSize=2147483647} 2018-11-07T10:32:14,547 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-7] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=GetFile status=200 headers={X-WOPI-ItemVersion=0.64} 2018-11-07T10:32:16,879 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-4] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=GetLock 2018-11-07T10:32:16,880 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-4] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=GetLock status=200 headers={X-WOPI-Lock={"S":"94856614-2a56-457a-b02f-41f2e3b01ef5","F":4}}
Office Online displays the "Sorry, your session expired. Please refresh the page to continue" message.
At this point, 2 WOPI locks exist in the DB, one for the main file and one for the attachement since the first call to Lock succeeded.
Yet, the second call to Lock supposed to unlock and relock fails with a conflict response considering that the file is unlocked, see https://wopirest.readthedocs.io/en/latest/files/UnlockAndRelock.html:
... or if the file is unlocked, the host must return a “lock mismatch” response (409 Conflict)
=> UnlockAndRelock shouldn't return 409 Conflict if the document is locked and has another WOPI lock.
We should better distinguish these 2 cases:
- Document is unlocked.
- Document has another WOPI lock.
As a side effect, when trying to refresh, we get an Office Online error and these server logs:
2018-11-07T10:32:56,144 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-8] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=CheckFileInfo 2018-11-07T10:32:56,148 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-8] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=CheckFileInfo status=200 body={BreadcrumbBrandUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/, SupportsRename=true, Size=52103, BaseFileName=308 SW Bus Pack.docx, CloseUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8, UserFriendlyName=Joe DiMaggio, SupportsGetLock=true, OwnerId=joe, Version=0.64, UserCanRename=true, UserCanNotWriteRelative=false, HostViewUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/wopi/view/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/files:files/0/file, IsAnonymousUser=false, FileVersionUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/ui/#!/doc/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8, DownloadUrl=https://ataillefer-wopi.nuxeo.com/nuxeo/nxfile/default/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/files:files/0/file/308%20SW%20Bus%20Pack.docx?changeToken=357-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/fefddf7c-20bc-439d-bac9-a2eb31fe41d8/files:files/0/file, BreadcrumbBrandName=Nuxeo Platform, BreadcrumbFolderName=WOPI} 2018-11-07T10:32:56,521 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=Lock headers={X-WOPI-Lock={"S":"3f2134ea-caa3-4b7f-b40b-92fb367791c2","F":4}, X-WOPI-OldLock=null} 2018-11-07T10:32:56,526 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Condition: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl Document isn't locked or has another WOPI lock 2018-11-07T10:32:56,528 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.wopi.lock.LockHelper] Locking: fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl Adding lock {"S":"3f2134ea-caa3-4b7f-b40b-92fb367791c2","F":4} 2018-11-07T10:32:56,532 ERROR [WOPI_http-nio-0.0.0.0-8080-exec-10] [org.nuxeo.ecm.webengine.app.WebEngineExceptionMapper] org.nuxeo.ecm.directory.DirectoryException: Entry with id ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl already exists org.nuxeo.ecm.directory.DirectoryException: Entry with id ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl already exists at org.nuxeo.ecm.directory.sql.SQLSession.createEntryWithoutReferences(SQLSession.java:682) ~[nuxeo-platform-directory-sql-10.3-SNAPSHOT.jar:?] at org.nuxeo.ecm.directory.BaseSession.createEntry(BaseSession.java:363) ~[nuxeo-platform-directory-api-10.3-SNAPSHOT.jar:?] at org.nuxeo.wopi.lock.LockHelper.lambda$addLock$0(LockHelper.java:85) ~[nuxeo-wopi-10.3-SNAPSHOT.jar:?] at org.nuxeo.wopi.lock.LockHelper.lambda$doPrivilegedOnLockDirectory$9(LockHelper.java:183) ~[nuxeo-wopi-10.3-SNAPSHOT.jar:?] at org.nuxeo.runtime.api.Framework.doPrivileged(Framework.java:260) ~[nuxeo-runtime-10.3-SNAPSHOT.jar:?] at org.nuxeo.wopi.lock.LockHelper.doPrivilegedOnLockDirectory(LockHelper.java:181) ~[nuxeo-wopi-10.3-SNAPSHOT.jar:?] at org.nuxeo.wopi.lock.LockHelper.addLock(LockHelper.java:78) ~[nuxeo-wopi-10.3-SNAPSHOT.jar:?] at org.nuxeo.wopi.lock.LockHelper.addLock(LockHelper.java:70) ~[nuxeo-wopi-10.3-SNAPSHOT.jar:?] at org.nuxeo.wopi.jaxrs.FilesEndpoint.lock(FilesEndpoint.java:280) ~[nuxeo-wopi-10.3-SNAPSHOT.jar:?] at org.nuxeo.wopi.jaxrs.FilesEndpoint.doPost(FilesEndpoint.java:236) ~[nuxeo-wopi-10.3-SNAPSHOT.jar:?] at sun.reflect.GeneratedMethodAccessor158.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_172] at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_172] at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60) ~[jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$ObjectOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:258) ~[jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75) ~[jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302) ~[jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.uri.rules.SubLocatorRule.accept(SubLocatorRule.java:137) ~[jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108) ~[jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84) ~[jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1542) ~[jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1473) [jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1419) [jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1409) [jersey-server-1.19.4.jar:1.19.4] at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:409) [jersey-servlet-1.19.4.jar:1.19.4] at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:558) [jersey-servlet-1.19.4.jar:1.19.4] at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:733) [jersey-servlet-1.19.4.jar:1.19.4] at org.nuxeo.ecm.webengine.app.jersey.WebEngineServlet.containerService(WebEngineServlet.java:72) [nuxeo-webengine-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.ecm.webengine.app.jersey.WebEngineServlet.service(WebEngineServlet.java:56) [nuxeo-webengine-core-10.3-SNAPSHOT.jar:?] at javax.servlet.http.HttpServlet.service(HttpServlet.java:741) [servlet-api.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) [tomcat-websocket.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.elasticsearch.ElasticSearchFilter.doFilter(ElasticSearchFilter.java:55) [nuxeo-elasticsearch-core-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.webengine.jaxrs.session.SessionCleanupFilter.run(SessionCleanupFilter.java:50) [nuxeo-webengine-jaxrs-10.3-SNAPSHOT.jar:?] at org.nuxeo.ecm.webengine.jaxrs.HttpFilter.doFilter(HttpFilter.java:49) [nuxeo-webengine-jaxrs-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.webengine.app.WebContextFilter.doFilter(WebContextFilter.java:56) [nuxeo-webengine-core-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.webengine.jaxrs.context.RequestContextFilter.run(RequestContextFilter.java:48) [nuxeo-webengine-jaxrs-10.3-SNAPSHOT.jar:?] at org.nuxeo.ecm.webengine.jaxrs.HttpFilter.doFilter(HttpFilter.java:49) [nuxeo-webengine-jaxrs-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.webengine.app.HeaderFixFilter.run(HeaderFixFilter.java:62) [nuxeo-webengine-core-10.3-SNAPSHOT.jar:?] at org.nuxeo.ecm.webengine.jaxrs.HttpFilter.doFilter(HttpFilter.java:49) [nuxeo-webengine-jaxrs-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.platform.web.common.requestcontroller.filter.NuxeoThreadTrackerFilter.doFilter(NuxeoThreadTrackerFilter.java:43) [nuxeo-platform-web-common-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.platform.web.common.requestcontroller.filter.NuxeoStandbyFilter.doFilter(NuxeoStandbyFilter.java:67) [nuxeo-platform-web-common-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.core.management.jtajca.internal.Log4jWebFilter.doFilter(Log4jWebFilter.java:69) [nuxeo-core-management-jtajca-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.platform.ui.web.rest.FancyURLFilter.doFilter(FancyURLFilter.java:120) [nuxeo-platform-ui-web-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.platform.web.common.requestcontroller.filter.NuxeoRequestControllerFilter.doFilter(NuxeoRequestControllerFilter.java:134) [nuxeo-platform-web-common-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doFilterInternal(NuxeoAuthenticationFilter.java:631) [nuxeo-platform-web-common-10.3-SNAPSHOT.jar:?] at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doFilter(NuxeoAuthenticationFilter.java:427) [nuxeo-platform-web-common-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.platform.web.common.requestcontroller.filter.NuxeoCorsCsrfFilter.doFilter(NuxeoCorsCsrfFilter.java:160) [nuxeo-platform-web-common-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.platform.web.common.exceptionhandling.NuxeoExceptionFilter.doFilter(NuxeoExceptionFilter.java:67) [nuxeo-platform-web-common-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.nuxeo.ecm.platform.web.common.encoding.NuxeoEncodingFilter.doFilter(NuxeoEncodingFilter.java:64) [nuxeo-platform-web-common-10.3-SNAPSHOT.jar:?] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) [catalina.jar:9.0.12] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) [catalina.jar:9.0.12] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199) [catalina.jar:9.0.12] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) [catalina.jar:9.0.12] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:490) [catalina.jar:9.0.12] at org.apache.catalina.valves.rewrite.RewriteValve.invoke(RewriteValve.java:277) [catalina.jar:9.0.12] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) [catalina.jar:9.0.12] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) [catalina.jar:9.0.12] at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:668) [catalina.jar:9.0.12] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) [catalina.jar:9.0.12] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) [catalina.jar:9.0.12] at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:408) [tomcat-coyote.jar:9.0.12] at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) [tomcat-coyote.jar:9.0.12] at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:770) [tomcat-coyote.jar:9.0.12] at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1415) [tomcat-coyote.jar:9.0.12] at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-coyote.jar:9.0.12] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_172] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_172] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-util.jar:9.0.12] at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172] 2018-11-07T10:32:56,860 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-5] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Request: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=GetFile headers={X-WOPI-MaxExpectedSize=2147483647} 2018-11-07T10:32:56,864 DEBUG [WOPI_http-nio-0.0.0.0-8080-exec-5] [org.nuxeo.wopi.jaxrs.FilesEndpoint] Response: repository=default docId=fefddf7c-20bc-439d-bac9-a2eb31fe41d8 xpath=files:files/0/file user=joe fileId=ZGVmYXVsdC9mZWZkZGY3Yy0yMGJjLTQzOWQtYmFjOS1hMmViMzFmZTQxZDgvZmlsZXM6ZmlsZXMvMC9maWxl operation=GetFile status=200 headers={X-WOPI-ItemVersion=0.64}
Trying to call LockHelper.addLock twice with the smae file id should never happen, nevertheless, should we make it idempotent to avoid such an error?