Occ is slow (10s, ~3k queries)

Support intro

Sorry to hear you’re facing problems :slightly_frowning_face:

help.nextcloud.com is for home/non-enterprise users. If you’re running a business, paid support can be accessed via portal.nextcloud.com where we can ensure your business keeps running smoothly.

In order to help you as quickly as possible, before clicking Create Topic please provide as much of the below as you can. Feel free to use a pastebin service for logs, otherwise either indent short log examples with four spaces:

example

Or for longer, use three backticks above and below the code snippet:

longer
example
here

Some or all of the below information will be requested if it isn’t supplied; for fastest response please provide as much as you can :heart:

Nextcloud version (eg, 20.0.5): 26.0.3
Operating system and version (eg, Ubuntu 20.04): Arch Linux
Apache or nginx version (eg, Apache 2.4.25): 2.4.57 (Nextcloud AIO v6.3.0; httpd:2.4.57-alpine3.18)
PHP version (eg, 7.4): 8.1.21 (Nextcloud AIO v6.3.0; php:8.1.21-fpm-alpine3.18)

The issue you are facing:

Nextcloud AIO startup is slow, and when I run docker exec --user www-data -it nextcloud-aio-nextcloud php occ config:system:set "overwrite.cli.url" "--value=myurl" it takes 10s to execute and produces ~3.3k queries.

Is this the first time you’ve seen this error? (Y/N): N, just didn’t investigate earlier.

Steps to replicate it:

No clue

The output of your Nextcloud log in Admin > Logging:

PASTE HERE

The output of your config.php file in /path/to/nextcloud (make sure you remove any identifiable information!):

PASTE HERE

The output of your Apache/nginx/system log in /var/log/____:

PASTE HERE

Output errors in nextcloud.log in /var/www/ or as admin user in top right menu, filtering for errors. Use a pastebin service if necessary.

PASTE HERE

Queries sorted by count

1070x [{constant}] LOG: execute : SELECT CURRENT_DATABASE()

636x [{constant}] LOG: execute : SELECT attnum, attname FROM pg_attribute WHERE attrelid={constant} AND attnum IN ({constant}) ORDER BY attnum ASC

356x [{constant}] LOG: execute : SELECT
a.attnum,
quote_ident(a.attname) AS field,
t.typname AS type,
format_type(a.atttypid, a.atttypmod) AS complete_type,
(SELECT tc.collcollate FROM pg_catalog.pg_collation tc WHERE tc.oid = a.attcollation) AS collation,
(SELECT t1.typname FROM pg_catalog.pg_type t1 WHERE t1.oid = t.typbasetype) AS domain_type,
(SELECT format_type(t2.typbasetype, t2.typtypmod) FROM
pg_catalog.pg_type t2 WHERE t2.typtype = {constant} AND t2.oid = a.atttypid) AS domain_complete_type,
a.attnotnull AS isnotnull,
(SELECT {constant}
FROM pg_index
WHERE c.oid = pg_index.indrelid
AND pg_index.indkey[{constant}] = a.attnum
AND pg_index.indisprimary = {constant}
) AS pri,
(SELECT pg_get_expr(adbin, adrelid)
FROM pg_attrdef
WHERE c.oid = pg_attrdef.adrelid
AND pg_attrdef.adnum=a.attnum
) AS default,
(SELECT pg_description.description
FROM pg_description WHERE pg_description.objoid = c.oid AND a.attnum = pg_description.objsubid
) AS comment
FROM pg_attribute a, pg_class c, pg_type t, pg_namespace n
WHERE n.nspname NOT IN ({constant}, {constant}, {constant}) AND c.relname = {constant} AND n.nspname = ANY(current_schemas(false))
AND a.attnum > {constant}
AND a.attrelid = c.oid
AND a.atttypid = t.oid
AND n.oid = c.relnamespace
ORDER BY a.attnum

356x [{constant}] LOG: execute : SELECT quote_ident(r.conname) as conname, pg_catalog.pg_get_constraintdef(r.oid, true) as condef
FROM pg_catalog.pg_constraint r
WHERE r.conrelid =
(
SELECT c.oid
FROM pg_catalog.pg_class c, pg_catalog.pg_namespace n
WHERE n.nspname NOT IN ({constant}, {constant}, {constant}) AND c.relname = {constant} AND n.nspname = ANY(current_schemas(false)) AND n.oid = c.relnamespace
)
AND r.contype = {constant}

356x [{constant}] LOG: execute : SELECT quote_ident(relname) as relname, pg_index.indisunique, pg_index.indisprimary,
pg_index.indkey, pg_index.indrelid,
pg_get_expr(indpred, indrelid) AS where
FROM pg_class, pg_index
WHERE oid IN (
SELECT indexrelid
FROM pg_index si, pg_class sc, pg_namespace sn
WHERE sn.nspname NOT IN ({constant}, {constant}, {constant}) AND sc.relname = {constant} AND sn.nspname = ANY(current_schemas(false))
AND sc.oid=si.indrelid AND sc.relnamespace = sn.oid
) AND pg_index.indexrelid = oid

356x [{constant}] LOG: execute : SELECT obj_description({constant}::regclass) AS table_comment;

142x [{constant}] LOG: execute : SELECT attnum, attname FROM pg_attribute WHERE attrelid={constant} AND attnum IN ({constant} ,{constant}) ORDER BY attnum ASC

44x [{constant}] LOG: execute : SELECT attnum, attname FROM pg_attribute WHERE attrelid={constant} AND attnum IN ({constant} ,{constant} ,{constant}) ORDER BY attnum ASC

