Timeout Error regarding ConvertService.ashx

[maltokyo]

I have everything running reasonably well, with latest version of nextcloud and document server integrated together.

Though, soon after starting up, without any activity, I get these errors in the log.

I still can work on the server with documents, but for some time after this error (a few minues!) everything freezes and I cant open or edit documents.

I could not find a suitable response to this issue, so creating a new issue. Any help appreciated!

nc_onlyoffice_documentserver  | ==> /var/log/onlyoffice/documentserver/converter/err.log <==
nc_onlyoffice_documentserver  | 
nc_onlyoffice_documentserver  | ==> /var/log/onlyoffice/documentserver/converter/out.log <==
nc_onlyoffice_documentserver  | [2024-09-25T11:33:54.631] [WARN] [localhost] [docId] [userId] nodeJS - num of CPUs: 12; availableParallelism: undefined
nc_onlyoffice_documentserver  | [2024-09-25T11:33:54.633] [WARN] [localhost] [docId] [userId] nodeJS - update cluster with 1 workers
nc_onlyoffice_documentserver  | [2024-09-25T11:33:54.641] [WARN] [localhost] [docId] [userId] nodeJS - worker 802 started.
nc_onlyoffice_documentserver  | [2024-09-25T11:33:54.643] [WARN] [localhost] [docId] [userId] nodeJS - num of CPUs: 12; availableParallelism: undefined
nc_onlyoffice_documentserver  | [2024-09-25T11:33:54.643] [WARN] [localhost] [docId] [userId] nodeJS - update cluster with 1 workers
nc_onlyoffice_documentserver  | [2024-09-25T11:34:35.038] [WARN] [localhost] [docId] [userId] nodeJS - num of CPUs: 12; availableParallelism: undefined
nc_onlyoffice_documentserver  | [2024-09-25T11:34:35.039] [WARN] [localhost] [docId] [userId] nodeJS - update cluster with 1 workers
nc_onlyoffice_documentserver  | [2024-09-25T11:34:35.048] [WARN] [localhost] [docId] [userId] nodeJS - worker 1036 started.
nc_onlyoffice_documentserver  | [2024-09-25T11:34:35.050] [WARN] [localhost] [docId] [userId] nodeJS - num of CPUs: 12; availableParallelism: undefined
nc_onlyoffice_documentserver  | [2024-09-25T11:34:35.050] [WARN] [localhost] [docId] [userId] nodeJS - update cluster with 1 workers
nc_onlyoffice_documentserver  | 
nc_onlyoffice_documentserver  | ==> /var/log/onlyoffice/documentserver/docservice/err.log <==
nc_onlyoffice_documentserver  | 
nc_onlyoffice_documentserver  | ==> /var/log/onlyoffice/documentserver/docservice/out.log <==
nc_onlyoffice_documentserver  | [2024-09-25T11:07:16.343] [WARN] [localhost] [docId] [userId] nodeJS - Express server listening on port 8000 in production-linux mode. Version: 8.1.3. Build: 4
nc_onlyoffice_documentserver  | [2024-09-25T11:24:29.758] [WARN] [localhost] [docId] [userId] nodeJS - start shutdown:true
nc_onlyoffice_documentserver  | [2024-09-25T11:24:29.759] [WARN] [localhost] [docId] [userId] nodeJS - active connections: 0
nc_onlyoffice_documentserver  | [2024-09-25T11:24:29.759] [WARN] [localhost] [docId] [userId] nodeJS - end shutdown
nc_onlyoffice_documentserver  | [2024-09-25T11:33:55.065] [WARN] [localhost] [docId] [userId] nodeJS - Express server starting...
nc_onlyoffice_documentserver  | [2024-09-25T11:33:55.068] [WARN] [localhost] [docId] [userId] nodeJS - Failed to subscribe to plugin folder updates. When changing the list of plugins, you must restart the server. https://nodejs.org/docs/latest/api/fs.html#fs_availability
nc_onlyoffice_documentserver  | [2024-09-25T11:33:55.247] [WARN] [localhost] [docId] [userId] nodeJS - Express server listening on port 8000 in production-linux mode. Version: 8.1.3. Build: 4
nc_onlyoffice_documentserver  | [2024-09-25T11:34:33.292] [WARN] [localhost] [docId] [userId] nodeJS - Express server starting...
nc_onlyoffice_documentserver  | [2024-09-25T11:34:33.295] [WARN] [localhost] [docId] [userId] nodeJS - Failed to subscribe to plugin folder updates. When changing the list of plugins, you must restart the server. https://nodejs.org/docs/latest/api/fs.html#fs_availability
nc_onlyoffice_documentserver  | [2024-09-25T11:34:33.449] [WARN] [localhost] [docId] [userId] nodeJS - Express server listening on port 8000 in production-linux mode. Version: 8.1.3. Build: 4
nc_onlyoffice_documentserver  | 
nc_onlyoffice_documentserver  | ==> /var/log/onlyoffice/documentserver/nginx.error.log <==
nc_onlyoffice_documentserver  | 2024/09/25 07:36:21 [error] 7817#7817: *333 upstream timed out (110: Unknown error) while reading response header from upstream, client: 172.18.0.26, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "cloud.mydomain-redacted.com"
nc_onlyoffice_documentserver  | 2024/09/25 07:36:21 [error] 7817#7817: *335 upstream timed out (110: Unknown error) while reading response header from upstream, client: 172.18.0.26, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "cloud.mydomain-redacted.com"
nc_onlyoffice_documentserver  | 2024/09/25 07:36:21 [error] 7817#7817: *337 upstream timed out (110: Unknown error) while reading response header from upstream, client: 172.18.0.26, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "cloud.mydomain-redacted.com"
nc_onlyoffice_documentserver  | 2024/09/25 07:36:22 [error] 7817#7817: *339 upstream timed out (110: Unknown error) while reading response header from upstream, client: 172.18.0.26, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "cloud.mydomain-redacted.com"
nc_onlyoffice_documentserver  | 2024/09/25 07:36:23 [error] 7817#7817: *341 upstream timed out (110: Unknown error) while reading response header from upstream, client: 172.18.0.26, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "cloud.mydomain-redacted.com"
nc_onlyoffice_documentserver  | 2024/09/25 07:37:21 [error] 7817#7817: *343 upstream timed out (110: Unknown error) while reading response header from upstream, client: 172.18.0.26, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "cloud.mydomain-redacted.com"
nc_onlyoffice_documentserver  | 2024/09/25 07:37:21 [error] 7817#7817: *345 upstream timed out (110: Unknown error) while reading response header from upstream, client: 172.18.0.26, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "cloud.mydomain-redacted.com"
nc_onlyoffice_documentserver  | 2024/09/25 07:37:21 [error] 7817#7817: *347 upstream timed out (110: Unknown error) while reading response header from upstream, client: 172.18.0.26, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "cloud.mydomain-redacted.com"
nc_onlyoffice_documentserver  | 2024/09/25 07:37:22 [error] 7817#7817: *349 upstream timed out (110: Unknown error) while reading response header from upstream, client: 172.18.0.26, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "cloud.mydomain-redacted.com"
nc_onlyoffice_documentserver  | 2024/09/25 07:37:23 [error] 7817#7817: *351 upstream timed out (110: Unknown error) while reading response header from upstream, client: 172.18.0.26, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "cloud.mydomain-redacted.com"

