Documents won't open from Nextcloud unless the container is restarted

[rev138]

I am using CODE 2.1

The first time I start the container, if I try to open a document from Nextcloud it fails with the following message:

Failed to load the document. Please ensure the file type is supported and not corrupted, and try again.

If I 'restart' the container, it works fine after that.

I noticed that the first time I start the container, it always prints a log message like this:

ForKit not responsive for 37618 ms forking 1 children. Resetting.

When I restart the container, the error does not appear. Coincidence?

As a test, I appended some extra code to the start script to kill and relaunch loolwsd, and now it works fine without a restart after 60 seconds.

sleep 45
killall5 -9 loolwsd

su -c "/usr/bin/loolwsd \
    --version \
    --o:sys_template_path=/opt/lool/systemplate \
    --o:lo_template_path=/opt/collaboraoffice5.3 \
    --o:child_root_path=/opt/lool/child-roots \
    --o:file_server_root_path=/usr/share/loolwsd" \
    -s /bin/bash lool

There's definitely something unique about the first run.

[krono]

Can Confirm with current docker image.

[thebearon]

ForKit not responsive for 37618 ms forking 1 children. Resetting.
This is not an error, and the service should work fine afterwards, are there any actual errors/fatal errors? (ERR/FTL entries in log)

I did notice in a few cases that the fork couldn't finish in time during the first start on some system setups, which resulted in "FTL Failed to fork child processes" error (somewhat similar to, and likely partially behind #10, but it only occurs once).

In the next release the initial timeout will be extended, so if that's the reason behind this issue, it should be gone then.

[brylie]

I had the same problem today. Here are my Docker logs for the latest collabora image:

