N+1 slowdown on index page (playbooks list)

[bendem]

I was looking into why the index of ara takes so long to load (2s on good days) and I found that ara does 7 queries per playbook displayed in the table (6 counts for plays, tasks, results, hosts, files, records and 1 select for the labels).

We use ARA_PAGE_SIZE=50 but there are really no reason for the page to load that slow.

I've played with it a bit and with postgres you can get the same data off the db in 58ms by counting in the playbooks query and doing a join+aggregate for the labels.

SELECT distinct on ("playbooks"."id")
    "playbooks"."id",
    "playbooks"."created",
    "playbooks"."updated",
    "playbooks"."started",
    "playbooks"."ended",
    "playbooks"."duration",
    "playbooks"."name",
    "playbooks"."ansible_version",
    "playbooks"."client_version",
    "playbooks"."python_version",
    "playbooks"."server_version",
    "playbooks"."status",
    "playbooks"."arguments",
    "playbooks"."path",
    "playbooks"."controller",
    "playbooks"."user",

    (SELECT COUNT(*) AS "__count" FROM "plays" WHERE "plays"."playbook_id" = "playbooks"."id") as "plays_count",
    (SELECT COUNT(*) AS "__count" FROM "tasks" WHERE "tasks"."playbook_id" = "playbooks"."id") as "tasks_count",
    (SELECT COUNT(*) AS "__count" FROM "results" WHERE "results"."playbook_id" = "playbooks"."id") as "results_count",
    (SELECT COUNT(*) AS "__count" FROM "hosts" WHERE "hosts"."playbook_id" = "playbooks"."id") as "hosts_count",
    (SELECT COUNT(*) AS "__count" FROM "files" WHERE "files"."playbook_id" = "playbooks"."id") as "files_count",
    (SELECT COUNT(*) AS "__count" FROM "records" WHERE "records"."playbook_id" = "playbooks"."id") as "records_count",

    array_agg("playbooks_labels"."name") OVER (PARTITION BY "playbooks"."id") as "labels"
FROM "playbooks"
JOIN (
    SELECT
        "playbooks_labels"."playbook_id",
        "labels"."name"
    FROM "labels"
    INNER JOIN "playbooks_labels" ON ("labels"."id" = "playbooks_labels"."label_id")
) "playbooks_labels" ON "playbooks_labels"."playbook_id" = "playbooks"."id"
ORDER BY "playbooks"."id" DESC LIMIT 50;

ara/ara/api/serializers.py

Lines 36 to 47 in dde7674

	class ItemCountSerializer(serializers.ModelSerializer):
	class Meta:
	abstract = True
	# For counting relationships to other objects
	items = serializers.SerializerMethodField()
	@staticmethod
	def get_items(obj):
	types = ["plays", "tasks", "results", "hosts", "files", "records"]
	items = {item: getattr(obj, item).count() for item in types if hasattr(obj, item)}
	return items

[bendem]

Postgres logs with timestamp (1.472s database time).

[l00d3r]

I think I am affected by the same thing that is causing the issue here but in a different way, after upgrading ara-server from 1.6.1 to 1.7.0 our playbook runs have had 50% increase in run times (some are 6min to 9min, some went from 14min to 21min )

Why I think the root cause is the same is because there is a ~2sec delay between each task run reporting to ara server.