I encounter problems with a Collabora Online intregation the users get the message that the document cannot be recovered.
I analyzed the log and I see that, some time, the unlock comes before the putFile request. And the putFile requests fails, because the lock does not exists any more.
This is an extract of the log for the same document. They all use the same access token (the end user does not reload the editor page). As our app is load-balanced, the host may be different for each request:
| timestamp | host | ctxt_route | |
|---|---|---|---|
| {InstantSeconds=1674046477},ISO,Z resolved to 2023-01-18T12:54:37.843851 | chill-5dcd7b4d55-5t849 | chill_wopi_file_edit | ← the end user opens the editor page |
| {InstantSeconds=1674046479},ISO,Z resolved to 2023-01-18T12:54:39.705799 | chill-5dcd7b4d55-gvgvq | checkFileInfo | ← load the page |
| {InstantSeconds=1674046480},ISO,Z resolved to 2023-01-18T12:54:40.247943 | chill-5dcd7b4d55-b7nh5 | getFile | |
| {InstantSeconds=1674046481},ISO,Z resolved to 2023-01-18T12:54:41.465522 | chill-5dcd7b4d55-5t849 | lock | |
| {InstantSeconds=1674046794},ISO,Z resolved to 2023-01-18T12:59:54.882569 | chill-5dcd7b4d55-gvgvq | putFile | |
| {InstantSeconds=1674047038},ISO,Z resolved to 2023-01-18T13:03:58.787539 | chill-5dcd7b4d55-gvgvq | unlock | |
| {InstantSeconds=1674047040},ISO,Z resolved to 2023-01-18T13:04:00.424865 | chill-5dcd7b4d55-gvgvq | putFile | ← the problem happens here, the request is rejected because the document is unlocked |
| {InstantSeconds=1674047165},ISO,Z resolved to 2023-01-18T13:06:05.579083 | chill-5dcd7b4d55-b7nh5 | checkFileInfo | |
| {InstantSeconds=1674047165},ISO,Z resolved to 2023-01-18T13:06:05.909414 | chill-5dcd7b4d55-5t849 | getFile | |
| {InstantSeconds=1674047166},ISO,Z resolved to 2023-01-18T13:06:06.263681 | chill-5dcd7b4d55-5t849 | lock | |
| {InstantSeconds=1674047185},ISO,Z resolved to 2023-01-18T13:06:25.541099 | chill-5dcd7b4d55-gvgvq | putFile | |
| {InstantSeconds=1674047291},ISO,Z resolved to 2023-01-18T13:08:11.857386 | chill-5dcd7b4d55-b7nh5 | putFile | |
| {InstantSeconds=1674048070},ISO,Z resolved to 2023-01-18T13:21:10.813988 | chill-5dcd7b4d55-5t849 | lock | |
| {InstantSeconds=1674048975},ISO,Z resolved to 2023-01-18T13:36:15.956676 | chill-5dcd7b4d55-b7nh5 | lock | |
| {InstantSeconds=1674049171},ISO,Z resolved to 2023-01-18T13:39:31.752212 | chill-5dcd7b4d55-5t849 | putFile | |
| {InstantSeconds=1674049173},ISO,Z resolved to 2023-01-18T13:39:33.622750 | chill-5dcd7b4d55-5t849 | unlock | ← ok, correct order |
This happens ~10% of the document views (20-30 times a day, for 400-500 documents opened)
I think I will try to solve this problem by introducing a delay in unlock of a couple of seconds (5 seconds). So that, if a putFile request will still find a lock if they happens in this delay time.
My questions are:
-
should I open a ticket here ? Is this “normal”, or a bug ?
I think that Collabora should wait for the putFile request to fullfill before unlocking the file…
-
Do you think that adding this delay will solve this problem without any side effect ?
Thanks