Hi all!
I have a strange problem with latest Collabora + Nextcloud, when I try to open a document.
The following well-known message appears usually after 25 seconds of “Connecting…”:
“Well, this is embarrassing, we cannot connect to your document. Please try again.”
But now comes the strange behavior:
If I perform some collabora editor actions (like uploading an image) while connecting, it starts working immediately!
See also the debug log below, before and after uploading the image.
There are no JS errors in the browser, no nginx and no collabora errors at all.
It just gives collabora a kick.
I also tried many variations of /etc/resolve.conf, which resulted either in an immediate popup of this error message or no change at all.
I also read lots of other related posts, set up the whole server twice…
Thanks a lot!
My setup:
- Ubuntu 16.04 LTS
- kernel 4.4.0-62-generic with kernel extras
- docker 1.13.1
- aufs kernel support is available
- latest collabora/code, loolwsd 2.0.3
- wonderfall/nextcloud 11.0.1
- jwilder/nginx-proxy
- sameersbn/bind:9.9.5
docker info
Containers: 11
Running: 9
Paused: 0
Stopped: 2
Images: 11
Server Version: 1.13.1
Storage Driver: aufs
Root Dir: /var/lib/docker/aufs
Backing Filesystem: extfs
Dirs: 92
Dirperm1 Supported: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
Volume: local
Network: bridge host macvlan null overlay
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: aa8187dbd3b7ad67d8e5e3a15115d3eef43a7ed1
runc version: 9df8b306d01f59d3a8029be411de015b7304dd8f
init version: 949e6fa
Security Options:
apparmor
seccomp
Profile: default
Kernel Version: 4.4.0-62-generic
Operating System: Ubuntu 16.04.2 LTS
OSType: linux
Architecture: x86_64
CPUs: 8
Total Memory: 23.48 GiB
Name: puck996
ID: RCWJ:F6MY:E4SS:WWPP:UYDC:E7DM:FDJP:RVLX:GZKJ:R7EK:7777:CVDM
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): false
Registry: https://index.docker.io/v1/
Experimental: false
Insecure Registries:
127.0.0.0/8
Live Restore Enabled: false
wsd-00033-0034 21:08:54.047549 [ client_req_hdl ] INF Request from 172.18.0.5:44936: POST /loleaflet/2.0.3/loleaflet.html?WOPISrc=https%3A%2F%2Fcloud2.domain.at%2Fapps%2Frichdocuments%2Fwopi%2Ffiles%2F110_ocadc83b19e7&title=New%20Spreadsheet.ods&lang=en&closebutton=1&revisionhistory=1 HTTP/1.1 / Host: office.domain.at / Connection: close / X-Real-IP: 210.47.118.125 / X-Forwarded-For: 210.47.118.125 / X-Forwarded-Proto: https / X-Forwarded-Ssl: on / X-Forwarded-Port: 443 / Content-Length: 45 / Cache-Control: max-age=0 / Origin: null / Upgrade-Insecure-Requests: 1 / User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/56.0.2924.87 Safari/537.36 / Content-Type: application/x-www-form-urlencoded / Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8 / DNT: 1 / Accept-Encoding: gzip, deflate, br / Accept-Language: de-DE,de;q=0.8,en-US;q=0.6,en;q=0.4 / Cookie: cc2e6d07390afdb582b0d357eb22d1f5=i3mbijkhi2fvhs3j6nu9b3e6r6; _ga=GA1.2.145858230.1447332834; f7a8116916e4709f9034b00e655a9d92=us9v9bhat38kmun3p19etbb5k1
wsd-00033-0034 21:08:54.047719 [ client_req_hdl ] DBG Preprocessing file: /usr/share/loolwsd//loleaflet/dist/loleaflet.html
wsd-00033-0034 21:08:54.047855 [ client_req_hdl ] WRN WOPI host did not pass optional access_token_ttl| wsd/FileServer.cpp:255
wsd-00033-0035 21:08:54.526418 [ client_req_hdl ] INF Request from 172.18.0.5:44938: GET /lool/https%3A%2F%2Fcloud2.domain.at%2Fapps%2Frichdocuments%2Fwopi%2Ffiles%2F110_ocadc83b19e7%3Faccess_token%3D9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V%26access_token_ttl%3D0%26permission%3Dedit/ws HTTP/1.1 / Host: office.domain.at / Upgrade: websocket / Connection: upgrade / X-Real-IP: 210.47.118.125 / X-Forwarded-For: 210.47.118.125 / X-Forwarded-Proto: https / X-Forwarded-Ssl: on / X-Forwarded-Port: 443 / Pragma: no-cache / Cache-Control: no-cache / Origin: https://office.domain.at / Sec-WebSocket-Version: 13 / User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/56.0.2924.87 Safari/537.36 / DNT: 1 / Accept-Encoding: gzip, deflate, sdch, br / Accept-Language: de-DE,de;q=0.8,en-US;q=0.6,en;q=0.4 / Cookie: cc2e6d07390afdb582b0d357eb22d1f5=i3mbijkhi2fvhs3j6nu9b3e6r6; _ga=GA1.2.145858230.1447332834; f7a8116916e4709f9034b00e655a9d92=us9v9bhat38kmun3p19etbb5k1 / Sec-WebSocket-Key: ktYGyUfM6G1lyf0kBrhZuw== / Sec-WebSocket-Extensions: permessage-deflate; client_max_window_bits
wsd-00033-0035 21:08:54.526489 [ client_ws_001b ] DBG Thread started.| wsd/LOOLWSD.cpp:1141
wsd-00033-0035 21:08:54.526514 [ client_ws_001b ] DBG Handling: /lool/https%3A%2F%2Fcloud2.domain.at%2Fapps%2Frichdocuments%2Fwopi%2Ffiles%2F110_ocadc83b19e7%3Faccess_token%3D9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V%26access_token_ttl%3D0%26permission%3Dedit/ws| wsd/LOOLWSD.cpp:1144
wsd-00033-0035 21:08:54.526659 [ client_ws_001b ] INF Starting GET request handler for session [001b].| wsd/LOOLWSD.cpp:763
wsd-00033-0035 21:08:54.526753 [ client_ws_001b ] DBG No DocumentBroker with docKey [/apps/richdocuments/wopi/files/110_ocadc83b19e7] found. New Child and Document.| wsd/LOOLWSD.cpp:853
wsd-00033-0035 21:08:54.526797 [ client_ws_001b ] DBG getNewChild: Have 1 children, forking 1| wsd/LOOLWSD.cpp:430
wsd-00033-0035 21:08:54.526848 [ client_ws_001b ] DBG MasterToForKit: spawn 1| wsd/LOOLWSD.cpp:310
wsd-00033-0035 21:08:54.526911 [ client_ws_001b ] DBG getNewChild: Returning new child [2001].| wsd/LOOLWSD.cpp:442
wsd-00033-0035 21:08:54.526928 [ clifrk-00041-0041 21:08:54.527001 [ loolforkit ] INF ForKit command: [spawn 1].| kit/ForKit.cpp:93
frk-00041-0041 21:08:54.527077 [ loolforkit ] INF Spawning 1 child per request.| kit/ForKit.cpp:101
frk-00041-0041 21:08:54.527107 [ loolforkit ] INF Creating 1 new child.| kit/ForKit.cpp:419
frk-00041-0041 21:08:54.527133 [ loolforkit ] DBG Forking a loolkit process.| kit/ForKit.cpp:209
frk-00041-0041 21:08:54.531262 [ loolforkit ] INF Forked kit [2066].| kit/ForKit.cpp:244
kit-02066-2066 21:08:54.531991 [ loolkit ] INF Initializing kit
kit-02066-2066 21:08:54.532199 [ loolkit ] INF Log level is [7].
kit-02066-2066 21:08:54.532260 [ loolkit ] DBG Process started.| kit/Kit.cpp:1494
kit-02066-2066 21:08:54.532366 [ loolkit ] INF Jail path: /opt/lool/child-roots/2066/| kit/Kit.cpp:1508
kit-02066-2066 21:08:54.532743 [ loolkit ] DBG symlink("../lo","/opt/lool/child-roots/2066/opt/collaboraoffice5.1")| kit/Kit.cpp:265
ent_ws_001b ] DBG New DocumentBroker for docKey [/apps/richdocuments/wopi/files/110_ocadc83b19e7].| wsd/LOOLWSD.cpp:885
wsd-00033-0035 21:08:54.527026 [ client_ws_001b ] INF DocumentBroker [https://cloud2.domain.at/apps/richdocuments/wopi/files/110_ocadc83b19e7?access_token=9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V&access_token_ttl=0&permission=edit] created. DocKey: [/apps/richdocuments/wopi/files/110_ocadc83b19e7]| wsd/DocumentBroker.cpp:172
wsd-00033-0035 21:08:54.527074 [ client_ws_001b ] DBG Query param: access_token, value: 9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V| wsd/LOOLWSD.cpp:908
wsd-00033-0035 21:08:54.527092 [ client_ws_001b ] DBG Query param: access_token_ttl, value: 0| wsd/LOOLWSD.cpp:908
wsd-00033-0035 21:08:54.527108 [ client_ws_001b ] DBG Query param: permission, value: edit| wsd/LOOLWSD.cpp:908
wsd-00033-0035 21:08:54.527126 [ client_ws_001b ] INF ClientSession ctor [ToClient-001b].
wsd-00033-0035 21:08:54.527289 [ client_ws_001b ] INF Loading [/apps/richdocuments/wopi/files/110_ocadc83b19e7] for session [001b] and jail [2001].| wsd/DocumentBroker.cpp:198
wsd-00033-0035 21:08:54.527314 [ client_ws_001b ] DBG Loading from URI: https://cloud2.domain.at/apps/richdocuments/wopi/files/110_ocadc83b19e7?access_token=9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V&access_token_ttl=0&permission=edit| wsd/DocumentBroker.cpp:214
wsd-00033-0035 21:08:54.527340 [ client_ws_001b ] INF jailPath: /user/docs/2001, jailRoot: /opt/lool/child-roots/2001| wsd/DocumentBroker.cpp:229
wsd-00033-0035 21:08:54.527361 [ client_ws_001b ] DBG Creating new storage instance for URI [https://cloud2.domain.at/apps/richdocuments/wopi/files/110_ocadc83b19e7?access_token=9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V&access_token_ttl=0&permission=edit].| wsd/DocumentBroker.cpp:236
wsd-00033-0035 21:08:54.527382 [ client_ws_001b ] INF Public URI [https://cloud2.domain.at/apps/richdocuments/wopi/files/110_ocadc83b19e7?access_token=9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V&access_token_ttl=0&permission=edit] considered WOPI.| wsd/Storage.cpp:174
wsd-00033-0035 21:08:54.527424 [ client_ws_001b ] DBG Storage ctor: https://cloud2.domain.at/apps/richdocuments/wopi/files/110_ocadc83b19e7?access_token=9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V&access_token_ttl=0&permission=edit
wsd-00033-0035 21:08:54.527443 [ client_ws_001b ] INF WopiStorage ctor with localStorePath: [/opt/lool/child-roots/2001], jailPath: [/user/docs/2001], uri: [https://cloud2.domain.at/apps/richdocuments/wopi/files/110_ocadc83b19e7?access_token=9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V&access_token_ttl=0&permission=edit].
wsd-00033-0035 21:08:54.527461 [ client_ws_001b ] DBG Getting info for wopi uri [https://cloud2.domain.at/apps/richdocuments/wopi/files/110_ocadc83b19e7?access_token=9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V&access_token_ttl=0&permission=edit].
wsd-00033-2065 21:08:54.528436 [ client_ws_001b ] DBG ToClient-001b SenderThread started| wsd/ClientSession.cpp:468
wsd-00033-0035 21:08:54.600830 [ client_ws_001b ] DBG WOPI::CheckFileInfo returned: {"BaseFileName":"New Spreadsheet.ods","Size":7134,"Version":"0","UserId":"admin","OwnerId":"admin","UserFriendlyName":"admin","UserCanWrite":true,"PostMessageOrigin":"https:\/\/cloud2.domain.at\/"}. Call duration: 0.073348s
wsd-00033-0035 21:08:54.600959 [ client_ws_001b ] WRN Missing JSON property [HidePrintOption]| wsd/Storage.cpp:353
wsd-00033-0035 21:08:54.600988 [ client_ws_001b ] WRN Missing JSON property [HideSaveOption]| wsd/Storage.cpp:353
wsd-00033-0035 21:08:54.601012 [ client_ws_001b ] WRN Missing JSON property [HideExportOption]| wsd/Storage.cpp:353
wsd-00033-0035 21:08:54.601043 [ client_ws_001b ] WRN Missing JSON property [EnableOwnerTermination]| wsd/Storage.cpp:353
wsd-00033-0035 21:08:54.601064 [ client_ws_001b ] WRN Missing JSON property [DisablePrint]| wsd/Storage.cpp:353
wsd-00033-0035 21:08:54.601085 [ client_ws_001b ] WRN Missing JSON property [DisableExport]| wsd/Storage.cpp:353
wsd-00033-0035 21:08:54.601104 [ client_ws_001b ] WRN Missing JSON property [DisableCopy]| wsd/Storage.cpp:353
wsd-00033-0035 21:08:54.601328 [ clienkit-02001-2001 21:08:54.685940 [ loolkit ] DBG child_ws_2001: recv [session 001b /apps/richdocuments/wopi/files/110_ocadc83b19e7].| kit/Kit.cpp:1663
kit-02001-2001 21:08:54.685990 [ loolkit ] INF New session [001b] request on url [/apps/richdocuments/wopi/files/110_ocadc83b19e7].| kit/Kit.cpp:1678
kit-02001-2001 21:08:54.686025 [ loolkit ] INF Document ctor for url [/apps/richdocuments/wopi/files/110_ocadc83b19e7] on child [2001].| kit/Kit.cpp:460
kit-02001-2001 21:08:54.686088 [ loolkit ] INF Creating first session for url: /apps/richdocuments/wopi/files/110_ocadc83b19e7 for sessionId: 001b on jailId: 2001| kit/Kit.cpp:494
kit-02001-2001 21:08:54.686124 [ loolkit ] INF ChildSession ctor [ToMaster-001b].| kit/ChildSession.cpp:46
kit-02001-2067 21:08:54.686120 [ lok_handler ] DBG Thread started.| kit/Kit.cpp:1309
kit-02001-2001 21:08:54.686146 [ loolkit ] DBG Sessions: 1| kit/Kit.cpp:499
kit-02066-2066 21:08:54.859557 [ loolkit ] DBG Initialized jail files.| kit/Kit.cpp:1565
kit-02066-2066 21:08:54.859869 [ loolkit ] INF chroot("/opt/lool/child-roots/2066/")| kit/Kit.cpp:1582
kit-02066-2066 21:08:54.860038 [ loolkit ] DBG Initialized jail nodes, dropped caps.| kit/Kit.cpp:1599
kit-02066-2066 21:08:54.920407 [ loolkit ] INF Process is ready.| kit/Kit.cpp:1626
kit-02066-2066 21:08:54.921490 [ loolkit ] INF SocketProcessor [child_ws_2066] starting.| common/IoUtil.cpp:49
image upload using the “insert graphic” icon of the editor"
(still “Connecting…”)
kit-02001-2001 21:09:18.760656 [ loolkit ] DBG child_ws_2001: recv [child-001b load url=https://cloud2.domain.at/apps/richdocuments/wopi/files/110_ocadc83b19e7?access_token=9dtnk6HqTf1...].| kit/Kit.cpp:1663
kit-02001-2001 21:09:18.760834 [ loolkit ] DBG child_ws_2001: recv [child-001b partpagerectangles].| kit/Kit.cpp:1663
kit-02001-2067 21:09:18.760900 [ lok_handler ] INF Loading session [001b] on url [file:///user/docs/2001/New%20Spreadsheet.ods] is loading. 1 views loaded.| kit/Kit.cpp:912
kit-02001-2067 21:09:18.760988 [ lok_handler ] INF Loading new document from URI: [file:///user/docs/2001/New%20Spreadsheet.ods] for session [001b].| kit/Kit.cpp:1126
kit-02001-2001 21:09:18.760931 [ loolkit ] DBG child_ws_2001: recv [child-001b getchildid].| kit/Kit.cpp:1663
kit-02001-2067 21:09:18.761037 [ lok_handler ] DBG Calling lokit::documentLoad.| kit/Kit.cpp:1141
kit-02001-2067 21:09:19.016862 [ lok_handler ] DBG Returned lokit::documentLoad.| kit/Kit.cpp:1143
kit-02001-2067 21:09:19.034544 [ lok_handler ] INF Document [/apps/richdocuments/wopi/files/110_ocadc83b19e7] view [0] loaded. Have 1 view.| kit/Kit.cpp:1247
kit-02001-2067 21:09:19.034614 [ lok_handler ] INF Created new view with viewid: [0] for username: [admin] in session: [001b].| kit/ChildSession.cpp:339
kit-02001-2067 21:09:19.034662 [ lok_handler ] DBG Sending status after loading view 0.| kit/ChildSession.cpp:352
kit-02001-2067 21:09:19.035071 [ lok_handler ] INF Loaded session 001b| kit/ChildSession.cpp:370
kit-02001-2001 21:09:19.084185 [ loolkit ] DBG child_ws_2001: recv [child-001b commandvalues command=.uno:StyleApply].| kit/Kit.cpp:1663
kit-02001-2001 21:09:19.089672 [ loolkit ] DBG child_ws_2001: recv [child-001b commandvalues command=.uno:CharFontName].| kit/Kit.cpp:1663
t_ws_001b ] DBG Session [001b] is the document owner| wsd/DocumentBroker.cpp:290
wsd-00033-0035 21:08:54.601377 [ client_ws_001b ] DBG Setting username [admin] and userId [admin] for session [001b]| wsd/DocumentBroker.cpp:306
wsd-00033-0035 21:08:54.601392 [ client_ws_001b ] DBG Wopi requesting: https://cloud2.domain.at/apps/richdocuments/wopi/files/110_ocadc83b19e7/contents?access_token=9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V&access_token_ttl=0&permission=edit
wsd-00033-0035 21:08:54.684923 [ client_ws_001b ] INF WOPI::GetFile downloaded 6549 bytes from [https://cloud2.domain.at/apps/richdocuments/wopi/files/110_ocadc83b19e7/contents?access_token=9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V&access_token_ttl=0&permission=edit] -> /opt/lool/child-roots/2001/user/docs/2001/New Spreadsheet.ods in 0.0834662s : 200 OK| wsd/Storage.cpp:475
wsd-00033-0035 21:08:54.685330 [ client_ws_001b ] INF TileCache ctor for uri [https://cloud2.domain.at/apps/richdocuments/wopi/files/110_ocadc83b19e7?access_token=9dtnk6HqTf1cSGxgH4J6QJcNtc22Ys0V&access_token_ttl=0&permission=edit] modifiedTime=1487020134 getLastModified()=0
wsd-00033-0035 21:08:54.686185 [ client_ws_001b ] DBG Added admin document [/apps/richdocuments/wopi/files/110_ocadc83b19e7].| wsd/AdminModel.cpp:247
wsd-00033-0035 21:08:54.693812 [ client_ws_001b ] INF PrisonerSession ctor [ToPrisoner-001b].| wsd/PrisonerSession.cpp:44
wsd-00033-0035 21:08:54.693979 [ client_ws_001b ] INF SocketProcessor [client_ws_001b] starting.| common/IoUtil.cpp:49
wsd-00033-0037 21:08:54.921156 [ prsnr_req_hdl ] INF Request from 127.0.0.1:54542: GET /loolws/newchild?pid=2066 HTTP/1.0 / Connection: Upgrade / Upgrade: websocket / Sec-WebSocket-Version: 13 / Sec-WebSocket-Key: NRSHSx4J03dO+YtWKqWVCw== / Host: 127.0.0.1:9981
wsd-00033-0037 21:08:54.921210 [ prsnr_req_hdl ] INF New child [2066].| wsd/LOOLWSD.cpp:1312
wsd-00033-0037 21:08:54.921415 [ prsnr_req_hdl ] INF ChildProcess ctor [2066].| wsd/DocumentBroker.hpp:51
wsd-00033-0037 21:08:54.921441 [ prsnr_req_hdl ] INF Have 1 child.| wsd/LOOLWSD.cpp:401
wsd-00033-2074 21:08:54.921517 [ docbrk_ws_2066 ] INF SocketProcessor [docbrk_ws_2066] starting.| common/IoUtil.cpp:49
wsd-00033-0035 21:09:18.760235 [ client_ws_001b ] INF Requesting document load from child.
...
...
...