[Solved]Nextcloud hang each time I upload a file

Hello all,
I’m facing an issue that drive me crazy for a while:
I’m running Nextcloud 12.0.5 on a Debian Jessy, wtih nginx and mariadb.
It’s running on a raspberry pi3, so it is using php 5.4

Now my issue : Each time I try to upload a file in nextcloud, either via the web interface or the sync client, the system seems to hang out after a while: it upload the file, then the sync client stuck on “getting sync data” (translation from french :slight_smile: ) for a few minutes and then end up with an error “connection closed”.
However, the file is sometimes still correctly uploaded. Problem is when they are many files or file uploaded is changed again on client side before the end of the stuck part, where strange behavior will occurs (new file deleted by the older version still on the server for example).
I monitored it via htop and it seems that a php-fpm process keep running for a long time after the file upload and is never released : it always time out whatever the time out duration I set (I tryed until 3600s!)
The issue occurs whatever the size of the file (even with a “touch testfile” in the sync folder, it will happen)

I can’t find anything useful in the nextcloud log, even in debug mode, nor in the php-fpm log, even in debug mode:

[10-Mar-2018 21:03:22.678442] DEBUG: pid 8318, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool nextcloud] currently 1 active children, 4 spare children, 5 running children. Spawning rate 2
[10-Mar-2018 21:03:22.678483] DEBUG: pid 8318, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool www] currently 0 active children, 2 spare children, 2 running children. Spawning rate 1
[10-Mar-2018 21:03:22.708764] DEBUG: pid 8318, fpm_event_loop(), line 424: event module triggered 2 events
[10-Mar-2018 21:03:22.708882] DEBUG: pid 8318, fpm_got_signal(), line 76: received SIGCHLD
[10-Mar-2018 21:03:22.709018] DEBUG: pid 8318, fpm_children_bury(), line 254: [pool nextcloud] child 2745 has been killed by the process management after 29.060002 seconds from start
[10-Mar-2018 21:03:22.709053] DEBUG: pid 8318, fpm_event_loop(), line 424: event module triggered 1 events

In config.php, I disabled file locking (I’m nearly the only one to use this server, so not very useful):

<?php
$CONFIG = array (
  'passwordsalt' => 'removed',
  'secret' => 'removed',
  'trusted_domains' => 
  array (
    0 => 'localhost',
    1 => 'removed',
  ),
  'datadirectory' => '/media/PersonnalCloud/nextcloud/data',
  'overwrite.cli.url' => 'http://localhost',
  'dbtype' => 'mysql',
  'version' => '12.0.5',
  'dbname' => 'nextcloud',
  'dbhost' => 'localhost',
  'dbport' => '',
  'dbtableprefix' => 'oc_',
  'dbuser' => 'removed',
  'dbpassword' => 'removed',
  'logtimezone' => 'UTC',
  'installed' => true,
  'instanceid' => 'ocbxlsvr5cj5',
  'ldapIgnoreNamingRules' => false,
  'ldapProviderFactory' => '\\OCA\\User_LDAP\\LDAPProviderFactory',
  'updatechecker' => false,
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'integrity.check.disabled' => true,
  'maintenance' => false,
  'loglevel' => 1,
  'tempdirectory' => '/media/PersonnalCloud/tmp',
  'trashbin_retention_obligation' => 'auto',
  'versions_retention_obligation' => 'auto, 365',
  'theme' => '',
  'preview_max_x' => 1024,
  'preview_max_y' => 1024,
  'preview_max_scale_factor' => 1,
  'filelocking.enabled' => false,
);

Output of nextcloud log:

