CollaboraOnline / online

Collabora Online is a collaborative online office suite based on LibreOffice technology. This is also the source for the Collabora Office apps for iOS and Android.
https://collaboraonline.com
Other
1.79k stars 686 forks source link

fails to open document, "WOPI::CheckFileInfo failed: | wsd/DocumentBroker.cpp:2332", "ERR Storage error while starting session" #5855

Open vasyugan opened 1 year ago

vasyugan commented 1 year ago

Describe the bug I experience this problem with one of my nextcloud instances, running on a synology diskstation. It occurs only when I use natively installed coolwsd. It does NOT occur with collabora running in docker. It also does not affect my other Nextcloud instances on other servers, using the same instance of collbora. They all work fine with both the native and the dockerized version. However, one instance stubbornly refused to cooperate withe native version while working fine with the dockerized version.

To Reproduce Steps to reproduce the behavior:

  1. Install Collabora on Ubuntu 22.04 LTS using the native debian packages for this distro
  2. Shut down the collabora docker instance, edit /etc/coolwsd.xml to accept connections from the same Nextcloud instances that used the dockerized version.
  3. On the target Nextcloud instance try to open a document in "Nextcloud office"
  4. See error "Document cannot be opened, please try again later"

Expected behavior Should open the document, just as the dockerized version did.

Actual behavior Error screen " Document cannot be opened. Please try again later"

Desktop (please complete the following information)

Additional context Here the relevant portion from the systemd log:

