Owncloud client frequent disconnections

Desktop
1

Expected behaviour

The client should stay online and stay sync’d

Actual behaviour

The client randomly disconnects (times can vary from minutes to hours) with an error "Server https://server.company.com is temporarily unavailable

Steps to reproduce

Login.
Wait.

Server configuration

Operating system: Ubuntu 18.0.4

Web server: Apache2

Database: mysql

PHP version: 7.2

ownCloud version: 10.5.0.10

Storage backend (external storage): smb (Apple and Synology NAS)

Client configuration

Client version: 10.15

Operating system: MacOS

OS language: English

Qt version used by client package (Linux only, see also Settings dialog): N/A

Client package (From ownCloud or distro) (Linux only): N/A

Installation path of client: /Users/Applications

Logs

Template for output < 10 lines

  1. Client logfile: Output of owncloud --logwindow or owncloud --logfile log.txt
    (On Windows using cmd.exe, you might need to first cd into the ownCloud directory)

  2. Web server error log: [Mon Sep 28 06:25:13.381915 2020] [mpm_prefork:notice] [pid 1796] AH00163: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 configured – resuming normal operations
    [Mon Sep 28 06:25:13.381941 2020] [core:notice] [pid 1796] AH00094: Command line: ‘/usr/sbin/apache2’
    [Mon Sep 28 15:37:22.722791 2020] [mpm_prefork:notice] [pid 1796] AH00171: Graceful restart requested, doing restart
    AH00558: apache2: Could not reliably determine the server’s fully qualified domain name, using 127.0.1.1. Set the ‘ServerName’ directive globally to suppress this message
    [Mon Sep 28 15:37:22.863616 2020] [mpm_prefork:notice] [pid 1796] AH00163: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 configured – resuming normal operations
    [Mon Sep 28 15:37:22.863634 2020] [core:notice] [pid 1796] AH00094: Command line: ‘/usr/sbin/apache2’
    [Mon Sep 28 15:37:29.974502 2020] [mpm_prefork:notice] [pid 1796] AH00171: Graceful restart requested, doing restart
    AH00558: apache2: Could not reliably determine the server’s fully qualified domain name, using 127.0.1.1. Set the ‘ServerName’ directive globally to suppress this message
    [Mon Sep 28 15:37:30.069139 2020] [mpm_prefork:notice] [pid 1796] AH00163: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 configured – resuming normal operations
    [Mon Sep 28 15:37:30.069165 2020] [core:notice] [pid 1796] AH00094: Command line: ‘/usr/sbin/apache2’
    [Mon Sep 28 15:37:33.115370 2020] [mpm_prefork:notice] [pid 1796] AH00171: Graceful restart requested, doing restart
    AH00558: apache2: Could not reliably determine the server’s fully qualified domain name, using 127.0.1.1. Set the ‘ServerName’ directive globally to suppress this message
    [Mon Sep 28 15:37:33.185415 2020] [mpm_prefork:notice] [pid 1796] AH00163: Apache/2.4.29 (Ubuntu) OpenSSL/1.1.1 configured – resuming normal operations
    [Mon Sep 28 15:37:33.185433 2020] [core:notice] [pid 1796] AH00094: Command line: ‘/usr/sbin/apache2’
    [Tue Sep 29 06:25:06.409884 2020] [mpm_prefork:notice] [pid 1796] AH00171: Graceful restart requested, doing restart
    AH00558: apache2: Could not reliably determine the server’s fully qualified domain name, using 127.0.1.1. Set the ‘ServerName’ directive globally to suppress this message

  3. Server logfile: ownCloud log (data/owncloud.log): (Log file is 68M)

EXTRA INFO
Most users don’t have this issue, but the affected owner is synchronising 5.8TB of files. These are media files and many of them. The issue occurs on any client computer that logs in as this user.

Can’t put lines in from client log as they contain links and these are not allowed from me as I am a new poster.

I should mention too that Owncloud is authenticationg using LDAP to an Apple server running OpenDirectory. I suspect this is where the problems are arising.

2

I cleared the owncloud.log file and grabbed some lines when the problem occurs.

