Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

File is still locked after removing or updating share #8273

Closed
ScharfViktor opened this issue Jan 23, 2024 · 11 comments · Fixed by #8529
Closed

File is still locked after removing or updating share #8273

ScharfViktor opened this issue Jan 23, 2024 · 11 comments · Fixed by #8529
Assignees
Labels
Priority:p2-high Escalation, on top of current planning, release blocker Type:Bug
Milestone

Comments

@ScharfViktor
Copy link
Contributor

ScharfViktor commented Jan 23, 2024

related #6368 #8264 #8060

Steps:

Actual: file is still locked. admin cannot open this file
image

After removing access to einstein -> einstein does not unlock the file
<d:owner>OnlyOffice</d:owner><d:timeout>Second-2770</d:timeout>

Screen.Recording.2024-01-23.at.16.54.40.mov

cc @aduffeck

@ScharfViktor ScharfViktor added Type:Bug Priority:p2-high Escalation, on top of current planning, release blocker labels Jan 23, 2024
@2403905
Copy link
Contributor

2403905 commented Jan 25, 2024

The same behavior occurs when the permission has been changed from edit to view. #8060

@ScharfViktor ScharfViktor changed the title File is still locked after removing share File is still locked after removing or updating share Jan 29, 2024
@2403905
Copy link
Contributor

2403905 commented Jan 29, 2024

The logs are from a local setup.