|Debug|user_ldap|Ready for a paged search|2018-03-10T21:04:20+0100|
|---|---|---|---|
|Debug|user_ldap|initializing paged search for Filter (&(|(objectclass=posixAccount))(uid=nicolas)) base Array ( [0] => ou=users,dc=yunohost,dc=org ) attr Array ( [0] => dn [1] => uid [2] => samaccountname [3] => memberof [4] => userquota [5] => mail [6] => displayname [7] => [8] => jpegphoto [9] => thumbnailphoto ) limit 500 offset 0|2018-03-10T21:04:20+0100|
|Debug|user_ldap|Ready for a paged search|2018-03-10T21:04:16+0100|
|Debug|user_ldap|initializing paged search for Filter (&(objectClass=posixGroup)(uniqueMember=uid=diane,ou=users,dc=yunohost,dc=org)) base Array ( [0] => ou=groups,dc=yunohost,dc=org ) attr Array ( [0] => cn [1] => dn ) limit 500 offset 0|2018-03-10T21:04:16+0100|
|Debug|user_ldap|Ready for a paged search|2018-03-10T21:04:16+0100|
|Debug|user_ldap|initializing paged search for Filter (&(objectClass=posixGroup)(objectClass=posixGroup)(gidNumber=36039)) base Array ( [0] => ou=groups,dc=yunohost,dc=org ) attr Array ( [0] => dn ) limit 1 offset 0|2018-03-10T21:04:16+0100|
|Debug|user_ldap|Ready for a paged search|2018-03-10T21:04:16+0100|
|Debug|user_ldap|initializing paged search for Filter objectClass=* base Array ( [0] => uid=diane,ou=users,dc=yunohost,dc=org ) attr Array ( [0] => gidnumber ) limit 500 offset 0|2018-03-10T21:04:16+0100|
|Debug|user_ldap|Requested attribute primarygroupid not found for uid=diane,ou=users,dc=yunohost,dc=org|2018-03-10T21:04:16+0100|
|Debug|user_ldap|Ready for a paged search|2018-03-10T21:04:16+0100|
|Debug|user_ldap|initializing paged search for Filter objectClass=* base Array ( [0] => uid=diane,ou=users,dc=yunohost,dc=org ) attr Array ( [0] => primarygroupid ) limit 500 offset 0|2018-03-10T21:04:16+0100|
|Debug|user_ldap|Ready for a paged search|2018-03-10T21:04:16+0100|
|Debug|user_ldap|initializing paged search for Filter (&(|(objectclass=posixAccount))(uid=diane)) base Array ( [0] => ou=users,dc=yunohost,dc=org ) attr Array ( [0] => dn [1] => uid [2] => samaccountname [3] => memberof [4] => userquota [5] => mail [6] => displayname [7] => [8] => jpegphoto [9] => thumbnailphoto ) limit 500 offset 0|2018-03-10T21:04:16+0100|
|Debug|user_ldap|Ready for a paged search|2018-03-10T21:04:16+0100|
|Debug|user_ldap|initializing paged search for Filter (&(|(objectclass=posixAccount))(uid=diane)) base Array ( [0] => ou=users,dc=yunohost,dc=org ) attr Array ( [0] => dn [1] => uid [2] => samaccountname [3] => memberof [4] => userquota [5] => mail [6] => displayname [7] => [8] => jpegphoto [9] => thumbnailphoto ) limit 500 offset 0|2018-03-10T21:04:16+0100|
|Debug|user_ldap|Ready for a paged search|2018-03-10T21:03:58+0100|
|Debug|user_ldap|initializing paged search for Filter (&(|(objectclass=posixAccount))(uid=nicolas)) base Array ( [0] => ou=users,dc=yunohost,dc=org ) attr Array ( [0] => dn [1] => uid [2] => samaccountname [3] => memberof [4] => userquota [5] => mail [6] => displayname [7] => [8] => jpegphoto [9] => thumbnailphoto ) limit 500 offset 0|2018-03-10T21:03:58+0100|
|Debug|user_ldap|Ready for a paged search|2018-03-10T21:03:49+0100|
|Debug|user_ldap|initializing paged search for Filter (&(|(objectclass=posixAccount))(uid=nicolas)) base Array ( [0] => ou=users,dc=yunohost,dc=org ) attr Array ( [0] => dn [1] => uid [2] => samaccountname [3] => memberof [4] => userquota [5] => mail [6] => displayname [7] => [8] => jpegphoto [9] => thumbnailphoto ) limit 500 offset 0|2018-03-10T21:03:49+0100|
|Info|user_ldap|No paged search for us, Cpt., Limit 500 Offset 500|2018-03-10T21:00:02+0100|
|Info|user_ldap|Looking for cookie L/O 500/0|2018-03-10T21:00:02+0100|

Anyone having an idea on which direction to search?
Krakinou

the answer is here : raspberry pi3 + i suppose a usb hdd

Lame hardware.

sorry.

Hi,
Well, I certainly don’t expect high performance from my rasp, but a 0 byte file that time out a php process after 3600s seems to be very very VERY low performance, even with a usb HDD…
Sounds more like a misconfig or a bug to me…

i read your conf file, and nothing seem weird.

Check php.ini consistency in /etc/php/5.4/ cgi/cli/fpm

Thanks for taken the time to look.
I tried, but I don’t know what to look for…
as far as I can tell, everything seems fine… most setting are just default ones

my rules for php consistency is to have the same set of option between the three main ini files, and also to have the nextcloud php ini equal.

after that, raspery are using the same i/o channel between usb/network. might be linked. On the openmediavault forum, some threads were about troubles when smb/cifs is enable …

I think I find the culprit (the fact of opening a new thread gave me an idea):
While uploading a file, i ran

    lsof -p "PID number of the php-fpm process"

and I noticed that the last open dir was //data/app_dataXXXXXXX/preview/.
And in this folder, I have more than 6GB of preview generated over time.

So I moved all the preview to a temp folder and tadaaaa, upload succesfully completed without problem for a new file!

So in the end, I guess you were right :slight_smile: : lame hardware and big data…

I don’t understand why uploading a file open the preview folder though, I thought preview were generated when accessing the file in the web interface, not during upload (moreover upload of file without preview??)

i am so sorry to be right !!! :slight_smile:

but good idea on your side

I noticed there is a bug opened, with a kind of workaround.
Maybe solved one day…