10x [{constant}] LOG: execute : SELECT attnum, attname FROM pg_attribute WHERE attrelid={constant} AND attnum IN ({constant} ,{constant} ,{constant} ,{constant}) ORDER BY attnum ASC

3x [{constant}] LOG: execute : SHOW search_path

2x [{constant}] LOG: execute : SELECT schema_name AS nspname
FROM information_schema.schemata
WHERE schema_name NOT LIKE ‘pg_%’
AND schema_name != {constant}

2x [{constant}] LOG: execute : SELECT sequence_name AS relname,
sequence_schema AS schemaname,
minimum_value AS min_value,
increment AS increment_by
FROM information_schema.sequences
WHERE sequence_catalog = {constant}
AND sequence_schema NOT LIKE ‘pg_%’
AND sequence_schema != {constant}

2x [{constant}] LOG: execute : SELECT quote_ident(table_name) AS table_name,
table_schema AS schema_name
FROM information_schema.tables
WHERE table_schema NOT LIKE ‘pg_%’
AND table_schema != {constant}
AND table_name != {constant}
AND table_name != {constant}
AND table_type != {constant}

2x [{constant}] LOG: execute : SELECT attnum, attname FROM pg_attribute WHERE attrelid={constant} AND attnum IN ({constant} ,{constant} ,{constant} ,{constant} ,{constant} ,{constant}) ORDER BY attnum ASC

2x [{constant}] LOG: execute : SELECT attnum, attname FROM pg_attribute WHERE attrelid={constant} AND attnum IN ({constant} ,{constant} ,{constant} ,{constant} ,{constant}) ORDER BY attnum ASC

1x [{constant}] LOG: execute : SELECT * FROM “oc_appconfig”

1x [{constant}] LOG: execute : SELECT “id”, “numeric_id”, “available”, “last_checked” FROM “oc_storages” WHERE “id” = ${constant}

1x [{constant}] LOG: execute : SELECT “filecache”.“fileid”, “storage”, “path”, “path_hash”, “filecache”.“parent”, “filecache”.“name”, “mimetype”, “mimepart”, “size”, “mtime”, “storage_mtime”, “encrypted”, “etag”, “permissions”, “checksum”, “unencrypted_size”, “metadata_etag”, “creation_time”, “upload_time” FROM “oc_filecache” “filecache” LEFT JOIN “oc_filecache_extended” “fe” ON “filecache”.“fileid” = “fe”.“fileid” WHERE (“storage” = ${constant}) AND (“path_hash” = ${constant})

1x [{constant}] LOG: execute : SELECT “id”, “mimetype” FROM “oc_mimetypes”

1x [{constant}] LOG: execute : SELECT schema_name
FROM information_schema.schemata
WHERE schema_name NOT LIKE ‘pg_%’
AND schema_name != {constant}

1x [{constant}] LOG: execute : SELECT VERSION() AS version

1x [{constant}] LOG: execute : SELECT “mount_id”, “mount_point”, “storage_backend”, “auth_backend”, “priority”, “type” FROM “oc_external_mounts”

1x [{constant}] LOG: execute : SELECT “type”, “value”, “mount_id” FROM “oc_external_applicable” WHERE “mount_id” IN (${constant})

1x [{constant}] LOG: execute : SELECT “key”, “value”, “mount_id” FROM “oc_external_config” WHERE “mount_id” IN (${constant})

1x [{constant}] LOG: execute : SELECT “key”, “value”, “mount_id” FROM “oc_external_options” WHERE “mount_id” IN (${constant})

1x [{constant}] LOG: execute : SHOW SERVER_VERSION

3350

Hi @notEvil - I assume you tested the speed with query logging disabled and debug disabled, correct? Because that those will destroy performance. Just confirming the more obvious possibilities first. :slight_smile:

What is the underlying hardware, storage, and RAM?

What does your usage seem like with AIO running across your CPU and memory?

Query logging is disabled by default and I enabled it just for the duration of the occ command. The log level (occ log:manage --level) was actually set to debug and generated many entries per second. And 'debug' is not set in any config.php.

I just tested with query logging disabled and log level set to warning, but its still slow. Enabling query logging doesn’t make any difference.

Hardware is weak (Intel N3150 quad-core 1.6GHz, 4GB RAM, SSD) but its working pretty well and CPU/memory usage is fine (mostly idle, short spikes on requests, mem is at 50%). During the occ command, php is at 10% (1 core) and postgres at 80% (1 core) for at least 6s. Thats why I believe its the number of requests, and ~3k seems a bit much for a small CLI command imo.

edit: maybe this helps (xdebug profile triggered by env variable)

I haven’t profiled it myself. I’m not sure what’s typical.

The bulk of the queries (from your earlier post) look like meta data ones (i.e. looking up the structure of the underlying tables in the db) as opposed to NC specific queries.

I can say that I pulled out a retired Pi 4 NC installation and ./occ config:list system takes just 1.186 seconds.

With your log settings more reasonable, are your Nextcloud logs relatively quiet?

Generically speaking, on the hardware you’re on, you might try disabling:

  • Talk
  • Imaginary
  • Office/CODE/Collabora

…to evaluate performance without them.

Looking at the logs more closely and comparing with the database, its rather obvious now:

178 tables, at least 8 queries per table and the process is performed twice. In total ~3k queries each taking a few ms to execute on average. So occ just doesn’t scale well with the number of apps. Maybe reflection could be done more efficiently, or on demand?