You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@airflow.apache.org by "Neil Hanlon (JIRA)" <ji...@apache.org> on 2016/06/17 14:43:05 UTC

[jira] [Comment Edited] (AIRFLOW-246) dag_stats endpoint has a terrible query

    [ https://issues.apache.org/jira/browse/AIRFLOW-246?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15336229#comment-15336229 ] 

Neil Hanlon edited comment on AIRFLOW-246 at 6/17/16 2:43 PM:
--------------------------------------------------------------

[~sekikn] Looks good to me. Query only takes ~4 seconds to run on our db (~750k rows).

Obviously with more task instances the actual size of this query will increase which will require database tuning to allow it to run (max_allowed_packet) and all that... so maybe it should also be looked at whether or not the whole thing should be rearchitected... both of the queries (original, and the one you wrote) are pretty ugly. I'm not saying all queries have to be pretty, but...

Let me know if you get a code fix for this and I'd be happy to test it.

(new query profile for posterity)

{code:sql}
airflow-rwdb01:airflow> show profile for query 1;
+--------------------------------+----------+
| Status                         | Duration |
+--------------------------------+----------+
| starting                       | 0.000033 |
| Waiting for query cache lock   | 0.000005 |
| Waiting on query cache mutex   | 0.000004 |
| checking query cache for query | 0.002673 |
| checking permissions           | 0.000006 |
| checking permissions           | 0.000004 |
| checking permissions           | 0.000003 |
| checking permissions           | 0.000006 |
| Opening tables                 | 0.000025 |
| System lock                    | 0.001740 |
| optimizing                     | 0.000005 |
| statistics                     | 0.000017 |
| preparing                      | 0.000008 |
| executing                      | 0.000007 |
| Sorting result                 | 0.000004 |
| Sending data                   | 0.000855 |
| optimizing                     | 0.000009 |
| statistics                     | 0.000009 |
| preparing                      | 0.000010 |
| executing                      | 0.000004 |
| Sending data                   | 0.000622 |
| optimizing                     | 0.000073 |
| statistics                     | 1.371602 |
| preparing                      | 0.000239 |
| executing                      | 0.000008 |
| Sending data                   | 0.407134 |
| optimizing                     | 0.000145 |
| statistics                     | 1.176737 |
| preparing                      | 0.000174 |
| executing                      | 0.000006 |
| Sending data                   | 0.395361 |
| optimizing                     | 0.000011 |
| statistics                     | 0.000014 |
| preparing                      | 0.000012 |
| executing                      | 0.000005 |
| Sending data                   | 0.000654 |
| removing tmp table             | 0.000021 |
| Sending data                   | 0.000013 |
| Waiting for query cache lock   | 0.000005 |
| Waiting on query cache mutex   | 0.000005 |
| Sending data                   | 0.001048 |
| init                           | 0.000023 |
| optimizing                     | 0.000006 |
| statistics                     | 0.000007 |
| preparing                      | 0.000008 |
| Creating tmp table             | 0.000386 |
| executing                      | 0.000006 |
| Copying to tmp table           | 0.005354 |
| Sorting result                 | 0.000091 |
| Sending data                   | 0.000090 |
| end                            | 0.000004 |
| removing tmp table             | 0.000169 |
| end                            | 0.000006 |
| query end                      | 0.000007 |
| closing tables                 | 0.000004 |
| removing tmp table             | 0.000007 |
| closing tables                 | 0.000004 |
| removing tmp table             | 0.000007 |
| closing tables                 | 0.000004 |
| removing tmp table             | 0.000005 |
| closing tables                 | 0.000013 |
| freeing items                  | 0.000144 |
| Waiting for query cache lock   | 0.000004 |
| Waiting on query cache mutex   | 0.000003 |
| freeing items                  | 0.000057 |
| Waiting for query cache lock   | 0.000004 |
| Waiting on query cache mutex   | 0.000005 |
| freeing items                  | 0.000004 |
| storing result in query cache  | 0.000007 |
| logging slow query             | 0.000004 |
| logging slow query             | 0.000221 |
| cleaning up                    | 0.000013 |
+--------------------------------+----------+
72 rows in set (0.00 sec)
{code}


was (Author: nhanlon):
[~sekikn] Looks good to me. Query only takes ~4 seconds to run on our db (~750k rows).

Obviously with more task instances the actual size of this query will increase which will require database tuning to allow it to run (max_allowed_packet) and all that... so maybe it should also be looked at whether or not the whole thing should be rearchitected... both of the queries (original, and the one you wrote) are pretty ugly. I'm not saying all queries have to be pretty, but...

Let me know if you get a code fix for this and I'd be happy to test it.

(new query profile for posterity)

{pre}
airflow-rwdb01:airflow> show profile for query 1;
+--------------------------------+----------+
| Status                         | Duration |
+--------------------------------+----------+
| starting                       | 0.000033 |
| Waiting for query cache lock   | 0.000005 |
| Waiting on query cache mutex   | 0.000004 |
| checking query cache for query | 0.002673 |
| checking permissions           | 0.000006 |
| checking permissions           | 0.000004 |
| checking permissions           | 0.000003 |
| checking permissions           | 0.000006 |
| Opening tables                 | 0.000025 |
| System lock                    | 0.001740 |
| optimizing                     | 0.000005 |
| statistics                     | 0.000017 |
| preparing                      | 0.000008 |
| executing                      | 0.000007 |
| Sorting result                 | 0.000004 |
| Sending data                   | 0.000855 |
| optimizing                     | 0.000009 |
| statistics                     | 0.000009 |
| preparing                      | 0.000010 |
| executing                      | 0.000004 |
| Sending data                   | 0.000622 |
| optimizing                     | 0.000073 |
| statistics                     | 1.371602 |
| preparing                      | 0.000239 |
| executing                      | 0.000008 |
| Sending data                   | 0.407134 |
| optimizing                     | 0.000145 |
| statistics                     | 1.176737 |
| preparing                      | 0.000174 |
| executing                      | 0.000006 |
| Sending data                   | 0.395361 |
| optimizing                     | 0.000011 |
| statistics                     | 0.000014 |
| preparing                      | 0.000012 |
| executing                      | 0.000005 |
| Sending data                   | 0.000654 |
| removing tmp table             | 0.000021 |
| Sending data                   | 0.000013 |
| Waiting for query cache lock   | 0.000005 |
| Waiting on query cache mutex   | 0.000005 |
| Sending data                   | 0.001048 |
| init                           | 0.000023 |
| optimizing                     | 0.000006 |
| statistics                     | 0.000007 |
| preparing                      | 0.000008 |
| Creating tmp table             | 0.000386 |
| executing                      | 0.000006 |
| Copying to tmp table           | 0.005354 |
| Sorting result                 | 0.000091 |
| Sending data                   | 0.000090 |
| end                            | 0.000004 |
| removing tmp table             | 0.000169 |
| end                            | 0.000006 |
| query end                      | 0.000007 |
| closing tables                 | 0.000004 |
| removing tmp table             | 0.000007 |
| closing tables                 | 0.000004 |
| removing tmp table             | 0.000007 |
| closing tables                 | 0.000004 |
| removing tmp table             | 0.000005 |
| closing tables                 | 0.000013 |
| freeing items                  | 0.000144 |
| Waiting for query cache lock   | 0.000004 |
| Waiting on query cache mutex   | 0.000003 |
| freeing items                  | 0.000057 |
| Waiting for query cache lock   | 0.000004 |
| Waiting on query cache mutex   | 0.000005 |
| freeing items                  | 0.000004 |
| storing result in query cache  | 0.000007 |
| logging slow query             | 0.000004 |
| logging slow query             | 0.000221 |
| cleaning up                    | 0.000013 |
+--------------------------------+----------+
72 rows in set (0.00 sec)
{pre}

> dag_stats endpoint has a terrible query
> ---------------------------------------
>
>                 Key: AIRFLOW-246
>                 URL: https://issues.apache.org/jira/browse/AIRFLOW-246
>             Project: Apache Airflow
>          Issue Type: Bug
>          Components: webserver
>    Affects Versions: Airflow 1.7.1
>         Environment: MySQL Backend through sqlalchemy
>            Reporter: Neil Hanlon
>
> Hitting this endpoint creates a series of queries on the database which take over 20 seconds to run, causing the page to not load for that entire time. Luckily the main page (which includes this under "Recent Statuses") loads this synchronously, but still... waiting almost half a minute (at times more) to see the statuses for dags is really not fun.
> We have less than a million rows in the task_instance table--so it's not even a problem with that.
> Here's a query profile for the query:
> https://gist.github.com/NeilHanlon/613f12724e802bc51c23fca7d46d28bf
> We've done some optimizations on the database, but to no avail.
> The query:
> {code:sql}
> SELECT task_instance.dag_id AS task_instance_dag_id, task_instance.state AS task_instance_state, count(task_instance.task_id) AS count_1 FROM task_instance LEFT OUTER JOIN (SELECT dag_run.dag_id AS dag_id, dag_run.execution_date AS execution_date FROM dag_run WHERE dag_run.state = 'running') AS running_dag_run ON running_dag_run.dag_id = task_instance.dag_id AND running_dag_run.execution_date = task_instance.execution_date LEFT OUTER JOIN (SELECT dag_run.dag_id AS dag_id, max(dag_run.execution_date) AS execution_date FROM dag_run GROUP BY dag_run.dag_id) AS last_dag_run ON last_dag_run.dag_id = task_instance.dag_id AND last_dag_run.execution_date = task_instance.execution_date WHERE task_instance.task_id IN ... AND (running_dag_run.dag_id IS NOT NULL OR last_dag_run.dag_id IS NOT NULL) GROUP BY task_instance.dag_id, task_instance.state;
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)