{“reqId”:“7659a044-783d-4720-8a70-54410b07f2a4”,“level”:2,“time”:“2020-10-01T02:13:27+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:“24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a”,“app”:“core”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/WIP",“message”:“Login failed: ‘brad’ (Remote IP: ‘xxx.xxx.142.214’)”}
{“reqId”:“5d9d3174-6d57-42e4-928d-70309c77ef7d”,“level”:3,“time”:“2020-10-01T02:13:29+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“GET”,“url”:"/ocs/v2.php/apps/notifications/api/v1/notifications?format=json",“message”:“Error when searching: Timed out code -5”}
{“reqId”:“5d9d3174-6d57-42e4-928d-70309c77ef7d”,“level”:3,“time”:“2020-10-01T02:13:29+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“GET”,“url”:"/ocs/v2.php/apps/notifications/api/v1/notifications?format=json",“message”:“Attempt for Paging? 1”}
{“reqId”:“5d9d3174-6d57-42e4-928d-70309c77ef7d”,“level”:2,“time”:“2020-10-01T02:13:29+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“core”,“method”:“GET”,“url”:"/ocs/v2.php/apps/notifications/api/v1/notifications?format=json",“message”:“Login failed: ‘brad’ (Remote IP: ‘xxx.xxx.142.214’)”}
{“reqId”:“7659a044-783d-4720-8a70-54410b07f2a4”,“level”:3,“time”:“2020-10-01T02:13:30+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/WIP",“message”:“Error when searching: Timed out code -5”}
{“reqId”:“7659a044-783d-4720-8a70-54410b07f2a4”,“level”:3,“time”:“2020-10-01T02:13:30+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/WIP",“message”:“Attempt for Paging? 1”}
{“reqId”:“5d9d3174-6d57-42e4-928d-70309c77ef7d”,“level”:3,“time”:“2020-10-01T02:13:31+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“GET”,“url”:"/ocs/v2.php/apps/notifications/api/v1/notifications?format=json",“message”:“Error when searching: Timed out code -5”}
{“reqId”:“5d9d3174-6d57-42e4-928d-70309c77ef7d”,“level”:3,“time”:“2020-10-01T02:13:31+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“GET”,“url”:"/ocs/v2.php/apps/notifications/api/v1/notifications?format=json",“message”:“Attempt for Paging? 1”}
{“reqId”:“7659a044-783d-4720-8a70-54410b07f2a4”,“level”:3,“time”:“2020-10-01T02:13:32+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/WIP",“message”:“Error when searching: Timed out code -5”}
{“reqId”:“7659a044-783d-4720-8a70-54410b07f2a4”,“level”:3,“time”:“2020-10-01T02:13:32+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/WIP",“message”:“Attempt for Paging? 1”}
{“reqId”:“7659a044-783d-4720-8a70-54410b07f2a4”,“level”:2,“time”:“2020-10-01T02:13:32+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“core”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/WIP",“message”:“Login failed: ‘brad’ (Remote IP: ‘xxx.xxx.142.214’)”}
{“reqId”:“5d9d3174-6d57-42e4-928d-70309c77ef7d”,“level”:3,“time”:“2020-10-01T02:13:33+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“GET”,“url”:"/ocs/v2.php/apps/notifications/api/v1/notifications?format=json",“message”:“Error when searching: Timed out code -5”}
{“reqId”:“5d9d3174-6d57-42e4-928d-70309c77ef7d”,“level”:3,“time”:“2020-10-01T02:13:33+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“GET”,“url”:"/ocs/v2.php/apps/notifications/api/v1/notifications?format=json",“message”:“Attempt for Paging? 1”}
{“reqId”:“5d9d3174-6d57-42e4-928d-70309c77ef7d”,“level”:2,“time”:“2020-10-01T02:13:33+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“core”,“method”:“GET”,“url”:"/ocs/v2.php/apps/notifications/api/v1/notifications?format=json",“message”:“Login failed: ‘brad’ (Remote IP: ‘xxx.xxx.142.214’)”}
{“reqId”:“ee11a19e-c156-43ff-94bc-d50f093acef4”,“level”:3,“time”:“2020-10-01T02:13:34+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/",“message”:“Error when searching: Timed out code -5”}
{“reqId”:“ee11a19e-c156-43ff-94bc-d50f093acef4”,“level”:3,“time”:“2020-10-01T02:13:34+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/",“message”:“Attempt for Paging? 1”}
{“reqId”:“ee11a19e-c156-43ff-94bc-d50f093acef4”,“level”:2,“time”:“2020-10-01T02:13:34+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“core”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/",“message”:“Login failed: ‘brad’ (Remote IP: ‘xxx.xxx.142.214’)”}
{“reqId”:“cede2598-227e-4171-a41e-ce121b84ca4f”,“level”:3,“time”:“2020-10-01T02:13:36+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/",“message”:“Error when searching: Timed out code -5”}
{“reqId”:“cede2598-227e-4171-a41e-ce121b84ca4f”,“level”:3,“time”:“2020-10-01T02:13:36+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“user_ldap”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/",“message”:“Attempt for Paging? 1”}
{“reqId”:“cede2598-227e-4171-a41e-ce121b84ca4f”,“level”:2,“time”:“2020-10-01T02:13:36+00:00”,“remoteAddr”:“xxx.xxx.142.214”,“user”:"–",“app”:“core”,“method”:“PROPFIND”,“url”:"/remote.php/dav/files/24c8a1ca-7fe0-4f92-a6a6-2ee2b5b2605a/",“message”:“Login failed: ‘brad’ (Remote IP: ‘xxx.xxx.142.214’)”}

3

For me looks like, server is overloaded from time to time.

2 Likes
4

Yes that could be difficult to spot. The server is dedicated to Owncloud and only has about 3 users currrently connected to it. I have increased the cache period to 28800 seconds and the timeout to 120 seconds in LDAP settings. It’s frustrating as other users connected at the same time don’t get disconnected, but they are not syncing as many files in their sessions as the affected client. The client that is affected says that if he notices it as it happens, he can’t log back in for about 30 seconds or so, which does seem to indicate that there is an outage of some description, yet the logs don’t seem to show any issues other than the timeouts themselves.

5

Check https://superuser.com/questions/720636/apache-restarting-graceful-restart-requested-doing-restart/720695

To give a bit more of info, the desktop client will make multiple requests during the sync process. While apache won’t likely cut the connection when it wants to restart, it will definitely reject any new incoming connection until apache it fully up and running again.
Since the client will need to sync such amount of file, it will take a lot of time, and it will likely hit a time when the apache server wants to restart.

2 Likes
6

I think I have tracked the issue down. The problem seemed to be with just one person. That person had 2 computers always connected and syncing to the server. As soon as they stop syncing on one of the computers it seems to be OK. I created a second test account (not LDAP) and he has been running both computers constantly on the two different accounts without an issue. I suspect that there may be an issue with 2 computers connecting simultaneously and syncing. Perhaps because they are on the same public IP address. Still monitoring.

2 Likes