Hi everyone,
Appologies if this topic is not for here. The first time having to ask for help here.
I have a peculiar question that i could not find a solution or explanation anywhere.
Recently i decided to optimize my mysql database, and respectively turned on the slow log. What i noticed is that in 2 days the mysql_slow.log was more than 150mb.
I started digging, using different tools to figure out why is this happening (mysqltuner.pl, tuning-primer.sh, pt-query-digest), change mysql settings, so on…
With no luck…
I am running:
Nextcloud version 18.0.1:
Operating system and version DietPi 6.28.0
Apache version Apache/2.4.25 (Debian)
PHP version 7.3.14-5+0~20200202.52+debian9~1.gbpa71879
settings in my.conf:
[mysqld]
sql-mode = ANSI,STRICT_TRANS_TABLES,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_AUTO_VALUE_ON_ZERO,NO_ENGINE_SUBSTITUTION,NO_ZERO_DATE,NO_ZERO_IN_DATE,ONLY_FULL_GROUP_BY
innodb = FORCE
query-cache-type = 0
query-cache-size = 0
query_cache_limi = 1M
max-connections = 100
open-files-limit = 3000
# INNODB #
innodb-flush-method = O_DIRECT
innodb-log-file-size = 128M
innodb-flush-log-at-trx-commit = 2
innodb-buffer-pool-size = 1G
innodb-buffer_pool_instances = 1
innodb_stats_on_metadata = 0
# LOGGING #
log-warnings = 2
log-error = /var/lib/mysql/mysql-error.log
slow-query-log = 1
slow-query-log-file = /var/lib/mysql/mysql-slow.log
log-queries-not-using-indexes = 1
long_query_time = 2
wait_timeout = 300
interactive_timeout = 300
The output of Nextcloud log in Admin > Logging:
there is nothing in that log that has to do with the slow logs. (currently is filled with errors from the document server, but that is for another topic)
My config.php:
<?php
$CONFIG = array (
'passwordsalt' => 'XXXXXXXX',
'secret' => 'XXXXXXX',
'trusted_domains' =>
array (
0 => 'localhost',
1 => 'XXXXXXX',
2 => 'XXXXXXX',
3 => 'XXXXXXX',
4 => 'XXXXXXX',
),
'datadirectory' => '/mnt/data/nextcloud_data',
'dbtype' => 'mysql',
'version' => '18.0.1.3',
'memcache.local' => '\\OC\\Memcache\\APCu',
'filelocking.enabled' => true,
'memcache.locking' => '\\OC\\Memcache\\Redis',
'redis' =>
array (
'host' => '/var/run/redis/redis-server.sock',
'port' => 0,
),
'overwrite.cli.url' => 'http://localhost/nextcloud',
'htaccess.RewriteBase' => '/',
'dbname' => 'nextcloud',
'dbhost' => 'localhost',
'dbport' => '',
'dbtableprefix' => 'oc_',
'mysql.utf8mb4' => true,
'dbuser' => 'oc_admin',
'dbpassword' => 'XXXXXXX',
'installed' => true,
'instanceid' => 'XXXXXXX',
'maintenance' => false,
'preview_max_x' => '1200',
'preview_max_y' => '1200',
'preview_max_scale_factor' => 1,
'theme' => '',
'loglevel' => 2,
'app_install_overwrite' =>
array (
0 => 'impersonate',
1 => 'ocr',
2 => 'files_clipboard',
3 => 'files_external_gdrive',
4 => 'files_external_dropbox',
5 => 'radio',
),
'updater.release.channel' => 'stable',
'jpeg_quality' => '65',
'updater.secret' => 'XXXXXXX',
);
I would put the outcome from mysql_slow.log, but this is 100k rows so im only showing the top 10 with mysqldumpslow.
Output from:
mysqldumpslow -a -s c -t 10 /var/lib/mysql/mysql-slow.log
Reading mysql slow query log from /var/lib/mysql/mysql-slow.log
Count: 1223 Time=0.00s (0s) Lock=0.00s (0s) Rows_sent=43.0 (52589), Rows_examined=43.0 (52589), Rows_affected=0.0 (0), oc_admin[oc_admin]@localhost
SELECT `id`, `mimetype` FROM `oc_mimetypes`
Count: 1223 Time=0.00s (1s) Lock=0.00s (0s) Rows_sent=0.0 (0), Rows_examined=0.0 (0), Rows_affected=0.0 (0), oc_admin[oc_admin]@localhost
SELECT DISTINCT `class`, `entity`, `events` FROM `oc_flow_operations` WHERE `events` <> '[]'
Count: 1223 Time=0.00s (5s) Lock=0.00s (0s) Rows_sent=346.0 (423158), Rows_examined=346.0 (423158), Rows_affected=0.0 (0), oc_admin[oc_admin]@localhost
SELECT * FROM `oc_appconfig`
Count: 1208 Time=0.00s (0s) Lock=0.00s (0s) Rows_sent=0.0 (0), Rows_examined=0.0 (0), Rows_affected=0.0 (0), oc_admin[oc_admin]@localhost
SELECT `uid`, `displayname` FROM `oc_guests_users` `u` LEFT JOIN `oc_preferences` `p` ON (`userid` = `uid`) AND (`appid` = 'settings') AND (`configkey` = 'email') WHERE (`uid` COLLATE utf8mb4_general_ci LIKE '%%') OR (`displayname` COLLATE utf8mb4_general_ci LIKE '%%') OR (`configvalue` COLLATE utf8mb4_general_ci LIKE '%%') ORDER BY `uid_lower` ASC
Count: 1202 Time=0.00s (0s) Lock=0.00s (0s) Rows_sent=0.0 (0), Rows_examined=0.0 (0), Rows_affected=0.0 (0), oc_admin[oc_admin]@localhost
SELECT `f`.`folder_id`, `mount_point`, `quota`, `acl`, `fileid`, `storage`, `path`, `name`, `mimetype`, `mimepart`, `size`, `mtime`, `storage_mtime`, `etag`, `encrypted`, `parent`, `a`.`permissions` AS `group_permissions`, `c`.`permissions` AS `permissions` FROM `oc_group_folders` `f` INNER JOIN `oc_group_folders_groups` `a` ON `f`.`folder_id` = `a`.`folder_id` LEFT JOIN `oc_filecache` `c` ON (`name` = CONCAT(`f`.`folder_id`, '')) AND (`parent` = '13472') WHERE `a`.`group_id` = 'home'
Count: 1188 Time=0.00s (0s) Lock=0.00s (0s) Rows_sent=0.0 (0), Rows_examined=0.0 (0), Rows_affected=0.0 (0), oc_admin[oc_admin]@localhost
SELECT `m`.`mount_id`, `mount_point`, `storage_backend`, `auth_backend`, `priority`, `m`.`type` FROM `oc_external_mounts` `m` INNER JOIN `oc_external_applicable` `a` ON `m`.`mount_id` = `a`.`mount_id` WHERE ((`a`.`type` = 1) AND (`a`.`value` IS NULL)) OR ((`a`.`type` = 3) AND (`a`.`value` = 'baboon')) OR ((`a`.`type` = 2) AND (`a`.`value` IN ('admin', 'home')))
Count: 1188 Time=0.00s (0s) Lock=0.00s (0s) Rows_sent=0.0 (0), Rows_examined=0.0 (0), Rows_affected=0.0 (0), oc_admin[oc_admin]@localhost
SELECT `f`.`folder_id`, `mount_point`, `quota`, `acl`, `fileid`, `storage`, `path`, `name`, `mimetype`, `mimepart`, `size`, `mtime`, `storage_mtime`, `etag`, `encrypted`, `parent`, `a`.`permissions` AS `group_permissions`, `c`.`permissions` AS `permissions` FROM `oc_group_folders` `f` INNER JOIN `oc_group_folders_groups` `a` ON `f`.`folder_id` = `a`.`folder_id` LEFT JOIN `oc_filecache` `c` ON (`name` = CONCAT(`f`.`folder_id`, '')) AND (`parent` = '13472') WHERE `a`.`group_id` = 'admin'
Count: 1188 Time=0.00s (0s) Lock=0.00s (0s) Rows_sent=3.0 (3564), Rows_examined=5.0 (5940), Rows_affected=0.0 (0), oc_admin[oc_admin]@localhost
SELECT `r`.*, `p`.* FROM `oc_talk_rooms` `r` LEFT JOIN `oc_talk_participants` `p` ON (`p`.`user_id` = 'baboon') AND (`p`.`room_id` = `r`.`id`) WHERE `p`.`user_id` IS NOT NULL
Count: 956 Time=0.00s (0s) Lock=0.00s (0s) Rows_sent=0.0 (0), Rows_examined=0.0 (0), Rows_affected=0.0 (0), oc_admin[oc_admin]@localhost
SELECT `o`.*, `s`.`type` AS `scope_type`, `s`.`value` AS `scope_actor_id` FROM `oc_flow_operations` `o` LEFT JOIN `oc_flow_operations_scope` `s` ON `o`.`id` = `s`.`operation_id` WHERE `s`.`type` = '0'
Count: 954 Time=0.00s (0s) Lock=0.00s (0s) Rows_sent=0.0 (0), Rows_examined=0.0 (0), Rows_affected=0.0 (0), oc_admin[oc_admin]@localhost
SELECT `o`.*, `s`.`type` AS `scope_type`, `s`.`value` AS `scope_actor_id` FROM `oc_flow_operations` `o` LEFT JOIN `oc_flow_operations_scope` `s` ON `o`.`id` = `s`.`operation_id` WHERE (`s`.`type` = '1') AND (`s`.`value` = 'baboon')
Basically my log fills with thousands of rows, every minute on the minute the log is undated with about 400-700 rows extra. They all repeat. the above dump is since about 2-3 hours.
First i thought the slow logs fills only when using the instance of nextcloud, but that is not the case. Regardless of being on the page or not, or not being used at all, every minute the entries come into the log.
If there is any other setting you need me to show here please let me know.
I want to find out if this behavior is normal, is there something i have done wrong, or something has gone wrong?
I dont find it normal that i have so many entries in the slow log, especially from nextcloud that i would assume is optimized with indexes and so on.
Any suggestions are welcome.
Thank you in advance