Hello
I have been trying to get the Collabora docker to work for a few days, but without success. I appreciate any help. Please let me know if there is a need for more info.
I can connect to the server just fine when I try to activate it in Nextcloud. I get a nice green checkmark, but when I try to open a file, I get
“Failed to load Collabora developer edition, please try again later” in the GUI. The error message from Nextcloud’s log is found below
I can also connect to the admin interface for Collabora, but navigating to anything beside the first admin page errors out.
My environment
I have more services running at home, everything behind a reverse proxy. The proxy handles SSL termination for some services, and some services connects to the backend over SSL as well. Working flawless for most things. The backend for the services is a mix of FreeNAS jails on the same box, and a Ubuntu box
Reverse Proxy
FreeNas 11.3
Apache 2.41
mod_md for ssl
Nextcloud
Served from cloud.domain.tld.
The software stack is
FreeNAS 11.3
Apache 2.41, and mod_md taking care of SSL
Mariadb 103
PHP 7.2
Nextcloud 18.04
Collabora app 3.6.0
Collabora
Collabora is behind the Proxy as well, served from office.domain.tld, Collabora is served on port 443, one among several vhosts.
Ubuntu 18.04
Apache2 reverse proxy
Collabora Docker image - latest as of 2020-05-13
I followed the instructions here: https://nextcloud.com/collaboraonline/.
Error logs and messages
Log from Nextcloud when opening a document
[richdocuments] Error: Doctrine\DBAL\Exception\InvalidFieldNameException: An exception occurred while executing 'INSERT INTO `oc_richdocuments_wopi`(`fileid`,`owner_uid`,`editor_uid`,`version`,`canwrite`,`server_host`,`token`,`expiry`,`template_destination`,`hide_download`,`direct`,`is_remote_token`,`template_id`) VALUES(?,?,?,?,?,?,?,?,?,?,?,?,?)' with params [1214349, "Kim", "Kim", 0, true, "https:\/\/cloud.REDACTED\/", "bTlpfxtwudGbVHkPARTLY REDACTED", 1589395547, 0, false, false, false, 0]:
SQLSTATE[42S22]: Column not found: 1054 Unknown column 'template_destination' in 'field list' at <<closure>>
0. /usr/local/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/DBALException.php line 169
Doctrine\DBAL\Driver\AbstractMySQLDriver->convertException("An exception oc ... '", Doctrine\DBAL\Dr ... ]})
1. /usr/local/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/DBALException.php line 145
Doctrine\DBAL\DBALException::wrapException(Doctrine\DBAL\Driver\PDOMySql\Driver {}, Doctrine\DBAL\Dr ... ]}, "An exception oc ... '")
2. /usr/local/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Statement.php line 162
Doctrine\DBAL\DBALException::driverExceptionDuringQuery(Doctrine\DBAL\Driver\PDOMySql\Driver {}, Doctrine\DBAL\Dr ... ]}, "INSERT INTO `oc ... )", {1: 1214349,2: " ... 0})
3. /usr/local/www/nextcloud/lib/public/AppFramework/Db/Mapper.php line 255
Doctrine\DBAL\Statement->execute()
4. /usr/local/www/nextcloud/lib/public/AppFramework/Db/Mapper.php line 129
OCP\AppFramework\Db\Mapper->execute("INSERT INTO `*P ... )", [1214349,"Kim"," ... 0])
5. /usr/local/www/nextcloud/apps/richdocuments/lib/Db/WopiMapper.php line 89
OCP\AppFramework\Db\Mapper->insert(OCA\Richdocuments\Db\Wopi {id: null})
6. /usr/local/www/nextcloud/apps/richdocuments/lib/TokenManager.php line 205
OCA\Richdocuments\Db\WopiMapper->generateFileToken("*** sensitive parameter replaced ***", "Kim", "Kim", "0", 1, "https://cloud.REDACTED/", null, 0, false, false, false, 0, null)
7. /usr/local/www/nextcloud/apps/richdocuments/lib/Controller/DocumentController.php line 238
OCA\Richdocuments\TokenManager->getToken("*** sensitive parameters replaced ***")
8. /usr/local/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php line 170
OCA\Richdocuments\Controller\DocumentController->index("*** sensitive parameter replaced ***")
9. /usr/local/www/nextcloud/lib/private/AppFramework/Http/Dispatcher.php line 99
OC\AppFramework\Http\Dispatcher->executeController(OCA\Richdocument ... {}, "index")
10. /usr/local/www/nextcloud/lib/private/AppFramework/App.php line 125
OC\AppFramework\Http\Dispatcher->dispatch(OCA\Richdocument ... {}, "index")
11. /usr/local/www/nextcloud/lib/private/AppFramework/Routing/RouteActionHandler.php line 47
OC\AppFramework\App::main("OCA\\Richdocume ... r", "index", OC\AppFramework\ ... {}, {_route: "richdocuments.document.index"})
12. <<closure>>
OC\AppFramework\Routing\RouteActionHandler->__invoke({_route: "richdocuments.document.index"})
13. /usr/local/www/nextcloud/lib/private/Route/Router.php line 299
call_user_func(OC\AppFramework\ ... {}, {_route: "richdocuments.document.index"})
14. /usr/local/www/nextcloud/lib/base.php line 1008
OC\Route\Router->match("/apps/richdocuments/index")
15. /usr/local/www/nextcloud/index.php line 38
OC::handleRequest()
GET /index.php/apps/richdocuments/index?fileId=1214349&requesttoken=PARTLY_REDACTED
from 192.168.1.1 by Kim at 2020-05-13T20:15:47+02:00
The docker container’s log is completely filled with
wsd-00007-00036 2020-05-13 18:15:33.631716 [ websrv_poll ] WRN Poco::Net::DNS::resolve("192.168.1.5") failed: Host not found: 192.168.1.5| wsd/LOOLWSD.cpp:2187
192.168.1.5 is the IP of the reverse proxy. I suspect that is the clue to what is wrong, but I lack the skill to say what might be wrong.
I can probably find more info in the docker log, but I do not know how to set the log level to debug in the image. I am a complete docker noob as is evident
Reverse proxy log
Log from the fron reverse proxy, the one running in a FreeNas jail. Log sampled from when I try to open a document
[Thu May 14 07:15:01.887690 2020] [socache_shmcb:debug] [pid 85236:tid 34531953152] mod_socache_shmcb.c(493): AH00831: socache_shmcb_store (0xd4 -> subcache 20)
[Thu May 14 07:15:01.887905 2020] [socache_shmcb:debug] [pid 85236:tid 34531953152] mod_socache_shmcb.c(847): AH00847: insert happened at idx=1, data=(202:234)
[Thu May 14 07:15:01.887935 2020] [socache_shmcb:debug] [pid 85236:tid 34531953152] mod_socache_shmcb.c(850): AH00848: finished insert, subcache: idx_pos/idx_used=0/2, data_pos/data_used=0/405
[Thu May 14 07:15:01.887962 2020] [socache_shmcb:debug] [pid 85236:tid 34531953152] mod_socache_shmcb.c(515): AH00834: leaving socache_shmcb_store successfully
[Thu May 14 07:15:01.888760 2020] [ssl:debug] [pid 85236:tid 34531953152] ssl_engine_kernel.c(376): [client 192.168.1.1:34311] AH02034: Initial (No.1) HTTPS request received for child 18 (server office.REDACTED:443)
[Thu May 14 07:15:01.888858 2020] [authz_core:debug] [pid 85236:tid 34531953152] mod_authz_core.c(843): [client 192.168.1.1:34311] AH01628: authorization result: granted (no directives)
[Thu May 14 07:15:01.888947 2020] [proxy:debug] [pid 85236:tid 34531953152] mod_proxy.c(1253): [client 192.168.1.1:34311] AH01143: Running scheme https handler (attempt 0)
[Thu May 14 07:15:01.888980 2020] [proxy:debug] [pid 85236:tid 34531953152] proxy_util.c(2336): AH00942: HTTPS: has acquired connection for (192.168.1.79)
[Thu May 14 07:15:01.889011 2020] [proxy:debug] [pid 85236:tid 34531953152] proxy_util.c(2392): [client 192.168.1.1:34311] AH00944: connecting https://192.168.1.79/hosting/capabilities to 192.168.1.79:443
[Thu May 14 07:15:01.889062 2020] [proxy:debug] [pid 85236:tid 34531953152] proxy_util.c(2615): [client 192.168.1.1:34311] AH00947: connected /hosting/capabilities to 192.168.1.79:443
[Thu May 14 07:15:01.889259 2020] [proxy:debug] [pid 85236:tid 34531953152] proxy_util.c(2916): AH00951: HTTPS: backend socket is disconnected.
[Thu May 14 07:15:01.889606 2020] [proxy:debug] [pid 85236:tid 34531953152] proxy_util.c(3081): AH02824: HTTPS: connection established with 192.168.1.79:443 (192.168.1.79)
[Thu May 14 07:15:01.889695 2020] [proxy:debug] [pid 85236:tid 34531953152] proxy_util.c(3267): AH00962: HTTPS: connection complete to 192.168.1.79:443 (192.168.1.79)
[Thu May 14 07:15:01.889727 2020] [ssl:info] [pid 85236:tid 34531953152] [remote 192.168.1.79:443] AH01964: Connection to child 0 established (server office.REDACTED:443)
[Thu May 14 07:15:01.904907 2020] [ssl:debug] [pid 85236:tid 34531953152] ssl_engine_kernel.c(1741): [remote 192.168.1.79:443] AH02275: Certificate Verification, depth 1, CRL checking mode: none (0) [subject: CN=Let's Encrypt Authority X3,O=Let's Encrypt,C=US / issuer: CN=DST Root CA X3,O=Digital Signature Trust Co. / serial: 0A0141420000015385736A0B85ECA708 / notbefore: Mar 17 16:40:46 2016 GMT / notafter: Mar 17 16:40:46 2021 GMT]
[Thu May 14 07:15:01.905351 2020] [ssl:debug] [pid 85236:tid 34531953152] ssl_engine_kernel.c(1741): [remote 192.168.1.79:443] AH02275: Certificate Verification, depth 0, CRL checking mode: none (0) [subject: CN=office.REDACTED / issuer: CN=Let's Encrypt Authority X3,O=Let's Encrypt,C=US / serial: 041DE6D3DF7D13220845409409E5323F9650 / notbefore: May 4 14:24:19 2020 GMT / notafter: Aug 2 14:24:19 2020 GMT]
[Thu May 14 07:15:01.907388 2020] [ssl:debug] [pid 85236:tid 34531953152] ssl_engine_kernel.c(2231): [remote 192.168.1.79:443] AH02041: Protocol: TLSv1.2, Cipher: ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)
[Thu May 14 07:15:01.907550 2020] [ssl:debug] [pid 85236:tid 34531953152] ssl_util_ssl.c(444): AH02412: [office.REDACTED:443] Cert matches for name 'office.REDACTED' [subject: CN=office.REDACTED / issuer: CN=Let's Encrypt Authority X3,O=Let's Encrypt,C=US / serial: 041DE6D3DF7D13220845409409E5323F9650 / notbefore: May 4 14:24:19 2020 GMT / notafter: Aug 2 14:24:19 2020 GMT]
[Thu May 14 07:15:01.912099 2020] [proxy:debug] [pid 85236:tid 34531953152] proxy_util.c(2351): AH00943: https: has released connection for (192.168.1.79)
[Thu May 14 07:15:01.918132 2020] [ssl:debug] [pid 85236:tid 34531953152] ssl_engine_io.c(1102): [client 192.168.1.1:34311] AH02001: Connection closed to child 18 with standard shutdown (server office.REDACTED:443)
Log from reverse proxy on the machine with collabora
[Thu May 14 06:15:38.796862 2020] [ssl:debug] [pid 5846:tid 140655883974400] ssl_engine_kernel.c(383): [client 192.168.1.5:20591] AH02034: Initial (No.1) HTTPS request received for child 13 (server office.REDACTED:443)
[Thu May 14 06:15:38.796886 2020] [authz_core:debug] [pid 5846:tid 140655883974400] mod_authz_core.c(835): [client 192.168.1.5:20591] AH01628: authorization result: granted (no directives)
[Thu May 14 06:15:38.796906 2020] [proxy:debug] [pid 5846:tid 140655883974400] mod_proxy.c(1229): [client 192.168.1.5:20591] AH01143: Running scheme https handler (attempt 0)
[Thu May 14 06:15:38.796911 2020] [proxy_ajp:debug] [pid 5846:tid 140655883974400] mod_proxy_ajp.c(738): [client 192.168.1.5:20591] AH00894: declining URL https://127.0.0.1:9980/hosting/capabilities
[Thu May 14 06:15:38.796916 2020] [proxy:debug] [pid 5846:tid 140655883974400] proxy_util.c(2177): AH00942: HTTPS: has acquired connection for (127.0.0.1)
[Thu May 14 06:15:38.796921 2020] [proxy:debug] [pid 5846:tid 140655883974400] proxy_util.c(2230): [client 192.168.1.5:20591] AH00944: connecting https://127.0.0.1:9980/hosting/capabilities to 127.0.0.1:9980
[Thu May 14 06:15:38.796926 2020] [proxy:debug] [pid 5846:tid 140655883974400] proxy_util.c(2439): [client 192.168.1.5:20591] AH00947: connected /hosting/capabilities to 127.0.0.1:9980
[Thu May 14 06:15:38.796955 2020] [socache_shmcb:debug] [pid 5846:tid 140655883974400] mod_socache_shmcb.c(557): AH00837: socache_shmcb_remove (0x59 -> subcache 25)
[Thu May 14 06:15:38.796960 2020] [socache_shmcb:debug] [pid 5846:tid 140655883974400] mod_socache_shmcb.c(571): AH00839: leaving socache_shmcb_remove successfully
[Thu May 14 06:15:38.797031 2020] [proxy:debug] [pid 5846:tid 140655883974400] proxy_util.c(2740): AH00951: HTTPS: backend socket is disconnected.
[Thu May 14 06:15:38.797078 2020] [proxy:debug] [pid 5846:tid 140655883974400] proxy_util.c(2908): AH02824: HTTPS: connection established with 127.0.0.1:9980 (127.0.0.1)
[Thu May 14 06:15:38.797086 2020] [proxy:debug] [pid 5846:tid 140655883974400] proxy_util.c(3075): AH00962: HTTPS: connection complete to 127.0.0.1:9980 (127.0.0.1)
[Thu May 14 06:15:38.797092 2020] [ssl:info] [pid 5846:tid 140655883974400] [remote 127.0.0.1:9980] AH01964: Connection to child 0 established (server office.REDACTED:443)
[Thu May 14 06:15:38.798644 2020] [ssl:debug] [pid 5846:tid 140655883974400] ssl_engine_kernel.c(1751): [remote 127.0.0.1:9980] AH02275: Certificate Verification, depth 1, CRL checking mode: none (0) [subject: CN=Dummy Authority,O=Dummy Authority,L=Stuttgart,ST=BW,C=DE / issuer: CN=Dummy Authority,O=Dummy Authority,L=Stuttgart,ST=BW,C=DE / serial: 2E80C549FDB9C4585F944E87CAF3ACA988A1C1FE / notbefore: May 13 18:14:10 2020 GMT / notafter: May 13 18:14:10 2045 GMT]
[Thu May 14 06:15:38.798670 2020] [ssl:debug] [pid 5846:tid 140655883974400] ssl_engine_kernel.c(1751): [remote 127.0.0.1:9980] AH02275: Certificate Verification, depth 1, CRL checking mode: none (0) [subject: CN=Dummy Authority,O=Dummy Authority,L=Stuttgart,ST=BW,C=DE / issuer: CN=Dummy Authority,O=Dummy Authority,L=Stuttgart,ST=BW,C=DE / serial: 2E80C549FDB9C4585F944E87CAF3ACA988A1C1FE / notbefore: May 13 18:14:10 2020 GMT / notafter: May 13 18:14:10 2045 GMT]
[Thu May 14 06:15:38.798739 2020] [ssl:debug] [pid 5846:tid 140655883974400] ssl_engine_kernel.c(1751): [remote 127.0.0.1:9980] AH02275: Certificate Verification, depth 0, CRL checking mode: none (0) [subject: CN=office\\\\.REDACTED\\\\.se,O=Dummy Authority,L=Stuttgart,ST=BW,C=DE / issuer: CN=Dummy Authority,O=Dummy Authority,L=Stuttgart,ST=BW,C=DE / serial: 0C0D79DAAA03828B1CEB1D867F55014FA3E07C03 / notbefore: May 13 18:14:10 2020 GMT / notafter: May 13 18:14:10 2045 GMT]
[Thu May 14 06:15:38.798894 2020] [ssl:debug] [pid 5846:tid 140655883974400] ssl_engine_kernel.c(2233): [remote 127.0.0.1:9980] AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_256_GCM_SHA384 (256/256 bits)
[Thu May 14 06:15:38.799013 2020] [ssl:debug] [pid 5846:tid 140655883974400] ssl_engine_kernel.c(2233): [remote 127.0.0.1:9980] AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_256_GCM_SHA384 (256/256 bits)
[Thu May 14 06:15:38.799050 2020] [ssl:debug] [pid 5846:tid 140655883974400] ssl_engine_kernel.c(2233): [remote 127.0.0.1:9980] AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_256_GCM_SHA384 (256/256 bits)
[Thu May 14 06:15:38.800898 2020] [proxy:debug] [pid 5846:tid 140655883974400] proxy_util.c(2192): AH00943: https: has released connection for (127.0.0.1)
[Thu May 14 06:15:43.801113 2020] [ssl:debug] [pid 5846:tid 140655800047360] ssl_engine_io.c(1106): [client 192.168.1.5:20591] AH02001: Connection closed to child 23 with standard shutdown (server office.REDACTED:443)