{"time": "2024-01-29T12:48:19.215", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Generating token", "userid": "h2hUDoljlmsylHcky-2c", "fileid": "d3cb393c-f777-4232-9dc5-610e79baf865", "endpoint": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714", "app": "OnlyOffice"}
{"time": "2024-01-29T12:48:19.218", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "d3cb393c-f777-4232-9dc5-610e79baf865", "trace": "cc366dc2abf0c0847c3afe76906b3997", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "2.9"}
{"time": "2024-01-29T12:48:19.219", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Access token generated", "userid": "h2hUDoljlmsylHcky-2c", "wopiuser": "9bb608d6-cb9b-4d4d-adf8-14f39506c714!9bb608d6-cb9b-4d4d-adf8-14f39506c714@https://ocis.owncloud.test", "friendlyname": "Admin", "usertype": "UserType.REGULAR", "mode": "ViewMode.READ_WRITE", "endpoint": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "mtime": "1706532471", "folderurl": "https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865", "appname": "OnlyOffice", "expiration": "1706618899", "token": "ClpJdruyUw6CiMK-i6sI"}
{"time": "2024-01-29T12:48:19.219", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiserver", "msg": "iopOpenInApp: redirecting client", "appurl": "https://onlyoffice.owncloud.test/hosting/wopi/word/edit?WOPISrc=https%3A%2F%2Fwopiserver.owncloud.test%2Fwopi%2Ffiles%2Fa4015be1%2Dc82c%2D4ade%2Db6e3%2D9187b9bad9ba%21ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1"}
{"time": "2024-01-29T12:48:19.245", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Checkfileinfo: client context", "user": "h2hUDoljlmsylHcky-2c", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "ClpJdruyUw6CiMK-i6sI", "client": "172.18.0.5", "deviceId": "None", "reqId": "None", "sessionId": "None", "app": "None", "appEndpoint": "None", "correlationId": "None", "wopits": "63842129299.238"}
{"time": "2024-01-29T12:48:19.248", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "e4d8eed9b3da6e1e20cf42584c1d7a72", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.2"}
{"time": "2024-01-29T12:48:19.252", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Empty value or key not found in getxattr", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "key": "iop.wopi.userinfo.9bb608d6-cb9b-4d4d-adf8-14f39506c714", "trace": "90d76810206bf9324a163f9cca8abe05", "metadata": "{'http://owncloud.org/ns/favorite': '', 'iop.wopi.lastwritetime': '1706532471', 'iop.wopi.userinfo.9bb608d6-cb9b-4d4d-adf8-14f39506c714': ''}"}
{"time": "2024-01-29T12:48:19.252", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopi", "msg": "File metadata response", "token": "ClpJdruyUw6CiMK-i6sI", "metadata": "{'BaseFileName': 'nwe.odt', 'BreadcrumbDocName': 'nwe.odt', 'FileExtension': '.odt', 'HostEditUrl': '_redacted_', 'HostViewUrl': '_redacted_', 'CloseUrl': 'https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865?scrollTo=nwe.odt', 'BreadcrumbFolderUrl': 'https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865?scrollTo=nwe.odt', 'IsAnonymousUser': False, 'UserFriendlyName': 'Admin', 'BreadcrumbFolderName': 'Parent folder', 'DownloadUrl': '_redacted_', 'FileUrl': '_redacted_', 'LicenseCheckForEditIsEnabled': True, 'BreadcrumbBrandName': None, 'BreadcrumbBrandUrl': '_redacted_', 'OwnerId': '9bb608d6-cb9b-4d4d-adf8-14f39506c714@https://ocis.owncloud.test', 'UserId': '9bb608d6-cb9b-4d4d-adf8-14f39506c714@https://ocis.owncloud.test', 'Size': 4730, 'LastModifiedTime': '2024-01-29 12:47:51.000', 'Version': 'v\"1c53173cdb0a76dd7a347ea6603f6ed3\"', 'SupportsExtendedLockLength': True, 'SupportsGetLock': True, 'SupportsUpdate': True, 'UserCanWrite': True, 'SupportsLocks': True, 'SupportsDeleteFile': True, 'ReadOnly': False, 'RestrictedWebViewOnly': False, 'UserCanNotWriteRelative': False, 'SupportsRename': False, 'UserCanRename': False, 'SupportsUserInfo': True, 'FileSharingUrl': '_redacted_'}"}
{"time": "2024-01-29T12:48:19.262", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Lock: client context", "user": "h2hUDoljlmsylHcky-2c", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "ClpJdruyUw6CiMK-i6sI", "client": "172.18.0.5", "deviceId": "None", "reqId": "None", "sessionId": "None", "app": "None", "appEndpoint": "None", "correlationId": "None", "wopits": "63842129299.256"}
{"time": "2024-01-29T12:48:19.264", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked getlock on unlocked or missing file", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt"}
{"time": "2024-01-29T12:48:19.265", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "No lock found", "lockop": "Lock", "user": "h2hUDoljlmsylHcky-2c", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "ClpJdruyUw6CiMK-i6sI"}
{"time": "2024-01-29T12:48:19.267", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "a0445dd991d44259dde7533357ee58d7", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "2.6"}
{"time": "2024-01-29T12:48:19.270", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked setlock", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "value": "opaquelocktoken:797356a8-0500-4ceb-a8a0-c94c8cde7eba VDhFbnE0UnVtQ2dheWI4akV4QlRwdz09", "result": "code: CODE_OK\ntrace: \"756545aebb08264daad91f91ec8fb4b2\"\n"}
{"time": "2024-01-29T12:48:19.277", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked setxattr", "result": "status {\n  code: CODE_OK\n  trace: \"86633d390c768fa1a2c9cd51f679b1cc\"\n}\n"}
{"time": "2024-01-29T12:48:19.277", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Successfully locked", "lockop": "Lock", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "ClpJdruyUw6CiMK-i6sI", "sessionId": "9bb608d6-cb9b-4d4d-adf8-14f39506c714", "lock": "T8Enq4RumCgayb8jExBTpw==", "oldlock": "None", "version": "v\"1c53173cdb0a76dd7a347ea6603f6ed3\""}
{"time": "2024-01-29T12:48:19.864", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiserver", "msg": "iopDownload: returning contents", "client": "172.18.0.8", "endpoint": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "ClpJdruyUw6CiMK-i6sI"}
{"time": "2024-01-29T12:48:19.869", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "readfile: InitiateFileDownloadRes returned", "trace": "0b3b87fb3b7c60a056a1070470867c57", "protocols": "[protocol: \"spaces\"\ndownload_endpoint: \"https://ocis.owncloud.test/data\"\ntoken: \"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA2NjE4ODk5LCJpYXQiOjE3MDY1MzI0OTksInRhcmdldCI6Imh0dHA6Ly9sb2NhbGhvc3Q6OTE1OC9kYXRhL3NwYWNlcy9hNDAxNWJlMS1jODJjLTRhZGUtYjZlMy05MTg3YjliYWQ5YmEkOWJiNjA4ZDYtY2I5Yi00ZDRkLWFkZjgtMTRmMzk1MDZjNzE0JTIxOWJiNjA4ZDYtY2I5Yi00ZDRkLWFkZjgtMTRmMzk1MDZjNzE0L253ZS5vZHQifQ.2GnYqMYoCjoW2w6WD7MpyGe2_ihj3qqla_dYziYfwWc\"\n]"}
/usr/local/lib/python3.11/site-packages/urllib3/connectionpool.py:1095: InsecureRequestWarning: Unverified HTTPS request is being made to host 'ocis.owncloud.test'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#tls-warnings
  warnings.warn(
{"time": "2024-01-29T12:48:19.903", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "File open for read", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.3"}
{"time": "2024-01-29T12:48:19.906", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "104407b2a1413680324d08652e5eee82", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.0"}
=== admin opened -> ok


{"time": "2024-01-29T12:48:52.201", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Unlock: client context", "user": "h2hUDoljlmsylHcky-2c", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "ClpJdruyUw6CiMK-i6sI", "client": "172.18.0.5", "deviceId": "None", "reqId": "None", "sessionId": "None", "app": "None", "appEndpoint": "None", "correlationId": "None", "wopits": "63842129332.189"}
{"time": "2024-01-29T12:48:52.312", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked getlock", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "result": "lock_id: \"opaquelocktoken:797356a8-0500-4ceb-a8a0-c94c8cde7eba VDhFbnE0UnVtQ2dheWI4akV4QlRwdz09\"\ntype: LOCK_TYPE_WRITE\napp_name: \"OnlyOffice\"\nexpiration {\n  seconds: 1706536099\n}\n"}
{"time": "2024-01-29T12:48:52.313", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Retrieved lock", "lockop": "Unlock", "user": "h2hUDoljlmsylHcky-2c", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "fileid": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "lock": "T8Enq4RumCgayb8jExBTpw==", "retrievedlock": "T8Enq4RumCgayb8jExBTpw==", "expTime": "2024-01-29T13:48:19", "token": "ClpJdruyUw6CiMK-i6sI"}
{"time": "2024-01-29T12:48:52.313", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "compareLocks", "lock1": "T8Enq4RumCgayb8jExBTpw==", "lock2": "T8Enq4RumCgayb8jExBTpw==", "result": "True"}
{"time": "2024-01-29T12:48:52.320", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "9822df103ba4110ff4e5aaea8c8e4dea", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "5.3"}
{"time": "2024-01-29T12:48:52.323", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked unlock", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "value": "opaquelocktoken:797356a8-0500-4ceb-a8a0-c94c8cde7eba VDhFbnE0UnVtQ2dheWI4akV4QlRwdz09", "result": "code: CODE_OK\ntrace: \"d517722441b4693a40ef5b891d76055d\"\n"}
{"time": "2024-01-29T12:49:02.835", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Generating token", "userid": "Xtp4D1vAXqW8ltrc9UR8", "fileid": "d3cb393c-f777-4232-9dc5-610e79baf865", "endpoint": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714", "app": "OnlyOffice"}
{"time": "2024-01-29T12:49:02.839", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "d3cb393c-f777-4232-9dc5-610e79baf865", "trace": "15bcdd3f11905fb0559e9f7692c040b2", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.2"}
{"time": "2024-01-29T12:49:02.839", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Access token generated", "userid": "Xtp4D1vAXqW8ltrc9UR8", "wopiuser": "dbe9672d-00d1-476d-85db-8a39b8e807ff!dbe9672d-00d1-476d-85db-8a39b8e807ff@https://ocis.owncloud.test", "friendlyname": "bob", "usertype": "UserType.REGULAR", "mode": "ViewMode.READ_WRITE", "endpoint": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "mtime": "1706532471", "folderurl": "https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865", "appname": "OnlyOffice", "expiration": "1706618942", "token": "pE5PREW9cadmaM6GYpfc"}
{"time": "2024-01-29T12:49:02.839", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiserver", "msg": "iopOpenInApp: redirecting client", "appurl": "https://onlyoffice.owncloud.test/hosting/wopi/word/edit?WOPISrc=https%3A%2F%2Fwopiserver.owncloud.test%2Fwopi%2Ffiles%2Fa4015be1%2Dc82c%2D4ade%2Db6e3%2D9187b9bad9ba%21ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1"}
{"time": "2024-01-29T12:49:02.864", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Checkfileinfo: client context", "user": "Xtp4D1vAXqW8ltrc9UR8", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "pE5PREW9cadmaM6GYpfc", "client": "172.18.0.5", "deviceId": "None", "reqId": "None", "sessionId": "None", "app": "None", "appEndpoint": "None", "correlationId": "None", "wopits": "63842129342.858"}
{"time": "2024-01-29T12:49:02.867", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "6ed2ca1d7e94a757125de9c358a679d9", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.2"}
{"time": "2024-01-29T12:49:02.871", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Empty value or key not found in getxattr", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "key": "iop.wopi.userinfo.dbe9672d-00d1-476d-85db-8a39b8e807ff", "trace": "9b5a088624f4cc309f2e6cdf672487ae", "metadata": "{'http://owncloud.org/ns/favorite': '', 'iop.wopi.lastwritetime': '1706532499', 'iop.wopi.userinfo.dbe9672d-00d1-476d-85db-8a39b8e807ff': ''}"}
{"time": "2024-01-29T12:49:02.871", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopi", "msg": "File metadata response", "token": "pE5PREW9cadmaM6GYpfc", "metadata": "{'BaseFileName': 'nwe.odt', 'BreadcrumbDocName': 'nwe.odt', 'FileExtension': '.odt', 'HostEditUrl': '_redacted_', 'HostViewUrl': '_redacted_', 'CloseUrl': 'https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865?scrollTo=nwe.odt', 'BreadcrumbFolderUrl': 'https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865?scrollTo=nwe.odt', 'IsAnonymousUser': False, 'UserFriendlyName': 'bob', 'BreadcrumbFolderName': 'Parent folder', 'DownloadUrl': '_redacted_', 'FileUrl': '_redacted_', 'LicenseCheckForEditIsEnabled': True, 'BreadcrumbBrandName': None, 'BreadcrumbBrandUrl': '_redacted_', 'OwnerId': '9bb608d6-cb9b-4d4d-adf8-14f39506c714@https://ocis.owncloud.test', 'UserId': 'dbe9672d-00d1-476d-85db-8a39b8e807ff@https://ocis.owncloud.test', 'Size': 4730, 'LastModifiedTime': '2024-01-29 12:47:51.000', 'Version': 'v\"1c53173cdb0a76dd7a347ea6603f6ed3\"', 'SupportsExtendedLockLength': True, 'SupportsGetLock': True, 'SupportsUpdate': True, 'UserCanWrite': True, 'SupportsLocks': True, 'SupportsDeleteFile': True, 'ReadOnly': False, 'RestrictedWebViewOnly': False, 'UserCanNotWriteRelative': False, 'SupportsRename': False, 'UserCanRename': False, 'SupportsUserInfo': True, 'FileSharingUrl': '_redacted_'}"}
{"time": "2024-01-29T12:49:02.878", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Lock: client context", "user": "Xtp4D1vAXqW8ltrc9UR8", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "pE5PREW9cadmaM6GYpfc", "client": "172.18.0.5", "deviceId": "None", "reqId": "None", "sessionId": "None", "app": "None", "appEndpoint": "None", "correlationId": "None", "wopits": "63842129342.873"}
{"time": "2024-01-29T12:49:02.881", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked getlock on unlocked or missing file", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt"}
{"time": "2024-01-29T12:49:02.881", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "No lock found", "lockop": "Lock", "user": "Xtp4D1vAXqW8ltrc9UR8", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "pE5PREW9cadmaM6GYpfc"}
{"time": "2024-01-29T12:49:02.884", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "d2868faa84bfc1486ab17cc1e4b9140e", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "2.4"}
{"time": "2024-01-29T12:49:02.886", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked setlock", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "value": "opaquelocktoken:797356a8-0500-4ceb-a8a0-c94c8cde7eba VDhFbnE0UnVtQ2dheWI4akV4QlRwdz09", "result": "code: CODE_OK\ntrace: \"c67089144c7a7da0da7a8b945c6b4507\"\n"}
{"time": "2024-01-29T12:49:02.898", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked setxattr", "result": "status {\n  code: CODE_OK\n  trace: \"e826c482a27551f9861ed056c5ad3e01\"\n}\n"}
{"time": "2024-01-29T12:49:02.898", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Successfully locked", "lockop": "Lock", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "pE5PREW9cadmaM6GYpfc", "sessionId": "dbe9672d-00d1-476d-85db-8a39b8e807ff", "lock": "T8Enq4RumCgayb8jExBTpw==", "oldlock": "None", "version": "v\"1c53173cdb0a76dd7a347ea6603f6ed3\""}
=== bob opened -> ok


{"time": "2024-01-29T12:49:51.924", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Generating token", "userid": "9ToiBXB7QL84ZPN4h2k0", "fileid": "d3cb393c-f777-4232-9dc5-610e79baf865", "endpoint": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714", "app": "OnlyOffice"}
{"time": "2024-01-29T12:49:51.927", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "d3cb393c-f777-4232-9dc5-610e79baf865", "trace": "b5527c6b9374c0c251a4245648ffc1bc", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.1"}
{"time": "2024-01-29T12:49:51.928", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Access token generated", "userid": "9ToiBXB7QL84ZPN4h2k0", "wopiuser": "9bb608d6-cb9b-4d4d-adf8-14f39506c714!9bb608d6-cb9b-4d4d-adf8-14f39506c714@https://ocis.owncloud.test", "friendlyname": "Admin", "usertype": "UserType.REGULAR", "mode": "ViewMode.READ_WRITE", "endpoint": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "mtime": "1706532471", "folderurl": "https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865", "appname": "OnlyOffice", "expiration": "1706618991", "token": "UUWWCTrRe1sJy8pF6Dn4"}
{"time": "2024-01-29T12:49:51.928", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiserver", "msg": "iopOpenInApp: redirecting client", "appurl": "https://onlyoffice.owncloud.test/hosting/wopi/word/edit?WOPISrc=https%3A%2F%2Fwopiserver.owncloud.test%2Fwopi%2Ffiles%2Fa4015be1%2Dc82c%2D4ade%2Db6e3%2D9187b9bad9ba%21ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1"}
{"time": "2024-01-29T12:49:51.957", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Checkfileinfo: client context", "user": "9ToiBXB7QL84ZPN4h2k0", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "UUWWCTrRe1sJy8pF6Dn4", "client": "172.18.0.5", "deviceId": "None", "reqId": "None", "sessionId": "None", "app": "None", "appEndpoint": "None", "correlationId": "None", "wopits": "63842129391.951"}
{"time": "2024-01-29T12:49:51.961", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "52453b069508f509ccb56fab2f05939e", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.4"}
{"time": "2024-01-29T12:49:51.964", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Empty value or key not found in getxattr", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "key": "iop.wopi.userinfo.9bb608d6-cb9b-4d4d-adf8-14f39506c714", "trace": "8912db4e572024ab2b5c4e8f5157fd5b", "metadata": "{'http://owncloud.org/ns/favorite': '', 'iop.wopi.lastwritetime': '1706532542', 'iop.wopi.userinfo.9bb608d6-cb9b-4d4d-adf8-14f39506c714': ''}"}
{"time": "2024-01-29T12:49:51.965", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopi", "msg": "File metadata response", "token": "UUWWCTrRe1sJy8pF6Dn4", "metadata": "{'BaseFileName': 'nwe.odt', 'BreadcrumbDocName': 'nwe.odt', 'FileExtension': '.odt', 'HostEditUrl': '_redacted_', 'HostViewUrl': '_redacted_', 'CloseUrl': 'https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865?scrollTo=nwe.odt', 'BreadcrumbFolderUrl': 'https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865?scrollTo=nwe.odt', 'IsAnonymousUser': False, 'UserFriendlyName': 'Admin', 'BreadcrumbFolderName': 'Parent folder', 'DownloadUrl': '_redacted_', 'FileUrl': '_redacted_', 'LicenseCheckForEditIsEnabled': True, 'BreadcrumbBrandName': None, 'BreadcrumbBrandUrl': '_redacted_', 'OwnerId': '9bb608d6-cb9b-4d4d-adf8-14f39506c714@https://ocis.owncloud.test', 'UserId': '9bb608d6-cb9b-4d4d-adf8-14f39506c714@https://ocis.owncloud.test', 'Size': 4730, 'LastModifiedTime': '2024-01-29 12:47:51.000', 'Version': 'v\"1c53173cdb0a76dd7a347ea6603f6ed3\"', 'SupportsExtendedLockLength': True, 'SupportsGetLock': True, 'SupportsUpdate': True, 'UserCanWrite': True, 'SupportsLocks': True, 'SupportsDeleteFile': True, 'ReadOnly': False, 'RestrictedWebViewOnly': False, 'UserCanNotWriteRelative': False, 'SupportsRename': False, 'UserCanRename': False, 'SupportsUserInfo': True, 'FileSharingUrl': '_redacted_'}"}
{"time": "2024-01-29T12:49:51.974", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Lock: client context", "user": "9ToiBXB7QL84ZPN4h2k0", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "UUWWCTrRe1sJy8pF6Dn4", "client": "172.18.0.5", "deviceId": "None", "reqId": "None", "sessionId": "None", "app": "None", "appEndpoint": "None", "correlationId": "None", "wopits": "63842129391.967"}
{"time": "2024-01-29T12:49:51.976", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked getlock", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "result": "lock_id: \"opaquelocktoken:797356a8-0500-4ceb-a8a0-c94c8cde7eba VDhFbnE0UnVtQ2dheWI4akV4QlRwdz09\"\ntype: LOCK_TYPE_WRITE\napp_name: \"OnlyOffice\"\nexpiration {\n  seconds: 1706536142\n}\n"}
{"time": "2024-01-29T12:49:51.977", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Retrieved lock", "lockop": "Lock", "user": "9ToiBXB7QL84ZPN4h2k0", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "fileid": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "lock": "T8Enq4RumCgayb8jExBTpw==", "retrievedlock": "T8Enq4RumCgayb8jExBTpw==", "expTime": "2024-01-29T13:49:02", "token": "UUWWCTrRe1sJy8pF6Dn4"}
{"time": "2024-01-29T12:49:51.980", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "c08847c0411f323ce36229189a092c2a", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.1"}
{"time": "2024-01-29T12:49:51.984", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat for getxattr", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.3"}
{"time": "2024-01-29T12:49:51.987", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked setlock on an already locked entity", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "appname": "OnlyOffice", "trace": "720d96daf0b01da0f003b002ee513de0", "reason": "set lock: error: precondition failed: already locked"}
{"time": "2024-01-29T12:49:51.987", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "compareLocks", "lock1": "T8Enq4RumCgayb8jExBTpw==", "lock2": "T8Enq4RumCgayb8jExBTpw==", "result": "True"}
{"time": "2024-01-29T12:49:51.989", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked refreshlock", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "value": "opaquelocktoken:797356a8-0500-4ceb-a8a0-c94c8cde7eba VDhFbnE0UnVtQ2dheWI4akV4QlRwdz09", "result": "code: CODE_OK\ntrace: \"224cd6ccfa64de87a817051d28412ba7\"\n"}
{"time": "2024-01-29T12:49:51.989", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Successfully locked", "lockop": "Lock", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "UUWWCTrRe1sJy8pF6Dn4", "sessionId": "9bb608d6-cb9b-4d4d-adf8-14f39506c714", "lock": "T8Enq4RumCgayb8jExBTpw==", "oldlock": "None", "version": "v\"1c53173cdb0a76dd7a347ea6603f6ed3\""}
=== admin changed bob's permissions rw -> r and opened -> ok


{"time": "2024-01-29T12:51:36.112", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Putfile: client context", "user": "Xtp4D1vAXqW8ltrc9UR8", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "pE5PREW9cadmaM6GYpfc", "client": "172.18.0.5", "deviceId": "None", "reqId": "None", "sessionId": "None", "app": "None", "appEndpoint": "None", "correlationId": "None", "wopits": "63842129496.1"}
{"time": "2024-01-29T12:51:36.116", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked getlock", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "result": "lock_id: \"opaquelocktoken:797356a8-0500-4ceb-a8a0-c94c8cde7eba VDhFbnE0UnVtQ2dheWI4akV4QlRwdz09\"\ntype: LOCK_TYPE_WRITE\napp_name: \"OnlyOffice\"\nexpiration {\n  seconds: 1706536191\n}\n"}
{"time": "2024-01-29T12:51:36.116", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Retrieved lock", "lockop": "Putfile", "user": "Xtp4D1vAXqW8ltrc9UR8", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "fileid": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "lock": "T8Enq4RumCgayb8jExBTpw==", "retrievedlock": "T8Enq4RumCgayb8jExBTpw==", "expTime": "2024-01-29T13:49:51", "token": "pE5PREW9cadmaM6GYpfc"}
{"time": "2024-01-29T12:51:36.116", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "compareLocks", "lock1": "T8Enq4RumCgayb8jExBTpw==", "lock2": "T8Enq4RumCgayb8jExBTpw==", "result": "True"}
{"time": "2024-01-29T12:51:36.117", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopi", "msg": "PutFile", "user": "Xtp4D1vAXqW8ltrc9UR8", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "fileid": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "action": "edit", "token": "pE5PREW9cadmaM6GYpfc"}
{"time": "2024-01-29T12:51:36.120", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat for getxattr", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.3"}
{"time": "2024-01-29T12:51:36.124", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "1153681796cc260ded8be0c87a2f71dc", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "2.9"}
{"time": "2024-01-29T12:51:36.126", "host": "80a14cbac9e3", "level": "ERROR", "process": "wopiserver", "module": "cs3iface", "msg": "Failed to initiateFileUpload on write", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "71a97c8171d9be59ac5a96fab7b2da0d", "code": "8", "reason": "permission denied"}
{"time": "2024-01-29T12:51:36.130", "host": "80a14cbac9e3", "level": "ERROR", "process": "wopiserver", "module": "cs3iface", "msg": "Failed to setxattr", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "key": "iop.wopi.lastwritetime", "trace": "564d682216f01f1f721184178b17f73a", "code": "8", "reason": "set arbitrary metadata: error: permission denied: a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt"}
{"time": "2024-01-29T12:51:36.132", "host": "80a14cbac9e3", "level": "ERROR", "process": "wopiserver", "module": "wopiutils", "msg": "Error writing file, a copy was stored locally for later recovery", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "recoveredpath": "/var/spool/wopirecovery/20240129T125136_editedby_dbe9672d-00d1-476d-85db-8a39b8e807ff_origat_9bb608d6-cb9b-4d4d-adf8-14f39506c714_nwe.odt", "token": "pE5PREW9cadmaM6GYpfc", "error": "set arbitrary metadata: error: permission denied: a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt"}
{"time": "2024-01-29T12:51:36.145", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Unlock: client context", "user": "Xtp4D1vAXqW8ltrc9UR8", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "pE5PREW9cadmaM6GYpfc", "client": "172.18.0.5", "deviceId": "None", "reqId": "None", "sessionId": "None", "app": "None", "appEndpoint": "None", "correlationId": "None", "wopits": "63842129496.138"}
{"time": "2024-01-29T12:51:36.149", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked getlock", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "result": "lock_id: \"opaquelocktoken:797356a8-0500-4ceb-a8a0-c94c8cde7eba VDhFbnE0UnVtQ2dheWI4akV4QlRwdz09\"\ntype: LOCK_TYPE_WRITE\napp_name: \"OnlyOffice\"\nexpiration {\n  seconds: 1706536191\n}\n"}
{"time": "2024-01-29T12:51:36.149", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Retrieved lock", "lockop": "Unlock", "user": "Xtp4D1vAXqW8ltrc9UR8", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "fileid": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "lock": "T8Enq4RumCgayb8jExBTpw==", "retrievedlock": "T8Enq4RumCgayb8jExBTpw==", "expTime": "2024-01-29T13:49:51", "token": "pE5PREW9cadmaM6GYpfc"}
{"time": "2024-01-29T12:51:36.149", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "compareLocks", "lock1": "T8Enq4RumCgayb8jExBTpw==", "lock2": "T8Enq4RumCgayb8jExBTpw==", "result": "True"}
{"time": "2024-01-29T12:51:36.153", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "8058b7919b36d2a8f2094d3b3015ff4f", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.7"}
{"time": "2024-01-29T12:51:36.156", "host": "80a14cbac9e3", "level": "ERROR", "process": "wopiserver", "module": "cs3iface", "msg": "Failed to unlock", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "2f3a2d4f1c32f12571f8192215817b3e", "code": "8", "reason": "unlock: error: permission denied: a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt"}
=== bob closed -> ERROR


{"time": "2024-01-29T12:51:55.035", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Generating token", "userid": "fqp_HYDGxwl3VnQ4KvCs", "fileid": "d3cb393c-f777-4232-9dc5-610e79baf865", "endpoint": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714", "app": "OnlyOffice"}
{"time": "2024-01-29T12:51:55.039", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "d3cb393c-f777-4232-9dc5-610e79baf865", "trace": "692ee9e1202130a6375e798f906f0a25", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.6"}
{"time": "2024-01-29T12:51:55.040", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Access token generated", "userid": "fqp_HYDGxwl3VnQ4KvCs", "wopiuser": "9bb608d6-cb9b-4d4d-adf8-14f39506c714!9bb608d6-cb9b-4d4d-adf8-14f39506c714@https://ocis.owncloud.test", "friendlyname": "Admin", "usertype": "UserType.REGULAR", "mode": "ViewMode.READ_WRITE", "endpoint": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "mtime": "1706532471", "folderurl": "https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865", "appname": "OnlyOffice", "expiration": "1706619115", "token": "v1rtk66XCS4BNvg6AOKs"}
{"time": "2024-01-29T12:51:55.040", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiserver", "msg": "iopOpenInApp: redirecting client", "appurl": "https://onlyoffice.owncloud.test/hosting/wopi/word/edit?WOPISrc=https%3A%2F%2Fwopiserver.owncloud.test%2Fwopi%2Ffiles%2Fa4015be1%2Dc82c%2D4ade%2Db6e3%2D9187b9bad9ba%21ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1"}
{"time": "2024-01-29T12:51:55.080", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Checkfileinfo: client context", "user": "fqp_HYDGxwl3VnQ4KvCs", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "v1rtk66XCS4BNvg6AOKs", "client": "172.18.0.5", "deviceId": "None", "reqId": "None", "sessionId": "None", "app": "None", "appEndpoint": "None", "correlationId": "None", "wopits": "63842129515.074"}
{"time": "2024-01-29T12:51:55.084", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "777901c80342e0d8bdc01bb6798dd29b", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "3.6"}
{"time": "2024-01-29T12:51:55.088", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Empty value or key not found in getxattr", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "key": "iop.wopi.userinfo.9bb608d6-cb9b-4d4d-adf8-14f39506c714", "trace": "a78e4849db4768b8926c4539f5d24917", "metadata": "{'http://owncloud.org/ns/favorite': '', 'iop.wopi.lastwritetime': '1706532542', 'iop.wopi.userinfo.9bb608d6-cb9b-4d4d-adf8-14f39506c714': ''}"}
{"time": "2024-01-29T12:51:55.089", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopi", "msg": "File metadata response", "token": "v1rtk66XCS4BNvg6AOKs", "metadata": "{'BaseFileName': 'nwe.odt', 'BreadcrumbDocName': 'nwe.odt', 'FileExtension': '.odt', 'HostEditUrl': '_redacted_', 'HostViewUrl': '_redacted_', 'CloseUrl': 'https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865?scrollTo=nwe.odt', 'BreadcrumbFolderUrl': 'https://ocis.owncloud.test/f/a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!d3cb393c-f777-4232-9dc5-610e79baf865?scrollTo=nwe.odt', 'IsAnonymousUser': False, 'UserFriendlyName': 'Admin', 'BreadcrumbFolderName': 'Parent folder', 'DownloadUrl': '_redacted_', 'FileUrl': '_redacted_', 'LicenseCheckForEditIsEnabled': True, 'BreadcrumbBrandName': None, 'BreadcrumbBrandUrl': '_redacted_', 'OwnerId': '9bb608d6-cb9b-4d4d-adf8-14f39506c714@https://ocis.owncloud.test', 'UserId': '9bb608d6-cb9b-4d4d-adf8-14f39506c714@https://ocis.owncloud.test', 'Size': 4730, 'LastModifiedTime': '2024-01-29 12:47:51.000', 'Version': 'v\"1c53173cdb0a76dd7a347ea6603f6ed3\"', 'SupportsExtendedLockLength': True, 'SupportsGetLock': True, 'SupportsUpdate': True, 'UserCanWrite': True, 'SupportsLocks': True, 'SupportsDeleteFile': True, 'ReadOnly': False, 'RestrictedWebViewOnly': False, 'UserCanNotWriteRelative': False, 'SupportsRename': False, 'UserCanRename': False, 'SupportsUserInfo': True, 'FileSharingUrl': '_redacted_'}"}
{"time": "2024-01-29T12:51:55.098", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "Lock: client context", "user": "fqp_HYDGxwl3VnQ4KvCs", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "v1rtk66XCS4BNvg6AOKs", "client": "172.18.0.5", "deviceId": "None", "reqId": "None", "sessionId": "None", "app": "None", "appEndpoint": "None", "correlationId": "None", "wopits": "63842129515.093"}
{"time": "2024-01-29T12:51:55.101", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked getlock", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "result": "lock_id: \"opaquelocktoken:797356a8-0500-4ceb-a8a0-c94c8cde7eba VDhFbnE0UnVtQ2dheWI4akV4QlRwdz09\"\ntype: LOCK_TYPE_WRITE\napp_name: \"OnlyOffice\"\nexpiration {\n  seconds: 1706536191\n}\n"}
{"time": "2024-01-29T12:51:55.102", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "wopiutils", "msg": "Retrieved lock", "lockop": "Lock", "user": "fqp_HYDGxwl3VnQ4KvCs", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "fileid": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "lock": "/QIUhlilCFbTvLfgCzyn5Q==", "retrievedlock": "T8Enq4RumCgayb8jExBTpw==", "expTime": "2024-01-29T13:49:51", "token": "v1rtk66XCS4BNvg6AOKs"}
{"time": "2024-01-29T12:51:55.104", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat", "fileref": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "89993f4248e6c70c10a901fe273b5c3b", "inode": "a4015be1-c82c-4ade-b6e3-9187b9bad9ba!ZDNjYjM5M2MtZjc3Ny00MjMyLTlkYzUtNjEwZTc5YmFmODY1", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "2.5"}
{"time": "2024-01-29T12:51:55.107", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked stat for getxattr", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "elapsedTimems": "2.8"}
{"time": "2024-01-29T12:51:55.109", "host": "80a14cbac9e3", "level": "INFO", "process": "wopiserver", "module": "cs3iface", "msg": "Invoked setlock on an already locked entity", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "appname": "OnlyOffice", "trace": "4ea983f82c0ccebee6ac771a8c1e689d", "reason": "set lock: error: precondition failed: already locked"}
{"time": "2024-01-29T12:51:55.110", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "compareLocks", "lock1": "T8Enq4RumCgayb8jExBTpw==", "lock2": "/QIUhlilCFbTvLfgCzyn5Q==", "strict": "True", "result": "False"}
{"time": "2024-01-29T12:51:55.110", "host": "80a14cbac9e3", "level": "WARNING", "process": "wopiserver", "module": "wopiutils", "msg": "Returning conflict", "lockop": "Lock", "user": "eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA2NjE5MTE0LCJpYXQiOjE3MDY1MzI3MTQsImlzcyI6Imh0dHBzOi8vb2Npcy5vd25jbG91ZC50ZXN0IiwidXNlciI6eyJpZCI6eyJpZHAiOiJodHRwczovL29jaXMub3duY2xvdWQudGVzdCIsIm9wYXF1ZV9pZCI6IjliYjYwOGQ2LWNiOWItNGQ0ZC1hZGY4LTE0ZjM5NTA2YzcxNCIsInR5cGUiOjF9LCJ1c2VybmFtZSI6ImFkbWluIiwibWFpbCI6ImFkbWluQGV4YW1wbGUub3JnIiwiZGlzcGxheV9uYW1lIjoiQWRtaW4iLCJ1aWRfbnVtYmVyIjo5OSwiZ2lkX251bWJlciI6OTl9LCJzY29wZSI6eyJ1c2VyIjp7InJlc291cmNlIjp7ImRlY29kZXIiOiJqc29uIiwidmFsdWUiOiJleUp3WVhSb0lqb2lMeUo5In0sInJvbGUiOjF9fX0.AAk4GxDPc44FAX9OesB-ZQ6fqp_HYDGxwl3VnQ4KvCs", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "v1rtk66XCS4BNvg6AOKs", "sessionId": "None", "lock": "/QIUhlilCFbTvLfgCzyn5Q==", "oldlock": "None", "retrievedlock": "T8Enq4RumCgayb8jExBTpw==", "fileage": "173.1", "reason": "The file is locked by OnlyOffice"}
=== admin failed to open 'Sorry, editor could not be loaded. Please contact your administrator.'

@wkloucek I noticed that the lock has been changed before an error. It could be a reason for the issue.
{"time": "2024-01-29T12:51:55.110", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "compareLocks", "lock1": "T8Enq4RumCgayb8jExBTpw==", "lock2": "/QIUhlilCFbTvLfgCzyn5Q==", "strict": "True", "result": "False"}

@2403905
Copy link
Contributor

2403905 commented Jan 29, 2024

Update:

  1. admin shared a file with bob with r/w permissions
  2. bob opened the file
  3. admin can open the file as well
  4. admin changed the bob's permission to 'editor' until bob keeps the file opened
  5. bob closed the file but the file can not be unlocked by onlyOffice/wopi
    {"time": "2024-01-29T12:51:36.156", "host": "80a14cbac9e3", "level": "ERROR", "process": "wopiserver", "module": "cs3iface", "msg": "Failed to unlock", "filepath": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "trace": "2f3a2d4f1c32f12571f8192215817b3e", "code": "8", "reason": "unlock: error: permission denied: a4015be1-c82c-4ade-b6e3-9187b9bad9ba$9bb608d6-cb9b-4d4d-adf8-14f39506c714!9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt"}
  6. admin can not open the file and we can see the new lock base64 digest that is not match with old one. "lock1": "T8Enq4RumCgayb8jExBTpw==", "lock2": "/QIUhlilCFbTvLfgCzyn5Q=="
    'Sorry, editor could not be loaded. Please contact your administrator.'
    {"time": "2024-01-29T12:51:55.110", "host": "80a14cbac9e3", "level": "DEBUG", "process": "wopiserver", "module": "wopiutils", "msg": "compareLocks", "lock1": "T8Enq4RumCgayb8jExBTpw==", "lock2": "/QIUhlilCFbTvLfgCzyn5Q==", "strict": "True", "result": "False"} {"time": "2024-01-29T12:51:55.110", "host": "80a14cbac9e3", "level": "WARNING", "process": "wopiserver", "module": "wopiutils", "msg": "Returning conflict", "lockop": "Lock", "user": "eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJhdWQiOiJyZXZhIiwiZXhwIjoxNzA2NjE5MTE0LCJpYXQiOjE3MDY1MzI3MTQsImlzcyI6Imh0dHBzOi8vb2Npcy5vd25jbG91ZC50ZXN0IiwidXNlciI6eyJpZCI6eyJpZHAiOiJodHRwczovL29jaXMub3duY2xvdWQudGVzdCIsIm9wYXF1ZV9pZCI6IjliYjYwOGQ2LWNiOWItNGQ0ZC1hZGY4LTE0ZjM5NTA2YzcxNCIsInR5cGUiOjF9LCJ1c2VybmFtZSI6ImFkbWluIiwibWFpbCI6ImFkbWluQGV4YW1wbGUub3JnIiwiZGlzcGxheV9uYW1lIjoiQWRtaW4iLCJ1aWRfbnVtYmVyIjo5OSwiZ2lkX251bWJlciI6OTl9LCJzY29wZSI6eyJ1c2VyIjp7InJlc291cmNlIjp7ImRlY29kZXIiOiJqc29uIiwidmFsdWUiOiJleUp3WVhSb0lqb2lMeUo5In0sInJvbGUiOjF9fX0.AAk4GxDPc44FAX9OesB-ZQ6fqp_HYDGxwl3VnQ4KvCs", "filename": "9bb608d6-cb9b-4d4d-adf8-14f39506c714/nwe.odt", "token": "v1rtk66XCS4BNvg6AOKs", "sessionId": "None", "lock": "/QIUhlilCFbTvLfgCzyn5Q==", "oldlock": "None", "retrievedlock": "T8Enq4RumCgayb8jExBTpw==", "fileage": "173.1", "reason": "The file is locked by OnlyOffice"}

@2403905 2403905 self-assigned this Jan 30, 2024
@aduffeck
Copy link
Contributor

aduffeck commented Jan 31, 2024

After some more testing and debugging we seem to understand that the root cause is that the wopiserver manages the locks in the scopes of users instead of applications. We also created a wopiserver issue to discuss the matters there.

The options moving forward seem to be:

  1. Implement service accounts in the wopiserver to not scope locks to the user anymore. That would prevent the current issue of locks becoming stuck, but requires bigger changes in the wopiserver.
  2. Allow revoking locks unconditionally of the user permissions on the files. That fixes the problem (after some smaller changes to the wopiserver like not statting the file before unlocking and not locking and comparing the lock before unlocking) but seems to violate the webdav spec and generally doesn't sound like a good idea.

Additionally we could change our business logic - at least until a proper solution is in place - to allow adding grants (which doesn't trigger that issue and is probably the more common case) but prevent removing grants while a lock is in place. That at least makes sure that there won't be stale locks, but makes it impossible to revoke permissions while a wopi session is open.

/cc @butonic

@2403905
Copy link
Contributor

2403905 commented Feb 2, 2024

The same error happens if user A working with a document in Collabora and user B tries to open the same document in Onlyoffice.
So, we have a lot of edge cases with locking.

@micbar
Copy link
Contributor

micbar commented Feb 8, 2024

@2403905 is that "in progress" or "to do" ?

@2403905
Copy link
Contributor

2403905 commented Feb 8, 2024

@micbar I moved back to the to do because as I understand you are working on a similar issue, aren't you?

@2403905
Copy link
Contributor

2403905 commented Feb 8, 2024

I mean the issue with the locks in a wopi

@2403905
Copy link
Contributor

2403905 commented Feb 14, 2024

@micbar To avoid annoying behavior with the locks, can we prevent removing or changing grants while a lock is in place for the ocis v5 until we implement the better solution?

@micbar
Copy link
Contributor

micbar commented Feb 14, 2024

Reading the wopi docs from Microsoft it says that locks should be done on an application level, not bound to a user.

@2403905 2403905 removed their assignment Feb 15, 2024
@micbar
Copy link
Contributor

micbar commented Feb 19, 2024

We should take the workaround here, disallow remove grants or update grants.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Priority:p2-high Escalation, on top of current planning, release blocker Type:Bug
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

4 participants