Feb 07 12:08:23 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261494 2023-02-07 12:08:23.997352 +0100 [ docbroker_022 ] ERR  #35: Read failed, have 0 buffered bytes (EPIPE: Broken pipe)| net/Socket.hpp:1135
Feb 07 12:08:23 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261494 2023-02-07 12:08:23.997424 +0100 [ docbroker_022 ] ERR  #35: Socket write returned -1 (EPIPE: Broken pipe)| net/Socket.hpp:1436
Feb 07 12:08:23 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261494 2023-02-07 12:08:23.997444 +0100 [ docbroker_022 ] ERR  #35: Socket write returned -1 (EPIPE: Broken pipe)| net/Socket.hpp:1436
Feb 07 12:08:23 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261494 2023-02-07 12:08:23.997498 +0100 [ docbroker_022 ] ERR  WOPI::CheckFileInfo failed for URI [https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe?access_token=QBlTGZtR19qXO4UMeeFh98gH4yB25jKK&access_token_ttl=1675804102000]: 0 . Headers:         Body: []| wsd/Storage.cpp:689
Feb 07 12:08:23 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261494 2023-02-07 12:08:23.997544 +0100 [ docbroker_022 ] ERR  loading document exception: WOPI::CheckFileInfo failed: | wsd/DocumentBroker.cpp:2370
Feb 07 12:08:23 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261494 2023-02-07 12:08:23.997566 +0100 [ docbroker_022 ] ERR  Failed to add session to [https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe] with URI [https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe?access_token=QBlTGZtR19qXO4UMeeFh98gH4yB25jKK&access_token_ttl=1675804102000]: WOPI::CheckFileInfo failed: | wsd/DocumentBroker.cpp:2332
Feb 07 12:08:23 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261494 2023-02-07 12:08:23.997591 +0100 [ docbroker_022 ] ERR  Storage error while starting session on https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe for socket #29. Terminating connection. Error: WOPI::CheckFileInfo failed: | wsd/COOLWSD.cpp:4856
Feb 07 12:08:24 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261494 2023-02-07 12:08:24.005434 +0100 [ docbroker_022 ] ERR  #28: Read failed, have 0 buffered bytes (ECONNRESET: Connection reset by peer)| net/Socket.hpp:1135
Feb 07 12:08:24 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261494 2023-02-07 12:08:24.005478 +0100 [ docbroker_022 ] WRN  Unassociated Kit (3259405) disconnected unexpectedly| wsd/COOLWSD.cpp:3395
Feb 07 12:08:24 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261531 2023-02-07 12:08:24.586365 +0100 [ docbroker_023 ] ERR  #33: Read failed, have 0 buffered bytes (EPIPE: Broken pipe)| net/Socket.hpp:1135
Feb 07 12:08:24 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261531 2023-02-07 12:08:24.586441 +0100 [ docbroker_023 ] ERR  #33: Socket write returned -1 (EPIPE: Broken pipe)| net/Socket.hpp:1436
Feb 07 12:08:24 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261531 2023-02-07 12:08:24.586458 +0100 [ docbroker_023 ] ERR  #33: Socket write returned -1 (EPIPE: Broken pipe)| net/Socket.hpp:1436
Feb 07 12:08:24 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261531 2023-02-07 12:08:24.586509 +0100 [ docbroker_023 ] ERR  WOPI::CheckFileInfo failed for URI [https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe?access_token=QBlTGZtR19qXO4UMeeFh98gH4yB25jKK&access_token_ttl=1675804102000&permission=edit]: 0 . Headers:         Body: []| wsd/Storage.cpp:689
Feb 07 12:08:24 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261531 2023-02-07 12:08:24.586551 +0100 [ docbroker_023 ] ERR  loading document exception: WOPI::CheckFileInfo failed: | wsd/DocumentBroker.cpp:2370
Feb 07 12:08:24 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261531 2023-02-07 12:08:24.586566 +0100 [ docbroker_023 ] ERR  Failed to add session to [https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe] with URI [https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe?access_token=QBlTGZtR19qXO4UMeeFh98gH4yB25jKK&access_token_ttl=1675804102000&permission=edit]: WOPI::CheckFileInfo failed: | wsd/DocumentBroker.cpp:2332
Feb 07 12:08:24 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261531 2023-02-07 12:08:24.586594 +0100 [ docbroker_023 ] ERR  Storage error while starting session on https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe for socket #28. Terminating connection. Error: WOPI::CheckFileInfo failed: | wsd/COOLWSD.cpp:4856
Feb 07 12:08:24 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261531 2023-02-07 12:08:24.592599 +0100 [ docbroker_023 ] ERR  #36: Read failed, have 0 buffered bytes (ECONNRESET: Connection reset by peer)| net/Socket.hpp:1135
Feb 07 12:08:24 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261531 2023-02-07 12:08:24.592643 +0100 [ docbroker_023 ] WRN  Unassociated Kit (3261496) disconnected unexpectedly| wsd/COOLWSD.cpp:3395
Feb 07 12:08:25 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261550 2023-02-07 12:08:25.088910 +0100 [ docbroker_024 ] ERR  #35: Read failed, have 0 buffered bytes (EPIPE: Broken pipe)| net/Socket.hpp:1135
Feb 07 12:08:25 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261550 2023-02-07 12:08:25.088993 +0100 [ docbroker_024 ] ERR  #35: Socket write returned -1 (EPIPE: Broken pipe)| net/Socket.hpp:1436
Feb 07 12:08:25 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261550 2023-02-07 12:08:25.089021 +0100 [ docbroker_024 ] ERR  #35: Socket write returned -1 (EPIPE: Broken pipe)| net/Socket.hpp:1436
Feb 07 12:08:25 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261550 2023-02-07 12:08:25.089091 +0100 [ docbroker_024 ] ERR  WOPI::CheckFileInfo failed for URI [https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe?access_token=QBlTGZtR19qXO4UMeeFh98gH4yB25jKK&access_token_ttl=1675804102000&permission=edit]: 0 . Headers:         Body: []| wsd/Storage.cpp:689
Feb 07 12:08:25 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261550 2023-02-07 12:08:25.089148 +0100 [ docbroker_024 ] ERR  loading document exception: WOPI::CheckFileInfo failed: | wsd/DocumentBroker.cpp:2370
Feb 07 12:08:25 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261550 2023-02-07 12:08:25.089174 +0100 [ docbroker_024 ] ERR  Failed to add session to [https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe] with URI [https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe?access_token=QBlTGZtR19qXO4UMeeFh98gH4yB25jKK&access_token_ttl=1675804102000&permission=edit]: WOPI::CheckFileInfo failed: | wsd/DocumentBroker.cpp:2332
Feb 07 12:08:25 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261550 2023-02-07 12:08:25.089208 +0100 [ docbroker_024 ] ERR  Storage error while starting session on https://*****.diskstation.me:4433/index.php/apps/richdocuments/wopi/files/12094_oclsffxzupxe for socket #29. Terminating connection. Error: WOPI::CheckFileInfo failed: | wsd/COOLWSD.cpp:4856
Feb 07 12:08:25 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261550 2023-02-07 12:08:25.098836 +0100 [ docbroker_024 ] ERR  #28: Read failed, have 0 buffered bytes (ECONNRESET: Connection reset by peer)| net/Socket.hpp:1135
Feb 07 12:08:25 ****.*****.*** coolwsd[3158473]: wsd-3158473-3261550 2023-02-07 12:08:25.098886 +0100 [ docbroker_024 ] WRN  Unassociated Kit (3261538) disconnected unexpectedly| wsd/COOLWSD.cpp:3395
vasyugan commented 1 year ago

