search

nextcloud / logreader

📜 Log reader for Nextcloud
56 stars 27 forks source link

SetupCheck is taking too long #1170

Open nickvergessen opened 5 months ago

nickvergessen commented 5 months ago

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.

nickvergessen commented 5 months ago

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

come-nc commented 5 months ago

@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.

nickvergessen commented 5 months ago

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

come-nc commented 5 months ago

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

nickvergessen commented 5 months ago

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

icewind1991 commented 5 months ago

https://github.com/nextcloud/logreader/pull/1179 should speed things up a bunch