Closed winstonford closed 2 years ago
How odd, I must admit I've never seen that. Looking at the URL, they suggest using redis as the permanent solution... but the snap uses redis. I can't immediately explain what's going on, so let's take a look at some logs, if you don't mind. First of all, can you paste the output from this script in here?
Also, the Nextcloud log is in the data directory, which by default is /var/snap/nextcloud/common/nextcloud/data
. See anything interesting in there? Or the PHP log, which is in /var/snap/nextcloud/current/apache/logs/php_errors.log
?
Also, yeah, restoring backups in DO might wreak havoc with Nextcloud's file tracking, be very careful.
Any chance this could be related? https://github.com/nextcloud/server/issues/9001
Yes I did read that about Redis and then suspected that the snap was already using it.. so thanks for the confirmation.
Actually was not expecting you to respond so quickly and I already restored the droplet from the same backup 19 hours ago. So unfortunately, all logs are gone.
One thing I noticed was an error on creating my test file. As I said, I created the test file in the browser, using the plus icon and creating a new file of 0 bytes. I saw an error about a file of zero size just before the lock error. So I wonder if that was related.
As for the redis race 9001 issue you asked about, I can't say.. although that says upload a bigger file, and as I said mine was actually an zero byte file.
As for restoring the droplet from a a back up, the only error I saw in the web ui stated that something wasn't right because my last cron job had run 19 hours ago, instead of 15 minutes ago. But as soon as the first cron ran, that warning disappeared and all seemed well.
As for my files being deleted, I believe this may be related to a setting somewhere where I said to sync deletes.
I will let you know if i see any odd behavior and check logs this time.
Thanks again for maintaining this snap!
ok having this error again after moving folders.
I am dealing with a sudden loss of available disk space and so looking for any larger tmp files I can remove and came across this:
139M Feb 3 03:44 /var/snap/nextcloud/11139/mysql/epi.err
Which surprised me because I did not think the snap is using mysql.
Something keep gobbling up disk such that / would go to 100%
snap stop nextcloud
was hanging so I deleted this 153m cache file:
-rw-r--r-- 1 root root 153M Mar 8 2018 /var/lib/snapd/cache/36976c1d357ad94c7bb47c0c77909e0ea23dd14ae86a46183b80e6994673697559b3de61d345b754f2092ceb461b047d
and was then able to stop the snap
now a df -h
shows that my / is stable with 165M available
/dev/vda1 49G 49G 165M 100% /
where as before it kept going to 0m available after I would free up space
Ok here are the previously requested log files:
-rw-r----- 1 root root 34M Feb 9 16:31 /var/snap/nextcloud/common/nextcloud/data/nextcloud.log
nextcloud.log.tar.gz
when I tailed this nextcloud log I got many many lines in the terminal which look like one long line with no spaces.
-rw-r--r-- 1 root root 5M Feb 9 16:42 /var/snap/nextcloud/current/apache/logs/php_errors.log
unfortunately I ruined this log file with a bad tar cmd.
This is what I got when I tailed it prior to destroying it:
`root@epi:/# tail /var/snap/nextcloud/current/apache/logs/php_errors.log
[09-Feb-2019 21:42:29 UTC] PHP Fatal error: Uncaught RedisException: MISCONF Redis is configured to save RDB snapshots, but it is currently not able to persist on disk. Commands that may modify the data set are disabled, because this instance is configured to report errors during writes if RDB snapshotting fails (stop-writes-on-bgsave-error option). Please check the Redis logs for details about the RDB error. in /snap/nextcloud/11337/htdocs/lib/private/Memcache/Redis.php:64 Stack trace:
Ok now installed ncdu to look for big files and found some here:
/var/snap/nextcloud/common/nextcloud/data/__groupfolders
19.7 GiB [##########] /trash
(Tailing the nextcloud.log I did see 'trash' quite a few times.)
When I look in that trash dir I see the same file many times:
5.1 MiB [##########] 30-boltmount-rev3v2PLAcWp1x19.3mf.d1549746257
5.1 MiB [##########] 30-boltmount-rev3v2PLAcWp1x19.3mf.d1549746256
The filename ends in .3mf so the string that follows: 49746257 may literally be the number of times the file occurs in the trash, as it looks to be sequential.
Indeed, the snap uses mysql. Any chance all your problems stem from having a full disk? You can definitely try emptying Nextcloud's trash if you're comfortable with that:
$ sudo nextcloud.occ trashbin:cleanup
Ok happy to empty the trash.. tho I have a strong feeling that the trash is exactly what caused the full disk in the first place.
ok deleted trash for all users
so that freed about 2gb, but the trash mentioned earlier remains at 19.7gb:
/var/snap/nextcloud/common/nextcloud/data/__groupfolders/trash/2 19.7 GiB [##########] /2
One of my machines just connected and began to sync, threw 403 forbidden errors, and now the disk space is full again. This is pretty ruinous, I'm not sure what to do. I stopped the snap.
group folders trash instantly grew by 2gb.
/var/snap/nextcloud/common/nextcloud/data/__groupfolders 21.9 GiB [##########] /trash
I got a nice error trying to empty the trash. Looking for Redis logs..
root@epi:/# nextcloud.occ trashbin:cleanup An unhandled exception has been thrown: RedisException: MISCONF Redis is configured to save RDB snapshots, but it is currently not able to persist on disk. Commands that may modify the data set are disabled, because this instance is configured to report errors during writes if RDB snapshotting fails (stop-writes-on-bgsave-error option). Please check the Redis logs for details about the RDB error. in /snap/nextcloud/11337/htdocs/lib/private/Memcache/Redis.php:64 Stack trace:
What the heck. Is that sync moving a huge directory around, perhaps? Something that Nextcloud might translate into new uploads as well as deletions? That redis error definitely sounds like a full disk.
I would not call it huge, but the lock problems did begin with moving a folder, a groupfolder. I suspect this problem may related to trash and groupfolder in nextcloud 15 and have posted the issue there. Sorry for the distraction as I do not believe this issue has to do with the nextcloud snap.
Maybe not related, but in the blog post announcing the recent updates https://nextcloud.com/blog/time-to-update-nextcloud-15.0.4-14.0.7-and-13.0.11-are-here/ they talk about this improvement:
In all versions:
- A better cleanup of stray locks helps reduce “File locked” errors
Maybe updating to 15.0.4 helps in some way...
@kyrofa any recommendations on how I might remove & re-install the nextcloud snap on the same server?
I have copied out all of my data and plan to just add it to a fresh install of nextcloud server.
@winstonford check out nextcloud.export
and nextcloud.import
.
After a power failure I got the following:
Server replied "423 Locked" to "MKCOL https://nextcloudserveraddresshere/remote.php/dav/files/path-to-filename-here"
A similar problem occurred to me today.
My nextcloud-client [on Debian GNU/Linux 9.12 (stretch) ] :
Server replied "423 Locked" to "PUT ......
nextcloud --version
Nextcloud version 2.5.1git
Using Qt 5.7.1, built against Qt 5.7.1
Using 'OpenSSL 1.0.2u 20 Dec 2019'
On the server side. Description: Ubuntu 16.04.6 LTS (xenial) Nextcoud: Nextcloud 17.0.2
Why does this happen without anything changing (by server at least) ? Is this a client problem? Because really nothing has changed on my server.
Same here. Using Redis store. My cache config looks like this:
'filelocking.enabled' => true,
'memcache.local' => '\OC\Memcache\APCu',
'memcache.distributed' => '\OC\Memcache\Redis',
'memcache.locking' => '\OC\Memcache\Redis',
'redis' => [
'host' => '127.0.0.1',
'port' => 6379,
],
I only use APCu
.
{
"system": {
"instanceid": "***REMOVED SENSITIVE VALUE***",
"passwordsalt": "***REMOVED SENSITIVE VALUE***",
"secret": "***REMOVED SENSITIVE VALUE***",
"trusted_domains": [
"*******"
],
"datadirectory": "***REMOVED SENSITIVE VALUE***",
"dbtype": "mysql",
"version": "17.0.2.1",
"overwrite.cli.url": "http:\/\/**********",
"htaccess.RewriteBase": "\/",
"dbname": "***REMOVED SENSITIVE VALUE***",
"dbhost": "***REMOVED SENSITIVE VALUE***",
"dbport": "",
"dbtableprefix": "oc_",
"dbuser": "***REMOVED SENSITIVE VALUE***",
"dbpassword": "***REMOVED SENSITIVE VALUE***",
"installed": true,
"mysql.utf8mb4": true,
"memcache.local": "\\OC\\Memcache\\APCu",
"mail_smtpmode": "smtp",
"mail_smtpsecure": "ssl",
"mail_sendmailmode": "smtp",
"mail_domain": "***REMOVED SENSITIVE VALUE***",
"mail_from_address": "***REMOVED SENSITIVE VALUE***",
"mail_smtphost": "***REMOVED SENSITIVE VALUE***",
"mail_smtpport": "465",
"mail_smtpauth": 1,
"mail_smtpname": "***REMOVED SENSITIVE VALUE***",
"mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
"maintenance": false,
"theme": "",
"loglevel": 2
}
}
I found the problem in my case. I switched to Redis recently, but in the db there were still lock entries. After removing them, error was gone.
Same issue here. Using NC 18.0.4 with REDIS already enabled. Uploading a high number of files generates those warnings after one minute.
This issue is very frustrating! Is there any way I can check? Nothing is logged, wehn the error occurs.
My config:
<?php
$CONFIG = array (
// .....
'datadirectory' => '/nextcloud',
'dbtype' => 'mysql',
'version' => '18.0.4.2',
// .....
'installed' => true,
'ldapIgnoreNamingRules' => false,
'ldapProviderFactory' => 'OCA\\User_LDAP\\LDAPProviderFactory',
'mail_smtpmode' => 'sendmail',
'mail_sendmailmode' => 'smtp',
'skeletondirectory' => '',
'maintenance' => false,
'theme' => '',
'loglevel' => 2,
'memcache.local' => '\\OC\\Memcache\\APCu',
'app_install_overwrite' =>
array (
0 => 'mindmap_app',
),
'filelocking.enabled' => true,
'memcache.locking' => '\\OC\\Memcache\\Redis',
'redis' =>
array (
'host' => '/var/run/redis/redis-server.sock',
'port' => 0,
'timeout' => 0.0,
),
);
ServerInfo:
{
"ocs":{
"meta":{
"status":"ok",
"statuscode":200,
"message":"OK"
},
"data":{
"nextcloud":{
"system":{
"version":"18.0.4.2",
"theme":"",
"enable_avatars":"yes",
"enable_previews":"yes",
"memcache.local":"\\OC\\Memcache\\APCu",
"memcache.distributed":"none",
"filelocking.enabled":"yes",
"memcache.locking":"\\OC\\Memcache\\Redis",
"debug":"no",
"freespace":162875158528,
"cpuload":[
0.16,
0.29,
0.43
],
"mem_total":8168100,
"mem_free":7416776,
"swap_total":2097148,
"swap_free":2066808,
"apps":{
"num_installed":45,
"num_updates_available":0,
"app_updates":[
]
}
},
"storage":{
"num_users":87,
"num_files":28225,
"num_storages":104,
"num_storages_local":1,
"num_storages_home":102,
"num_storages_other":1
},
"shares":{
"num_shares":218,
"num_shares_user":40,
"num_shares_groups":0,
"num_shares_link":63,
"num_shares_mail":115,
"num_shares_room":0,
"num_shares_link_no_password":62,
"num_fed_shares_sent":0,
"num_fed_shares_received":1,
"permissions_0_1":"3",
"permissions_3_1":"43",
"permissions_4_1":"68",
"permissions_0_3":"2",
"permissions_3_3":"3",
"permissions_4_3":"14",
"permissions_3_15":"17",
"permissions_4_15":"33",
"permissions_0_19":"12",
"permissions_0_31":"23"
}
},
"server":{
"webserver":"Apache\/2.4.29",
"php":{
"version":"7.2.24",
"memory_limit":2147483648,
"max_execution_time":3600,
"upload_max_filesize":17179869184
},
"database":{
"type":"mysql",
"version":"5.7.29",
"size":44392448
}
},
"activeUsers":{
"last5minutes":7,
"last1hour":8,
"last24hours":16
}
}
}
}
Redis Log:
21808:M 12 May 07:47:53.624 * The server is now ready to accept connections at /var/run/redis/redis-server.sock
21808:M 12 May 07:50:06.541 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 07:50:06.542 * Background saving started by pid 22030
22030:C 12 May 07:50:06.559 * DB saved on disk
22030:C 12 May 07:50:06.559 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 07:50:06.642 * Background saving terminated with success
21808:M 12 May 07:51:07.011 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 07:51:07.011 * Background saving started by pid 22156
22156:C 12 May 07:51:07.020 * DB saved on disk
22156:C 12 May 07:51:07.021 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 07:51:07.112 * Background saving terminated with success
21808:M 12 May 07:52:08.087 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 07:52:08.088 * Background saving started by pid 23002
23002:C 12 May 07:52:08.089 * DB saved on disk
23002:C 12 May 07:52:08.090 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 07:52:08.188 * Background saving terminated with success
21808:M 12 May 07:53:09.084 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 07:53:09.084 * Background saving started by pid 24460
24460:C 12 May 07:53:09.086 * DB saved on disk
24460:C 12 May 07:53:09.086 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 07:53:09.184 * Background saving terminated with success
21808:M 12 May 07:54:10.047 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 07:54:10.048 * Background saving started by pid 24494
24494:C 12 May 07:54:10.049 * DB saved on disk
24494:C 12 May 07:54:10.050 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 07:54:10.148 * Background saving terminated with success
21808:M 12 May 07:55:11.005 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 07:55:11.005 * Background saving started by pid 24620
24620:C 12 May 07:55:11.007 * DB saved on disk
24620:C 12 May 07:55:11.007 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 07:55:11.105 * Background saving terminated with success
21808:M 12 May 07:56:12.065 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 07:56:12.065 * Background saving started by pid 24978
24978:C 12 May 07:56:12.067 * DB saved on disk
24978:C 12 May 07:56:12.067 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 07:56:12.165 * Background saving terminated with success
21808:M 12 May 08:01:13.029 * 10 changes in 300 seconds. Saving...
21808:M 12 May 08:01:13.029 * Background saving started by pid 25477
25477:C 12 May 08:01:13.031 * DB saved on disk
25477:C 12 May 08:01:13.031 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:01:13.129 * Background saving terminated with success
21808:M 12 May 08:06:14.014 * 10 changes in 300 seconds. Saving...
21808:M 12 May 08:06:14.014 * Background saving started by pid 26041
26041:C 12 May 08:06:14.015 * DB saved on disk
26041:C 12 May 08:06:14.016 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:06:14.114 * Background saving terminated with success
21808:M 12 May 08:11:15.063 * 10 changes in 300 seconds. Saving...
21808:M 12 May 08:11:15.064 * Background saving started by pid 26755
26755:C 12 May 08:11:15.065 * DB saved on disk
26755:C 12 May 08:11:15.066 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:11:15.164 * Background saving terminated with success
21808:M 12 May 08:16:16.088 * 10 changes in 300 seconds. Saving...
21808:M 12 May 08:16:16.088 * Background saving started by pid 27335
27335:C 12 May 08:16:16.090 * DB saved on disk
27335:C 12 May 08:16:16.090 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:16:16.189 * Background saving terminated with success
21808:M 12 May 08:21:17.032 * 10 changes in 300 seconds. Saving...
21808:M 12 May 08:21:17.032 * Background saving started by pid 28059
28059:C 12 May 08:21:17.034 * DB saved on disk
28059:C 12 May 08:21:17.034 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:21:17.132 * Background saving terminated with success
21808:M 12 May 08:22:32.575 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:22:32.576 * Background saving started by pid 28263
28263:C 12 May 08:22:32.578 * DB saved on disk
28263:C 12 May 08:22:32.578 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:22:32.676 * Background saving terminated with success
21808:M 12 May 08:23:33.047 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:23:33.047 * Background saving started by pid 28510
28510:C 12 May 08:23:33.050 * DB saved on disk
28510:C 12 May 08:23:33.050 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:23:33.147 * Background saving terminated with success
21808:M 12 May 08:24:34.019 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:24:34.019 * Background saving started by pid 29026
29026:C 12 May 08:24:34.021 * DB saved on disk
29026:C 12 May 08:24:34.021 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:24:34.119 * Background saving terminated with success
21808:M 12 May 08:25:35.089 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:25:35.089 * Background saving started by pid 29190
29190:C 12 May 08:25:35.091 * DB saved on disk
29190:C 12 May 08:25:35.092 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:25:35.189 * Background saving terminated with success
21808:M 12 May 08:26:36.054 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:26:36.054 * Background saving started by pid 29249
29249:C 12 May 08:26:36.056 * DB saved on disk
29249:C 12 May 08:26:36.056 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:26:36.154 * Background saving terminated with success
21808:M 12 May 08:27:37.011 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:27:37.012 * Background saving started by pid 29480
29480:C 12 May 08:27:37.014 * DB saved on disk
29480:C 12 May 08:27:37.014 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:27:37.113 * Background saving terminated with success
21808:M 12 May 08:28:38.085 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:28:38.085 * Background saving started by pid 30230
30230:C 12 May 08:28:38.087 * DB saved on disk
30230:C 12 May 08:28:38.087 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:28:38.185 * Background saving terminated with success
21808:M 12 May 08:29:39.046 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:29:39.047 * Background saving started by pid 30608
30608:C 12 May 08:29:39.049 * DB saved on disk
30608:C 12 May 08:29:39.049 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:29:39.147 * Background saving terminated with success
21808:M 12 May 08:30:40.015 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:30:40.015 * Background saving started by pid 30861
30861:C 12 May 08:30:40.017 * DB saved on disk
30861:C 12 May 08:30:40.017 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:30:40.115 * Background saving terminated with success
21808:M 12 May 08:31:41.104 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:31:41.104 * Background saving started by pid 31094
31094:C 12 May 08:31:41.106 * DB saved on disk
31094:C 12 May 08:31:41.106 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:31:41.205 * Background saving terminated with success
21808:M 12 May 08:36:42.045 * 10 changes in 300 seconds. Saving...
21808:M 12 May 08:36:42.045 * Background saving started by pid 32243
32243:C 12 May 08:36:42.047 * DB saved on disk
32243:C 12 May 08:36:42.047 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:36:42.145 * Background saving terminated with success
21808:M 12 May 08:40:29.230 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:40:29.230 * Background saving started by pid 514
514:C 12 May 08:40:29.232 * DB saved on disk
514:C 12 May 08:40:29.232 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:40:29.330 * Background saving terminated with success
21808:M 12 May 08:41:30.102 * 10000 changes in 60 seconds. Saving...
21808:M 12 May 08:41:30.102 * Background saving started by pid 642
642:C 12 May 08:41:30.104 * DB saved on disk
642:C 12 May 08:41:30.104 * RDB: 0 MB of memory used by copy-on-write
21808:M 12 May 08:41:30.203 * Background saving terminated with success
Update: It is working with the native Windows client - Browser issue?
@Commifreak:
Uploading a high number of files generates those warnings after one minute.
I just opened https://github.com/nextcloud/server/issues/21073 and https://github.com/nextcloud/server/pull/21074 - sounds like you may be suffering from the same or similar issue.
In my case this error was encountered in a full installation of nextcloud, while trying to delete a folder. I would propose as a stopgap in this case to i) delete the folder from the server (e.g through the command-line); ii) trigger a rescan of the particular directory using php occ files:scan -p "the path of the parent folder" iii) delete the folder from the client if necessary.
This issue is stale because it has been without activity for 60 days. It will be closed after 7 more days of inactivity.
This just happened to me. I'm unsure how to clear oc_file_locks
with snap. How did you end up going about?
I figured out how to clear that table. But it doesn't solve my problem.
mysql> USE nextcloud;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A
Database changed
mysql> DELETE FROM oc_file_locks WHERE 1;
Query OK, 0 rows affected (0.02 sec)
mysql>
Name Version Rev Tracking Publisher Notes
nextcloud 25.0.5snap1 34073 latest/stable nextcloud✓ -
I ended up pruning the files from cli using rm
and then run nextcloud.occ files:scan --all
and it's deleted now...
My issue looked very much like this: https://help.nextcloud.com/t/file-is-locked-how-to-unlock/1883
But the solution did not work for me
On v15.02 running on digital ocean, and this snap is so well maintained this may be the first problem I have had in a year of using it.
Earlier today I got the error, "Server replied "423 Locked" to "DELETE https://[mydomain.com]/remote.php/dav/files/[myusername]/somefile
After reading this doc https://help.nextcloud.com/t/file-is-locked-how-to-unlock/1883, I noticed in the digital ocean ui that I had a backup from 19 hours ago. So I restored to this backup. All went well, then in the web ui, I created a new empty file, deleted it, and now I am getting the same error.
Then I noticed that while Nextcloud said it was syncing my files, it actually it deleted the folder and files I created today. So I lost a day's work and am a bit concerned.
Does anyone have this 423 lock problem with a snap or know how to troubleshoot it?