[SergeyKorneyev]

Could you enable debug logging, reproduce the issue and post the extended logs here? Log level can be changed the following way:

1. Open /etc/onlyoffice/documentserver/log4js/production.json (if you have a Docker installation, the file is inside the Document Server container)
2. Change the value of the "level" parameter from "WARN" to "DEBUG"
3. Restart the Document Server services to apply the changes. The command is supervisorctl restart all for Docker installations and systemctl restart ds-* for package installations

[maltokyo]

Hi @SergeyKorneyev , thank you for your reply.

I actually seem to have overcome this, but I really think that you should update the nginx config file and the default.json in this repo.

By increasing the timeouts in onlyoffice default.json and max number of child processes in nginx as per the two links below, I no longer get the errors above. To be honest, I am not sure which one worked, or if all was needed. But this has solved my issues.

https://help.nextcloud.com/t/nextcloud-18-onlyoffice-timeout-conversion-error/81012
https://serverfault.com/questions/884256/how-and-where-to-configure-pm-max-children-for-php-fpm-with-docker

[Xu-Xihe]

I also get the same error. It's strange that I have built the onlyofficedoc with docker on my Truenas's 24.10 and it works well. But, to some degree, I want to run this server on my remote server and the issue appeared. I have a 2Core with 2GB memory server running centos7, I first tried to install it within docker but the same error exist. Then I tried to install it locally and I have no way to solve it.
For converter/out.log

[2024-12-07T23:02:21.842] [WARN] [localhost] [docId] [userId] nodeJS - num of CPUs: 2; availableParallelism: undefined
[2024-12-07T23:02:21.845] [WARN] [localhost] [docId] [userId] nodeJS - update cluster with 1 workers
[2024-12-07T23:02:21.864] [WARN] [localhost] [docId] [userId] nodeJS - worker 1295 started.
[2024-12-07T23:02:21.865] [WARN] [localhost] [docId] [userId] nodeJS - num of CPUs: 2; availableParallelism: undefined
[2024-12-07T23:02:21.866] [WARN] [localhost] [docId] [userId] nodeJS - update cluster with 1 workers
[2024-12-07T23:02:22.986] [DEBUG] [localhost] [docId] [userId] nodeJS - [AMQP] connected
[2024-12-07T23:02:50.206] [INFO] [localhost] [check_161724270] [userId] nodeJS - Start Task
[2024-12-07T23:02:50.231] [DEBUG] [localhost] [check_161724270] [userId] nodeJS - isAllowDirectRequest url in jwt token res=true
[2024-12-07T23:04:50.257] [ERROR] [localhost] [check_161724270] [userId] nodeJS - error downloadFile:url=https://192.168.2.107:30027/apps/onlyoffice/empty?doc=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJhY3Rpb24iOiJlbXB0eSJ9.OAjlSf4a7OiOGeE4UqNHTyhNk2Cbg0krxpN9kzoHfbs;attempt=1;code:ETIMEDOUT;connect:null Error: Error: whole request cycle timeout
    at raiseError (/snapshot/server/Common/sources/utils.js)
    at Timeout.<anonymous> (/snapshot/server/Common/sources/utils.js)
    at listOnTimeout (node:internal/timers:559:17)
    at processTimers (node:internal/timers:502:7)
