Collabora "connecting" delay for 20 seconds

Hello everyone ,
I see the solution docker like me has a slow 20s. I have a VM with the docker and therefore nextcloud. I see that you have succeeded in exiting collaborated, can t we have a summary in tutorial to like you?
How itā€™ll work after when update if we stop the docker?

thank you

This is for the initial problem with the docker image (where the 20 second Problem remains with certain setups?)

# docker logs IMAGE_NAME_OR_NUMBER output for 20 seconds as following:

kit-00066-04 00:32:30.088271 [ kit_queue_0005 ] Session 0005 is loading. 0 views loaded. kit-00066-04 00:32:30.088300 [ kit_queue_0005 ] Loading new document from URI: [file:///user/docs/66/my-doc.docx] for session [0005]. kit-00066-04 00:32:30.088314 [ kit_queue_0005 ] Calling lokit::documentLoad. wsd-00020-15 00:32:30.334252 [ wsd_queue_0005 ] ToClient-0005 Recv: status wsd-00020-15 00:32:30.334964 [ wsd_queue_0005 ] ToClient-0005: handling [status]. wsd-00020-15 00:32:30.334998 [ wsd_queue_0005 ] Could not open /var/cache/loolwsd/4/f/b/03beec80a94b068f9e6407ab0a4b802567751/status.txt wsd-00020-15 00:32:30.335015 [ wsd_queue_0005 ] ToClient-0005 -> ToPrisoner-0005: status wsd-00020-15 00:32:30.335034 [ wsd_queue_0005 ] ToPrisoner-0005 Send: 6 bytes wsd-00020-15 00:32:30.335118 [ wsd_queue_0005 ] ToClient-0005 Recv: partpagerectangles wsd-00020-15 00:32:30.335140 [ wsd_queue_0005 ] ToClient-0005: handling [partpagerectangles]. wsd-00020-15 00:32:30.335161 [ wsd_queue_0005 ] Could not open /var/cache/loolwsd/4/f/b/03beec80a94b068f9e6407ab0a4b802567751/partpagerectangles.txt wsd-00020-15 00:32:30.335175 [ wsd_queue_0005 ] ToClient-0005 -> ToPrisoner-0005: partpagerectangles wsd-00020-15 00:32:30.335191 [ wsd_queue_0005 ] ToPrisoner-0005 Send: 18 bytes wsd-00020-00 00:32:30.599320 [ loolwsd ] Nothing to autosave [my.nextcloud.net/index.php/apps/richdocuments/wopi/files/169]. wsd-00020-10 00:32:32.802173 [ loolwsd ] Total memory used: 305284 wsd-00020-10 00:32:47.822702 [ loolwsd ] Total memory used: 305356 kit-00066-04 00:32:50.157427 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_START []. kit-00066-04 00:32:50.166889 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [4]. kit-00066-04 00:32:50.169376 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [8]. kit-00066-04 00:32:50.169482 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [12]. kit-00066-04 00:32:50.172691 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [16]. kit-00066-04 00:32:50.172765 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [20]. kit-00066-04 00:32:50.172832 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [24]. kit-00066-04 00:32:50.172909 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [28]. kit-00066-04 00:32:50.172980 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [32]. kit-00066-04 00:32:50.173107 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [36]. kit-00066-04 00:32:50.176601 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [40]. kit-00066-04 00:32:50.176696 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [44]. kit-00066-04 00:32:50.179868 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [48]. kit-00066-04 00:32:50.183275 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [52]. kit-00066-04 00:32:50.183384 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [56]. kit-00066-04 00:32:50.185098 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [60]. kit-00066-04 00:32:50.185290 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [64]. kit-00066-04 00:32:50.185369 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [68]. kit-00066-04 00:32:50.185573 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [72]. kit-00066-04 00:32:50.185664 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [76]. kit-00066-04 00:32:50.185756 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [80]. kit-00066-04 00:32:50.185827 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [84]. kit-00066-04 00:32:50.185897 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [88]. kit-00066-04 00:32:50.185966 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [92]. kit-00066-04 00:32:50.186045 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [96]. kit-00066-04 00:32:50.186114 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_SET_VALUE [100]. kit-00066-04 00:32:50.186838 [ kit_queue_0005 ] Document::DocumentCallback STATUS_INDICATOR_FINISH []. kit-00066-04 00:32:50.318518 [ kit_queue_0005 ] Returned lokit::documentLoad. kit-00066-04 00:32:50.348326 [ kit_queue_0005 ] Sending status after load.

So I see two cache, ā€˜could not openā€™ problems before a 15 sec. pause.
Someone?

Maybe you should enter into your docker image :

docker exec -i -t CONTENER_ID /bin/bash

then go into the folder : /var/cache/loolwsd and see the permissions with ls -ll

Maybe there is a permission problem.

Iā€™m gonna make a tutorial for extracting files from docker in order to have it working smoothly.

Thank you for the idea! But I think the permissions are alright?
-rw-r--r-- 1 lool lool 43 Aug 22 12:55 partpagerectangles.txt -rw-r--r-- 1 lool lool 61 Aug 22 12:55 status.txt

A second view on a second log - I thought maybe itā€™s not the two files, but rather something about the memory allocation? But perhaps the two are related tooā€¦
First log:
wsd-00020-00 00:32:30.599320 [ loolwsd ] Nothing to autosave [my.nc.net/index.php/apps/richdocuments/wopi/files/169]. wsd-00020-10 00:32:32.802173 [ loolwsd ] Total memory used: 305284 wsd-00020-10 00:32:47.822702 [ loolwsd ] Total memory used: 305356 kit-00066-04 00:32:50.157427 [ kit_queue_0005 ] Document::DocumentCallback ...
Second:
kit-00062-04 03:22:46.818813 [ kit_queue_0007 ] Calling lokit::documentLoad. wsd-00020-02 03:22:47.065459 [ prison_ws_0007 ] Message to admin console: adddoc 62 mydoc.docx 0007 128620 wsd-00020-02 03:22:47.065626 [ prison_ws_0007 ] SocketProcessor starting. wsd-00020-10 03:22:51.580593 [ loolwsd ] Total memory used: 304944 wsd-00020-00 03:23:01.598173 [ loolwsd ] Nothing to autosave [my.nc.net/index.php/apps/richdocuments/wopi/files/178]. wsd-00020-10 03:23:06.597875 [ loolwsd ] Total memory used: 305016 kit-00062-04 03:23:06.893370 [ kit_queue_0007 ] Document::DocumentCallback STATUS_INDICATOR_START [].

I donā€™t have a seperate memory setup for docker and the debian system is running in a VM.

// After investigating a little into this, is this a debian/ubuntu-like issue? I donā€™t think it is possible to enable kernel memory on these systems right now. The end of # docker info:
WARNING: No kernel memory limit support and this is relevant for:?
SocketProcessor starting. //

This doesnā€™t seem to matterā€¦ anyway, a fedora24 docker installation having this 20 seconds too. The log looks pretty much the same too.

I changed the permissions of /var/cache/loolwsd to 777, but that didnā€™t change to better, it broke the saving mechanism, I think.

Is it possible that the two documents are just not yet created and thus canā€™t be opened at the time?

hi all. OP here. iā€™ve been doing some further investigation and iā€™ve found the source of the 20 second delay. ironically it was, as I initially suspected, a DNS lookup.

by performing a tcpdump on the docker0 interface using the original (first) collabora docker image I could see a whole pile of DNS lookup requests directed to 192.168.65.1. this isnā€™t an IP that has anything to do with my infrastructure or anything to do with my docker setup.

when I updated to the most recent collabora docker image, this has now changed to direct to 192.168.100.1. again, not an IP address thatā€™s related to me.

09:35:30.230560 IP 172.17.0.1.59310 > 192.168.100.1.53: 57049+ A? fca10b4e59a4.site. (35)
09:35:35.235168 IP 172.17.0.1.59310 > 192.168.100.1.53: 57049+ A? fca10b4e59a4.site. (35)

when I first saw this I jumped into the collabora image and searched for references to 192.168.65.1. I repeated this for the current docker image and found this:

/opt/lool/systemplate/etc/resolv.conf:
# Generated by NetworkManager
search site
nameserver 192.168.100.1

i tried to change this, but the edit didnā€™t seem to apply. iā€™m suspecting this file is automatically generated when the docker image launches.

at the moment iā€™m trying to see if there is anything in docker i can reconfigure to accommodate for this. i know that in docker 1.10 and above there is a DNS proxy feature and I wonder if there is somehow I can setup docker to receive the DNS requests and proxy them across.

iā€™m still not sure where the 192.168.100.1 IP address is generated from, and I also donā€™t know why this IP changed from the first image 192.168.65.1. interestingly enough if I google for docker and either of these two IP addresses I find quite a few users with similar setups. i havenā€™t built anything in docker and I donā€™t know if any of this originates from an introductory guide or similar.

if the person who is responsible for creating this docker image is available to comment and perhaps provide any information about how the docker daemon is launched on their system with any specific networking options this might greatly assist. it would also be of great interest if either of the two above IP addresses mean anything to the original builders infrastructure.

iā€™ll post up more information if I discover anything that I can change in docker land that changes this functionality.

cheers, wizdude.

ugly hack #1

iptables -t nat -I PREROUTING -d 192.168.100.1 -p udp --dport 53 -j DNAT --to-destination (your nameserver ip)

eg:
iptables -t nat -I PREROUTING -d 192.168.100.1 -p udp --dport 53 -j DNAT --to-destination 192.168.25.11

bang. documents come up right away.

this is a horrible solution to the problem. the DNS requests are essentially failing, but failing very quickly rather than timing out.

iā€™m trying to work on getting the docker embedded DNS proxy working. I suspect iā€™ll need to change the IP of the docker bridge to 192.168.100.1 in order to get this working as intended. this will probably work for people (such as myself) that have spun up a VM solely for the purpose of running collabora, but would not be a solution for those running on an existing docker host.

iā€™m still unsure how the collabora container is meant to have its DNS configured, but that might be something for the creator of it to answer.

1 Like

Hi,

thats not horrible ā€¦ thats great :rocket:

Works like a charm :slight_smile:

Thanks.

Cheers,
Andreas

1 Like

another ugly hack ???

I just renamed the file

/opt/lool/systemplate/etc/resolv.conf to /opt/lool/systemplate/etc/resolv.conf_bak

and created a soft link to the system resolv.conf

 ln -s /etc/resolv.conf /opt/lool/systemplate/etc/resolv.conf

Seems to be okay too :slight_smile:

Cheers,
Andreas

1 Like

You can change the nameserver in /etc/resolv.conf inside a docker container via the --dns=ip option to the docker run command.

I just tested this, but it doesnā€™t change the delayā€¦ Is CODE using the /opt/lool/systemplate/etc/resolv.conf file?

iā€™ve just been trying to do the same thing, but i canā€™t work out how to save the changes. whenever i get into the container like:

docker run -it collabora/code /bin/bash

and make any changes and exit, none of them stick. from what i understand with docker this is ā€œby designā€.

whatā€™s the procedure to be able to make maintenance changes to a docker image and commit them locally?

edit: i taught myself how to use ā€œdocker commitā€ and iā€™ve worked this part out now.

I just tested this, but it doesnā€™t change the delayā€¦ Is CODE using the /opt/lool/systemplate/etc/resolv.conf file?

no - this is the problem. docker ensures that the /etc/resolv.conf is provided via a special mount (so the contents of this file inside the image are not actually used). the --dns-ip option allows you to override the default action which is to simply use the contents of the host /etc/resolv.conf. normally this option isnā€™t required unless you have a nameserver bound to the loopback adapter of the host or similar weird/special config.

from what I understand the /opt/lool/systemplate/ is like a chroot jail used by the environment of the document editor, so itā€™s the collabora subprocess which sees this as the resolv.conf to use. this comes factory prepared from the person who packaged this image as 192.168.100.1 (and it was 192.168.65.1 in the previous release).

@guddl 's response above seems like a good solution to this issue - assuming that the chroot jail or whatever collabora uses is happy with a symbolic link.

iā€™m guessing that since the /etc/resolv.conf is mounted in by docker that it would probably be recommended to rename the file and create the symbolic link in the /start-libreoffice.sh or /etc/rc.local or something simiilar. iā€™m not sure how solid a symbolic link to a mount would be.

ok. iā€™ve got this working ok now. i removed the /opt/look/systemplate/etc/resolv.conf file and modified the beginning of /start-libreoffice.sh so it reads like:

#!/bin/sh

# Fix lool resolv.conf problem (wizdude)
ln -s /etc/resolv.conf /opt/lool/systemplate/etc/resolv.conf

# Generate new SSL certificate instead of using the default

iā€™ve run some tcpdumpā€™s and Iā€™m not seeing any DNS query related problems anymore. Collabora Online is working great - nice and quick and no more delays.

i think the creator of this docker should be notified of this issue. are they here reading this thread? or do I need to report this back somewhere else?

cheers, wizdude

1 Like

Maybe this script is used inside the Dockerifle/Docker container to build the resulting docker container? https://github.com/LibreOffice/online/blob/master/loolwsd/loolwsd-systemplate-setup#L26

@jospoortvliet can you point this issue and the solution to the team which created the docker container? Maybe it would be good to explain a bit more how the docker container is created, or share the Dockerfile, so more people can have a look at it/improve it? Thanks!

1 Like

thank you for your solution but it does not rule my house.
I have the resolv.conf I delete and I do well the symbolic link.
by cons must restart after you?
For information on symbolic link is removed if I stop the docker, you must then redo the symbolic link.
ps: I have two for a certificate for a nextcloud and collaborated.
You have an idea?

Is working i change .sh and is working
I upgraded a docker image of collabora .

But i have a slow file to open whis a caracter spƩcial ! in france you have example

file open correctly : liberte.xls
file not open slow : libertƩ.xls

are you this problem ?

1 Like

See this : Collabora docker fails to open files with special chars

1 Like

thks i looking !

question : you have testing collabora whis nextcloud V10 ?

I started with 10.0 Beta now i am on 10.0 stable. Itā€™s working well

1 Like

hi nemskiller thks
and if you have time to create tuto i love u :slight_smile:

Here it is : [HOWTO] Collabora 2.0 without using Docker not for prod