logreader
logreader copied to clipboard
nextcloud
SetupCheck is taking too long / Detect and log slow running setup checks
On our instance the setup check did almost not finish.
I added var_dump(time() . $setupCheck->getService()); in the SetupCheckManager to find out it's actually the log reader taking all the time.
Our nextcloud.log.1 and nextcloud.log files are ~101MB both and the SetupCheck takes almost 20 minutes:
string(59) "1709933440 - OCA\DAV\SetupChecks\NeedsSystemAddressBookSync"
string(48) "1709933440 - OCA\LogReader\SetupChecks\LogErrors" <--------- WATCH THIS
string(70) "1709934599 - OCA\Notifications\Settings\SetupWarningOnRateLimitReached"
string(63) "1709934599 - OCA\Settings\SetupChecks\AppDirsWithDifferentOwner"
string(57) "1709934599 - OCA\Settings\SetupChecks\BruteForceThrottler"
string(59) "1709934599 - OCA\Settings\SetupChecks\CheckUserCertificates"
string(51) "1709934599 - OCA\Settings\SetupChecks\CodeIntegrity"
string(48) "1709934599 - OCA\Settings\SetupChecks\CronErrors"
string(46) "1709934599 - OCA\Settings\SetupChecks\CronInfo"
string(63) "1709934599 - OCA\Settings\SetupChecks\DatabaseHasMissingColumns"
string(63) "1709934599 - OCA\Settings\SetupChecks\DatabaseHasMissingIndices"
string(67) "1709934599 - OCA\Settings\SetupChecks\DatabaseHasMissingPrimaryKeys"
string(70) "1709934600 - OCA\Settings\SetupChecks\DatabasePendingBigIntConversions"
string(59) "1709934600 - OCA\Settings\SetupChecks\DefaultPhoneRegionSet"
string(57) "1709934600 - OCA\Settings\SetupChecks\EmailTestSuccessful"
string(49) "1709934600 - OCA\Settings\SetupChecks\FileLocking"
string(57) "1709934600 - OCA\Settings\SetupChecks\ForwardedForHeaders"
string(58) "1709934600 - OCA\Settings\SetupChecks\InternetConnectivity"
string(55) "1709934600 - OCA\Settings\SetupChecks\JavaScriptModules"
string(56) "1709934600 - OCA\Settings\SetupChecks\LegacySSEKeyFormat"
string(60) "1709934600 - OCA\Settings\SetupChecks\MaintenanceWindowStart"
string(56) "1709934600 - OCA\Settings\SetupChecks\MemcacheConfigured"
string(53) "1709934600 - OCA\Settings\SetupChecks\OverwriteCliUrl"
string(55) "1709934600 - OCA\Settings\SetupChecks\PhpDefaultCharset"
string(56) "1709934600 - OCA\Settings\SetupChecks\PhpFreetypeSupport"
string(47) "1709934600 - OCA\Settings\SetupChecks\PhpGetEnv"
string(52) "1709934600 - OCA\Settings\SetupChecks\PhpMemoryLimit"
string(48) "1709934600 - OCA\Settings\SetupChecks\PhpModules"
string(53) "1709934600 - OCA\Settings\SetupChecks\PhpOpcacheSetup"
string(49) "1709934600 - OCA\Settings\SetupChecks\PhpOutdated"
string(56) "1709934600 - OCA\Settings\SetupChecks\PhpOutputBuffering"
string(54) "1709934600 - OCA\Settings\SetupChecks\RandomnessSecure"
string(52) "1709934600 - OCA\Settings\SetupChecks\ReadOnlyConfig"
string(55) "1709934600 - OCA\Settings\SetupChecks\SupportedDatabase"
string(51) "1709934600 - OCA\Settings\SetupChecks\SystemIs64bit"
string(58) "1709934600 - OCA\Settings\SetupChecks\TransactionIsolation"
string(55) "1709934600 - OCA\SttWhisper\SetupChecks\ModelFilesCheck"
string(56) "1709934600 - OCA\SttWhisper\SetupChecks\BinaryFilesCheck"
string(53) "1709934600 - OCA\Theming\SetupChecks\PhpImagickModule"
string(57) "1709934600 - OCA\Translate\SetupChecks\MachineSupportsAvx"
string(55) "1709934600 - OCA\Translate\SetupChecks\ModelsDownloaded"
string(50) "1709934600 - OCA\Translate\SetupChecks\NodejsWorks"
string(55) "1709934600 - OCA\User_LDAP\SetupChecks\LdapInvalidUuids"
1.159 seconds = 19 minutes and 19 seconds...
This is not really acceptable.
I think we should skip the setupcheck when the file is bigger then 5 MB or something (home server level size), or we need to change it to simply grep | wc -l, but looping over the file in PHP and json decoding each line does not scale.
Should also build a check into the server code, that it logs an warning (> 5/10 seconds) or error (> 60 seconds) when a setupcheck is taking too long
@nickvergessen Note that there is already a log line for this purpose: $this->logger->debug('Running check '.get_class($setupCheckObject));
So with debug log level you can look at the timestamp of these lines in the log and see which one is taking long.
So with debug log level you can look at the timestamp of these lines in the log and see which one is taking long.
I can't really enable debug on production :D
So with debug log level you can look at the timestamp of these lines in the log and see which one is taking long.
I can't really enable debug on production :D
You can on a single occ run with env var NC_loglevel=0
yeah, anyway error logging very long running setupchecks sounds still good :) Sample: https://github.com/nextcloud/server/blob/131f481a67766d9bc5629948cc0abe1424308f00/lib/private/InitialStateService.php#L91-L101
https://github.com/nextcloud/logreader/pull/1179 should speed things up a bunch
Hi,
Is this issue fixed? I am experiencing something similar on nextcloud 29.0.7
When going to the admin -> overview I get Error occurred whilst checking server setup and when I run occ setupchecks it takes 1min8sec to complete.
Thanks for looking into this!
Hi,
Is this issue fixed? I am experiencing something similar on nextcloud 29.0.7
When going to the admin -> overview I get
Error occurred whilst checking server setupand when I runocc setupchecksit takes 1min8sec to complete.Thanks for looking into this!
This issue was fixed for logreader with PR https://github.com/nextcloud/logreader/pull/1178 Maybe you can run your setup checks with loglevel debug and see if you manage to see in the logs which check is taking so long?
I updated to 29.0.8 and it is solved! Apologies for reacting before updating.
@Mat-DB It's alright. The issue is still sitting open so it's understandable. :)
Seems we could close this with #1178 and #1179 being in place. I think this is still open to remind us about the idea to add automated detection and non-debug level logging of overly slow running setup checks here:
https://github.com/nextcloud/server/blob/5be832344eacb8328600d256c3090671c3f582d2/lib/private/SetupCheck/SetupCheckManager.php#L29-L38
to be kind of like we already do here, as @nickvergessen mentioned:
https://github.com/nextcloud/server/blob/131f481a67766d9bc5629948cc0abe1424308f00/lib/private/InitialStateService.php#L91-L101
