ERR WOPI::CheckFileInfo failed for URI 503 Service Unavailable

Hello,

Since I upgraded to version 6.4.10 I can no longer use collabora with nextcloud not open it independently.

Here is the error I have in my logs.

Are you having the same problem?

Can you help me ?

Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-04113 2021-07-27 13:22:11.846556 [ docbroker_012 ] WRN  Waking up dead poll thread [HttpSynReqPoll], started: false, finished: false| ./net/Socket.hpp:682
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-04113 2021-07-27 13:22:11.864016 [ docbroker_012 ] ERR  WOPI::CheckFileInfo failed for URI [https://drive.2itea.ch/index.php/apps/richdocuments/wopi/files/73057_ocg462wxck1x?access_token=sUjcOSgb9UJiaqdCX1qyE7g256KiZdkO&access_token_ttl=0]: 503 Service Unavailable. Headers: #011cache-control: no-cache / #011content-type: text/html / #011Body: [<html><body><h1>503 Service Unavailable</h1>
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: No server is available to handle this request.
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: </body></html>
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: ]| wsd/Storage.cpp:703
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-04113 2021-07-27 13:22:11.864172 [ docbroker_012 ] ERR  loading document exception: WOPI::CheckFileInfo failed: <html><body><h1>503 Service Unavailable</h1>
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: No server is available to handle this request.
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: </body></html>
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: | wsd/DocumentBroker.cpp:1893
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-04113 2021-07-27 13:22:11.864200 [ docbroker_012 ] ERR  Failed to add session to [/index.php/apps/richdocuments/wopi/files/73057_ocg462wxck1x] with URI [https://drive.2itea.ch/index.php/apps/richdocuments/wopi/files/73057_ocg462wxck1x?access_token=sUjcOSgb9UJiaqdCX1qyE7g256KiZdkO&access_token_ttl=0]: WOPI::CheckFileInfo failed: <html><body><h1>503 Service Unavailable</h1>
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: No server is available to handle this request.
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: </body></html>
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: | wsd/DocumentBroker.cpp:1855
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-04113 2021-07-27 13:22:11.864257 [ docbroker_012 ] ERR  Storage error while starting session on /index.php/apps/richdocuments/wopi/files/73057_ocg462wxck1x for socket #20. Terminating connection. Error: WOPI::CheckFileInfo failed: <html><body><h1>503 Service Unavailable</h1>
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: No server is available to handle this request.
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: </body></html>
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: | wsd/LOOLWSD.cpp:3592
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-04113 2021-07-27 13:22:11.864438 [ docbroker_012 ] WRN  Ignoring attempted read from 20| ./net/Socket.hpp:1021
Jul 27 15:22:11 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-04113 2021-07-27 13:22:11.864465 [ docbroker_012 ] ERR  Invalid or unknown session [088] to remove.| wsd/DocumentBroker.cpp:1932
Jul 27 15:22:12 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:12.433442 [ websrv_poll ] WRN  DocBroker with docKey [/index.php/apps/richdocuments/wopi/files/73057_ocg462wxck1x] that is marked to be destroyed. Rejecting client request.| wsd/LOOLWSD.cpp:2144
Jul 27 15:22:12 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:12.433513 [ websrv_poll ] ERR  Error while handling Client WS Request: Failed to create DocBroker with docKey [/index.php/apps/richdocuments/wopi/files/73057_ocg462wxck1x].| wsd/LOOLWSD.cpp:3621
Jul 27 15:22:12 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:12.433531 [ websrv_poll ] ERR  #28: Socket write returned -1 (EPIPE: Broken pipe)| ./net/Socket.hpp:1284
Jul 27 15:22:12 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:12.433550 [ websrv_poll ] ERR  #28: Socket write returned -1 (EPIPE: Broken pipe)| ./net/Socket.hpp:1284
Jul 27 15:22:12 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:12.433562 [ websrv_poll ] WRN  Socket #28 is shutting down but 64 bytes couldn't be flushed and still remain in the output buffer.| ./net/WebSocketHandler.hpp:765
Jul 27 15:22:12 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:12.433580 [ websrv_poll ] ERR  #28: attempted to remove: 894 which is > size: 0 clamped to 0| ./net/Socket.hpp:1120
Jul 27 15:22:12 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:12.433597 [ websrv_poll ] WRN  Ignoring attempted read from 28| ./net/Socket.hpp:1021
Jul 27 15:22:12 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:12.433611 [ websrv_poll ] ERR  #28: Socket write returned -1 (EPIPE: Broken pipe)| ./net/Socket.hpp:1284
Jul 27 15:22:13 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:13.575219 [ websrv_poll ] WRN  DocBroker with docKey [/index.php/apps/richdocuments/wopi/files/73057_ocg462wxck1x] that is marked to be destroyed. Rejecting client request.| wsd/LOOLWSD.cpp:2144
Jul 27 15:22:13 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:13.575300 [ websrv_poll ] ERR  Error while handling Client WS Request: Failed to create DocBroker with docKey [/index.php/apps/richdocuments/wopi/files/73057_ocg462wxck1x].| wsd/LOOLWSD.cpp:3621
Jul 27 15:22:13 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:13.575317 [ websrv_poll ] ERR  #28: Socket write returned -1 (EPIPE: Broken pipe)| ./net/Socket.hpp:1284
Jul 27 15:22:13 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:13.575336 [ websrv_poll ] ERR  #28: Socket write returned -1 (EPIPE: Broken pipe)| ./net/Socket.hpp:1284
Jul 27 15:22:13 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:13.575348 [ websrv_poll ] WRN  Socket #28 is shutting down but 64 bytes couldn't be flushed and still remain in the output buffer.| ./net/WebSocketHandler.hpp:765
Jul 27 15:22:13 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:13.575365 [ websrv_poll ] ERR  #28: attempted to remove: 894 which is > size: 0 clamped to 0| ./net/Socket.hpp:1120
Jul 27 15:22:13 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:13.575385 [ websrv_poll ] WRN  Ignoring attempted read from 28| ./net/Socket.hpp:1021
Jul 27 15:22:13 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01352 2021-07-27 13:22:13.575398 [ websrv_poll ] ERR  #28: Socket write returned -1 (EPIPE: Broken pipe)| ./net/Socket.hpp:1284
Jul 27 15:22:14 2IT-HVM-COLLAB-PUB-01 loolwsd[1342]: wsd-01342-01347 2021-07-27 13:22:14.041685 [ prisoner_poll ] WRN  Prisoner connection disconnected but without valid socket.| wsd/LOOLWSD.cpp:2231

I don’t know about your setup, just thought I’d mention that 6.4.10-6 was released a day ago, it includes this fix which has helped a lot of people out, hope it helps you too:

Thank you for your reply,

Even with the update the problem is still there.

I have a following configuration:

Nextcloud → Haproxy port: 443 → Nginx port: 80 → loolwsd full no ssl

I don’t use docker but directly from Debian 10 packages

But in version 6.4.9 it worked fine.

Do you have any other idea where this could come from?

Sorry I have no idea where the problem is, I am out of my depth. Personally, if it is in production I’d get a Collabora subscription and pay for some help. My gut feeling is it is to do with the “ssl: setup hostname for SNI” fix, I am not sure what changed that necessitated this fix.

We do have a Host: header on what we provide for our CheckFileInfo request - which is actually just a GET /wopi/files/(file_id) call (without the trailing /contents). The new thing is that we append the port number even for port 80 / 443 - which I have a patch to disable; I wonder if that could be the cause (?)

This seems to be the FAQ: Ignore port numbers in haproxy host header matches - Server Fault

CODE 6.4.10-10 is now out with a proposed fix, please check if that solves this problem.