[2024-12-07T23:04:50.257] [DEBUG] [localhost] [check_161724270] [userId] nodeJS - ExitCode (code=0;signal=null;error:-81)
[2024-12-07T23:04:50.258] [DEBUG] [localhost] [check_161724270] [userId] nodeJS - output (data={"ctx":{"tenant":"localhost","docId":"check_161724270","userId":"userId"},"cmd":{"withAuthorization":true,"c":"conv","id":"conv_check_161724270_65","format":"docx","url":"https://192.168.2.107:30027/apps/onlyoffice/empty?doc=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJhY3Rpb24iOiJlbXB0eSJ9.OAjlSf4a7OiOGeE4UqNHTyhNk2Cbg0krxpN9kzoHfbs","title":"check_161724270.docx","outputformat":65,"outputpath":"output.docx","codepage":46,"delimiter":4,"embeddedfonts":false,"status_info":-81,"nobase64":true}})
[2024-12-07T23:04:50.258] [DEBUG] [localhost] [check_161724270] [userId] nodeJS - postProcess
[2024-12-07T23:04:50.260] [DEBUG] [localhost] [check_161724270] [userId] nodeJS - deleteFolderRecursive
[2024-12-07T23:04:50.260] [INFO] [localhost] [check_161724270] [userId] nodeJS - End Task
[2024-12-07T23:04:50.266] [INFO] [localhost] [check_161724270] [userId] nodeJS - ackTask addResponse
[2024-12-07T23:04:50.266] [INFO] [localhost] [check_161724270] [userId] nodeJS - ackTask ack

For nginx

2024/12/07 22:17:12 [error] 28136#28136: *42 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 221.237.85.52, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "ip:30030"
2024/12/07 22:28:54 [error] 29798#29798: *6 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 221.237.85.52, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "ip:30030"
2024/12/07 22:28:56 [error] 29799#29799: *12 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 221.237.85.52, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://[::1]:8000/ConvertService.ashx", host: "ip:30030"
2024/12/07 22:43:30 [error] 30039#30039: *361 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 221.237.85.52, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://[::1]:8000/ConvertService.ashx", host: "ip:30030"
2024/12/07 22:45:48 [error] 30040#30040: *367 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 221.237.85.52, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "ip:30030"
2024/12/07 22:45:50 [error] 30040#30040: *373 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 221.237.85.52, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://[::1]:8000/ConvertService.ashx", host: "ip:30030"
2024/12/07 22:45:53 [error] 30039#30039: *379 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 221.237.85.52, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "ip:30030"
2024/12/07 22:46:29 [error] 30040#30040: *385 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 221.237.85.52, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://127.0.0.1:8000/ConvertService.ashx", host: "ip:30030"
2024/12/07 22:50:41 [error] 30039#30039: *391 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 221.237.85.52, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://[::1]:8000/ConvertService.ashx", host: "ip:30030"
2024/12/07 23:03:50 [error] 30040#30040: *452 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 221.237.85.52, server: , request: "POST /ConvertService.ashx HTTP/1.1", upstream: "http://[::1]:8000/ConvertService.ashx", host: "ip:30030"

Nothing useful in docservice/out.log.
I have set to DEBUG level and ip just stand for my real ip.
But, when I run curl -I http://127.0.0.1:8000/ConvertService.ashx
and
curl -I http://127.0.0.1:8000/healthcheck
Their output:

HTTP/1.1 200 OK
Content-Type: text/xml; charset=UTF-8
Content-Length: 80
ETag: W/"50-3xHctkWXRmDNgp89fZA3Y46PQK0"
Date: Sat, 07 Dec 2024 15:15:15 GMT
Connection: keep-alive
Keep-Alive: timeout=5


HTTP/1.1 200 OK
Content-Type: text/plain; charset=utf-8
Content-Length: 4
ETag: W/"4-X/5TO4MPCKAyY0ipFgr6/IraRNs"
Date: Sat, 07 Dec 2024 15:15:30 GMT
Connection: keep-alive
Keep-Alive: timeout=5

I have tried to set the time from 300 to 30000, but nothing happened.