Still reproducible on the same particular instance.

cohenchris commented 10 months ago

@vasyugan any update? I've been having this issue for some months now, I'm on the most recent version of collabora/code (23) and nextcloud (27). Same exact error messages. I am using docker-compose.

vasyugan commented 10 months ago

@vasyugan any update? I've been having this issue for some months now, I'm on the most recent version of collabora/code (23) and nextcloud (27). Same exact error messages. I am using docker-compose.

I'm seeing the problem only when I use the native packages and not when using docker. Since none of the devs has responded so far, I know just as little as I did half a year ago.

Have you checked whether the error also occurs when you use a different collabora instance? (I could offer you mine for testing.)

cohenchris commented 10 months ago

I think I've narrowed down the issue, at least on my setup. I am following this sanity-check guide: https://help.nextcloud.com/t/nextcloud-collabora-integration/151879

From my nextcloud container, I can curl my collabora endpoint. However, from my collabora container, I can't curl my nextcloud endpoint. It seems pretty likely that this is the culprit - opening a document in nextcloud immediately fails, and displays some error message about the reverse proxy being misconfigured. I'm guessing this is some DNS issue within the container.

I've tried to use Collabora's demo server too, and that worked fine. That is the only other collabora instance that I've tried.

Seems like we have a similar problem with very different setups... in your case, I would ensure that your WOPI allowlist is right in your coolwsd.xml (I think that's where it is). I have personally never tried installing NC/Collabora through native packages.

cohenchris commented 10 months ago

Hi, I ended up fixing the issue on my end. Again, I know this won't fix your issue, but maybe it will give you a place to start.

Some months ago, I saw this error in my nextcloud logs: AH00558: apache2: Could not reliably determine the server's fully qualified domain name, using 172.27.0.15. Set the 'ServerName' directive globally to suppress this message

I saw this issue here: https://github.com/nextcloud/docker/issues/609 Adding the 'hostname: cloud.mydomain.com' field to my docker-compose suppressed this issue. However, it had an unintended consequence. When collabora queries cloud.mydomain.com, it now resolves to the internal nextcloud container IP. Collabora attempts to connect over SSL on port 443, which is not open on the docker container.

My solution, for now, was to remove this hostname field, and ensure that my WOPI allowlist for Nextcloud is set correctly. This allowlist should be:

If your Collabora container is querying directly to the Nextcloud container, this should include the Collabora container's IP (docker inspect ). If not, it will be your external IP address (Collabora will do a DNS lookup for Nextcloud, see the IP, and query for it. The request will be coming from your external IP, to your external IP). Personally, I have hairpin NAT enabled on my router, so any requests to a domain name that is inside my network will never leave the network - instead, the router will bounce it back, improving latency. My network is on the 10.0.0.0/8 address space, so I set the WOPI allowlist IPs to 10.0.0.0/8, which allows WOPI requests from any device on my local network.

This setup works for me, although the FQDN error above comes back in my nextcloud container.