kit-00029-00027 18:09:08.173584 [ loolkit ] WRN  Linking/copying files from /opt/collaboraoffice5.3 to /opt/lool/child-roots/uC6ELWb4Pv1gXoMP/lo/ is taking too much time. Enabling verbose link/copy logging at information level.| kit/Kit.cpp:163
office version details: { "ProductName": "Collabora Office", "ProductVersion": "5.3", "ProductExtension": ".10.41", "BuildId": "b931733d36037cb90ae09f62b0345a2cd22e649c" }
wsd-00025-00026 18:09:19.534550 [ prisoner_poll ] WRN  ForKit not responsive for 31115 ms forking 1 children. Resetting.| wsd/LOOLWSD.cpp:352
wsd-00025-00033 18:09:22.576466 [ websrv_poll ] ERR  FileServerRequestHandler: File not found: Invalid URI request: [/loleaflet/8a1761a/loleaflet.html?WOPISrc=https%3A%2F%2Fdocs.westernfriend.org%2Findex.php%2Fapps%2Frichdocuments%2Fwopi%2Ffiles%2F28998_oc1ele6uybbl&title=DeleteThis.docx&lang=en&closebutton=1&revisionhistory=1].| wsd/FileServer.cpp:381
wsd-00025-00033 18:10:27.356926 [ websrv_poll ] ERR  FileServerRequestHandler: File not found: Invalid URI request: [/loleaflet/8a1761a/loleaflet.html?WOPISrc=https%3A%2F%2Fdocs.westernfriend.org%2Findex.php%2Fapps%2Frichdocuments%2Fwopi%2Ffiles%2F28998_oc1ele6uybbl&title=DeleteThis.docx&lang=en&closebutton=1&revisionhistory=1].| wsd/FileServer.cpp:381
wsd-00025-00033 18:10:43.458109 [ websrv_poll ] ERR  FileServerRequestHandler: File not found: Invalid URI request: [/loleaflet/8a1761a/loleaflet.html?WOPISrc=https%3A%2F%2Fdocs.westernfriend.org%2Findex.php%2Fapps%2Frichdocuments%2Fwopi%2Ffiles%2F28998_oc1ele6uybbl&title=DeleteThis.docx&lang=en&closebutton=1&revisionhistory=1].| wsd/FileServer.cpp:381
wsd-00025-00033 18:12:18.778736 [ websrv_poll ] WRN  WOPI host did not pass optional access_token_ttl| wsd/FileServer.cpp:540
wsd-00025-00038 18:12:23.630775 [ docbroker_001 ] WRN  Missing JSON property [WatermarkText]| wsd/Storage.cpp:421
wsd-00025-00038 18:12:23.747115 [ docbroker_001 ] WRN  Missing JSON property [HidePrintOption]| wsd/Storage.cpp:421
wsd-00025-00038 18:12:23.747533 [ docbroker_001 ] WRN  Missing JSON property [HideSaveOption]| wsd/Storage.cpp:421
wsd-00025-00038 18:12:23.753772 [ docbroker_001 ] WRN  Missing JSON property [HideExportOption]| wsd/Storage.cpp:421
wsd-00025-00038 18:12:23.753957 [ docbroker_001 ] WRN  Missing JSON property [EnableOwnerTermination]| wsd/Storage.cpp:421
wsd-00025-00038 18:12:23.754034 [ docbroker_001 ] WRN  Missing JSON property [DisablePrint]| wsd/Storage.cpp:421
wsd-00025-00038 18:12:23.754107 [ docbroker_001 ] WRN  Missing JSON property [DisableExport]| wsd/Storage.cpp:421
wsd-00025-00038 18:12:23.754175 [ docbroker_001 ] WRN  Missing JSON property [DisableCopy]| wsd/Storage.cpp:421
wsd-00025-00038 18:12:23.754259 [ docbroker_001 ] WRN  Missing JSON property [DisableInactiveMessages]| wsd/Storage.cpp:421
wsd-00025-00038 18:12:23.827997 [ docbroker_001 ] WRN  Attempted ping on non-upgraded websocket!| ./net/WebSocketHandler.hpp:280
E: lt_string_value: assertion `string != ((void *)0)' failed
E: lt_string_value: assertion `string != ((void *)0)' failed
E: lt_string_value: assertion `string != ((void *)0)' failed
E: lt_string_value: assertion `string != ((void *)0)' failed
kit-00035-00039 18:12:24.747358 [ lokit_001 ] ERR  Failed to load: file:///user/docs/wot4MhHWTgpqOfWK/DeleteThis.docx, error: loadComponentFromURL returned an empty reference| kit/Kit.cpp:1508
kit-00035-00039 18:12:24.747490 [ lokit_001 ] ERR  Failed to get LoKitDocument instance.| kit/ChildSession.cpp:368
kit-00035-00039 18:12:24.747818 [ lokit_001 ] WRN  Document::ViewCallback. Session [-1] is no longer active to process [STATUS_INDICATOR_START] [(nil)] message to Master Session.| kit/Kit.cpp:1823
kit-00035-00039 18:12:24.747888 [ lokit_001 ] WRN  Document::ViewCallback. Session [-1] is no longer active to process [STATUS_INDICATOR_FINISH] [(nil)] message to Master Session.| kit/Kit.cpp:1823
kit-00035-00039 18:12:24.976551 [ lokit_001 ] WRN  Skipping unload on incomplete view.| kit/ChildSession.cpp:72
kit-00035-00039 18:12:24.976613 [ lokit_001 ] ERR  No socket associated with WebSocketHandler 0x0xe54a590| ./net/WebSocketHandler.hpp:100
wsd-00025-00026 18:12:25.502735 [ prisoner_poll ] WRN  Waking up dead poll thread [docbroker_001], started: true, finished: true| ./net/Socket.hpp:512
wsd-00025-00026 18:12:25.507153 [ prisoner_poll ] WRN  Waking up dead poll thread [docbroker_001], started: true, finished: true| ./net/Socket.hpp:512
wsd-00025-00026 18:12:25.507735 [ prisoner_poll ] WRN  Waking up dead poll thread [docbroker_001], started: false, finished: true| ./net/Socket.hpp:512
wsd-00025-00026 18:12:25.507806 [ prisoner_poll ] WRN  Waking up dead poll thread [docbroker_001], started: false, finished: true| ./net/Socket.hpp:512
wsd-00025-00033 18:12:39.760237 [ websrv_poll ] WRN  WOPI host did not pass optional access_token_ttl| wsd/FileServer.cpp:540
wsd-00025-00043 18:12:41.012962 [ docbroker_002 ] WRN  Missing JSON property [WatermarkText]| wsd/Storage.cpp:421
wsd-00025-00043 18:12:41.017513 [ docbroker_002 ] WRN  Missing JSON property [HidePrintOption]| wsd/Storage.cpp:421
wsd-00025-00043 18:12:41.024451 [ docbroker_002 ] WRN  Missing JSON property [HideSaveOption]| wsd/Storage.cpp:421
wsd-00025-00043 18:12:41.024653 [ docbroker_002 ] WRN  Missing JSON property [HideExportOption]| wsd/Storage.cpp:421
wsd-00025-00043 18:12:41.026533 [ docbroker_002 ] WRN  Missing JSON property [EnableOwnerTermination]| wsd/Storage.cpp:421
wsd-00025-00043 18:12:41.026621 [ docbroker_002 ] WRN  Missing JSON property [DisablePrint]| wsd/Storage.cpp:421
wsd-00025-00043 18:12:41.026692 [ docbroker_002 ] WRN  Missing JSON property [DisableExport]| wsd/Storage.cpp:421
wsd-00025-00043 18:12:41.026762 [ docbroker_002 ] WRN  Missing JSON property [DisableCopy]| wsd/Storage.cpp:421
wsd-00025-00043 18:12:41.026843 [ docbroker_002 ] WRN  Missing JSON property [DisableInactiveMessages]| wsd/Storage.cpp:421
wsd-00025-00043 18:12:41.112748 [ docbroker_002 ] WRN  Attempted ping on non-upgraded websocket!| ./net/WebSocketHandler.hpp:280
kit-00029-00045 18:12:42.225507 [ lokit_002 ] ERR  Failed to load: file:///user/docs/uC6ELWb4Pv1gXoMP/ModuleAudit.ods, error: loadComponentFromURL returned an empty reference| kit/Kit.cpp:1508
kit-00029-00045 18:12:42.226166 [ lokit_002 ] ERR  Failed to get LoKitDocument instance.| kit/ChildSession.cpp:368
kit-00029-00045 18:12:42.244246 [ lokit_002 ] WRN  Document::ViewCallback. Session [-1] is no longer active to process [STATUS_INDICATOR_START] [(nil)] message to Master Session.| kit/Kit.cpp:1823
kit-00029-00045 18:12:42.244743 [ lokit_002 ] WRN  Document::ViewCallback. Session [-1] is no longer active to process [STATUS_INDICATOR_FINISH] [(nil)] message to Master Session.| kit/Kit.cpp:1823
kit-00029-00045 18:12:42.245316 [ lokit_002 ] WRN  Document::ViewCallback. Session [-1] is no longer active to process [STATUS_INDICATOR_START] [(nil)] message to Master Session.| kit/Kit.cpp:1823
kit-00029-00045 18:12:42.245750 [ lokit_002 ] WRN  Document::ViewCallback. Session [-1] is no longer active to process [STATUS_INDICATOR_SET_VALUE] [100] message to Master Session.| kit/Kit.cpp:1823
kit-00029-00045 18:12:42.246183 [ lokit_002 ] WRN  Document::ViewCallback. Session [-1] is no longer active to process [STATUS_INDICATOR_FINISH] [(nil)] message to Master Session.| kit/Kit.cpp:1823
kit-00029-00045 18:12:42.246649 [ lokit_002 ] WRN  Document::ViewCallback. Session [-1] is no longer active to process [STATUS_INDICATOR_FINISH] [(nil)] message to Master Session.| kit/Kit.cpp:1823
kit-00029-00045 18:12:42.526023 [ lokit_002 ] WRN  Skipping unload on incomplete view.| kit/ChildSession.cpp:72
kit-00029-00045 18:12:42.526207 [ lokit_002 ] ERR  No socket associated with WebSocketHandler 0x0xe54a5d0| ./net/WebSocketHandler.hpp:100
wsd-00025-00026 18:12:43.039213 [ prisoner_poll ] WRN  Waking up dead poll thread [docbroker_002], started: true, finished: true| ./net/Socket.hpp:512
wsd-00025-00026 18:12:43.039984 [ prisoner_poll ] WRN  Waking up dead poll thread [docbroker_002], started: true, finished: true| ./net/Socket.hpp:512
wsd-00025-00026 18:12:43.040888 [ prisoner_poll ] WRN  Waking up dead poll thread [docbroker_002], started: false, finished: true| ./net/Socket.hpp:512
wsd-00025-00026 18:12:43.046601 [ prisoner_poll ] WRN  Waking up dead poll thread [docbroker_002], started: false, finished: true| ./net/Socket.hpp:512

[chrsch]

I have the same problem runningloolwsd installed from deb packages. So this is not only a docker issue. But for me the workaround with just restart loolwsd doesn'T work if installed from .deb

[xundeenergie]

I have the same problem with docker-compose and nextcloud.
Restarting the container solves it.
But this is only a workaround.

[HHousen]

I too have the same problem with docker-compose and Nextcloud. None of the workarounds I've seen have had an effect.
Here are my other two replies on #7 and #10:
#7: Link
#10: Link

[xundeenergie]

hi ! I restart the single container with docker-compose restart collabora-code It ist part of a docker-compose file Am 22.08.2018 um 20:34 schrieb Brylie Christopher Oxley:

…

@xundeenergie <https://github.com/xundeenergie> what command do you use to restart the container? e.g. do you re-issue the command: |docker run -t -d -p 127.0.0.1:9980:9980 -e 'domain=example\\.domain\\.org' --restart always --cap-add MKNOD collabora/code | — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#16 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AFnyrciyc7IE1UYLFGrntHSU_vjMFEvgks5uTaQ3gaJpZM4N-whR>.