Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

dbt perf tuning #581

Draft
wants to merge 15 commits into
base: main
Choose a base branch
from
Draft

dbt perf tuning #581

wants to merge 15 commits into from

Conversation

aaronsteers
Copy link
Contributor

Includes changes from #580, should be merged after it.

This attempts to work through some performance issues I ran into when trying to get the full project to build using the new dbt_dev environment.

aaronsteers added a commit that referenced this pull request Feb 27, 2023
@aaronsteers
revert sql changes, moved to #581
bc58684
@aaronsteers aaronsteers mentioned this pull request Feb 27, 2023
Draft
@aaronsteers
Copy link
Contributor Author

I'll have to rerun from scratch to get the latest numbers, but here's the log from the first build operation which I was able to get successfully run end-to-end. From this log output, the tables taking more than 10 minutes are:

  • 40 minutes: stg_snowplow__events
  • 38 minutes: unstruct_event_flattened
  • 24 minutes: unstruct_exec_flattened
  • 23 minutes: unstruct_context_flattened
Details 
aj@AJs-MacBook-Pro data % meltano --environment=dbt_dev invoke dbt-snowflake:build
2023-02-27T18:56:17.468366Z [info     ] Environment 'dbt_dev' is active
Extension executing `dbt run`...
18:56:20  Running with dbt=1.3.2
18:56:21  Found 136 models, 348 tests, 4 snapshots, 0 analyses, 576 macros, 1 operation, 8 seed files, 25 sources, 0 exposures, 0 metrics
18:56:21
18:56:43  Concurrency: 1 threads (target='dbt_dev')
18:56:43
18:56:43  1 of 136 START sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.exposures  [RUN]
18:56:46  1 of 136 OK created sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.exposures  [SUCCESS 0 in 2.65s]
18:56:46  2 of 136 START sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.invocations  [RUN]
18:56:48  2 of 136 OK created sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.invocations  [SUCCESS 0 in 2.24s]
18:56:48  3 of 136 START sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.model_executions  [RUN]
18:56:50  3 of 136 OK created sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.model_executions  [SUCCESS 0 in 2.07s]
18:56:50  4 of 136 START sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.models .. [RUN]
18:56:51  4 of 136 OK created sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.models  [SUCCESS 0 in 1.55s]
18:56:51  5 of 136 START sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.seed_executions  [RUN]
18:56:53  5 of 136 OK created sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.seed_executions  [SUCCESS 0 in 1.97s]
18:56:53  6 of 136 START sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.seeds ... [RUN]
18:56:55  6 of 136 OK created sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.seeds  [SUCCESS 0 in 1.63s]
18:56:55  7 of 136 START sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.snapshot_executions  [RUN]
18:56:56  7 of 136 OK created sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.snapshot_executions  [SUCCESS 0 in 1.42s]
18:56:56  8 of 136 START sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.snapshots  [RUN]
18:56:58  8 of 136 OK created sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.snapshots  [SUCCESS 0 in 1.62s]
18:56:58  9 of 136 START sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.sources . [RUN]
18:57:00  9 of 136 OK created sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.sources  [SUCCESS 0 in 1.80s]
18:57:00  10 of 136 START sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.test_executions  [RUN]
18:57:01  10 of 136 OK created sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.test_executions  [SUCCESS 0 in 1.44s]
18:57:01  11 of 136 START sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.tests .. [RUN]
18:57:03  11 of 136 OK created sql incremental model USERDEV_PREP.SOURCE_DBT_ARTIFACTS.tests  [SUCCESS 0 in 1.38s]
18:57:03  12 of 136 START sql view model USERDEV_PREP.workspace.cloud_ip_ranges .......... [RUN]
18:57:04  12 of 136 OK created sql view model USERDEV_PREP.workspace.cloud_ip_ranges ..... [SUCCESS 1 in 0.95s]
18:57:04  13 of 136 START sql view model USERDEV_PREP.workspace.date_dim ................. [RUN]
18:57:05  13 of 136 OK created sql view model USERDEV_PREP.workspace.date_dim ............ [SUCCESS 1 in 1.03s]
18:57:05  14 of 136 START sql view model USERDEV_PREP.workspace.hash_lookup .............. [RUN]
18:57:05  14 of 136 OK created sql view model USERDEV_PREP.workspace.hash_lookup ......... [SUCCESS 1 in 0.69s]
18:57:05  15 of 136 START sql view model USERDEV_PREP.cloudwatch.stg_cloudwatch__log ..... [RUN]
18:57:06  15 of 136 OK created sql view model USERDEV_PREP.cloudwatch.stg_cloudwatch__log  [SUCCESS 1 in 0.65s]
18:57:06  16 of 136 START sql view model USERDEV_PREP.google_analytics.stg_ga__cli_events  [RUN]
18:57:07  16 of 136 OK created sql view model USERDEV_PREP.google_analytics.stg_ga__cli_events  [SUCCESS 1 in 0.61s]
18:57:07  17 of 136 START sql view model USERDEV_PREP.github_meltano.stg_github__issues .. [RUN]
18:57:07  17 of 136 OK created sql view model USERDEV_PREP.github_meltano.stg_github__issues  [SUCCESS 1 in 0.80s]
18:57:07  18 of 136 START sql view model USERDEV_PREP.github_meltano.stg_github__pull_requests  [RUN]
18:57:08  18 of 136 OK created sql view model USERDEV_PREP.github_meltano.stg_github__pull_requests  [SUCCESS 1 in 0.67s]
18:57:08  19 of 136 START sql view model USERDEV_PREP.github_meltano.stg_github__repositories  [RUN]
18:57:09  19 of 136 OK created sql view model USERDEV_PREP.github_meltano.stg_github__repositories  [SUCCESS 1 in 0.86s]
18:57:09  20 of 136 START sql view model USERDEV_PREP.github_search.stg_github_search__issues_base  [RUN]
18:57:10  20 of 136 OK created sql view model USERDEV_PREP.github_search.stg_github_search__issues_base  [SUCCESS 1 in 0.73s]
18:57:10  21 of 136 START sql view model USERDEV_PREP.github_search.stg_github_search__readme  [RUN]
18:57:11  21 of 136 OK created sql view model USERDEV_PREP.github_search.stg_github_search__readme  [SUCCESS 1 in 0.85s]
18:57:11  22 of 136 START sql view model USERDEV_PREP.github_search.stg_github_search__repositories  [RUN]
18:57:11  22 of 136 OK created sql view model USERDEV_PREP.github_search.stg_github_search__repositories  [SUCCESS 1 in 0.65s]
18:57:11  23 of 136 START sql table model USERDEV_PREP.gitlab.stg_gitlab__issues ......... [RUN]
18:57:13  23 of 136 OK created sql table model USERDEV_PREP.gitlab.stg_gitlab__issues .... [SUCCESS 1 in 1.50s]
18:57:13  24 of 136 START sql table model USERDEV_PREP.gitlab.stg_gitlab__merge_requests . [RUN]
18:57:14  24 of 136 OK created sql table model USERDEV_PREP.gitlab.stg_gitlab__merge_requests  [SUCCESS 1 in 1.73s]
18:57:14  25 of 136 START sql table model USERDEV_PREP.gitlab.stg_gitlab__projects ....... [RUN]
18:57:16  25 of 136 OK created sql table model USERDEV_PREP.gitlab.stg_gitlab__projects .. [SUCCESS 1 in 1.30s]
18:57:16  26 of 136 START sql view model USERDEV_PREP.meltanohub.stg_meltanohub__plugins . [RUN]
18:57:17  26 of 136 OK created sql view model USERDEV_PREP.meltanohub.stg_meltanohub__plugins  [SUCCESS 1 in 0.81s]
18:57:17  27 of 136 START sql view model USERDEV_PREP.slack.stg_slack__channels .......... [RUN]
18:57:18  27 of 136 OK created sql view model USERDEV_PREP.slack.stg_slack__channels ..... [SUCCESS 1 in 0.88s]
18:57:18  28 of 136 START sql view model USERDEV_PREP.slack.stg_slack__messages .......... [RUN]
18:57:19  28 of 136 OK created sql view model USERDEV_PREP.slack.stg_slack__messages ..... [SUCCESS 1 in 0.83s]
18:57:19  29 of 136 START sql view model USERDEV_PREP.slack.stg_slack__threads ........... [RUN]
18:57:19  29 of 136 OK created sql view model USERDEV_PREP.slack.stg_slack__threads ...... [SUCCESS 1 in 0.68s]
18:57:19  30 of 136 START sql view model USERDEV_PREP.slack.stg_slack__users ............. [RUN]
18:57:20  30 of 136 OK created sql view model USERDEV_PREP.slack.stg_slack__users ........ [SUCCESS 1 in 0.72s]
18:57:20  31 of 136 START sql view model USERDEV_PREP.snowplow.stg_snowplow__events_bad .. [RUN]
18:57:21  31 of 136 OK created sql view model USERDEV_PREP.snowplow.stg_snowplow__events_bad  [SUCCESS 1 in 0.71s]
18:57:21  32 of 136 START sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__exposures ... [RUN]
18:57:21  32 of 136 OK created sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__exposures  [SUCCESS 1 in 0.60s]
18:57:21  33 of 136 START sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__invocations . [RUN]
18:57:22  33 of 136 OK created sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__invocations  [SUCCESS 1 in 0.79s]
18:57:22  34 of 136 START sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__model_executions  [RUN]
18:57:23  34 of 136 OK created sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__model_executions  [SUCCESS 1 in 0.84s]
18:57:23  35 of 136 START sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__models ...... [RUN]
18:57:24  35 of 136 OK created sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__models . [SUCCESS 1 in 0.64s]
18:57:24  36 of 136 START sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__seed_executions  [RUN]
18:57:24  36 of 136 OK created sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__seed_executions  [SUCCESS 1 in 0.64s]
18:57:24  37 of 136 START sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__seeds ....... [RUN]
18:57:25  37 of 136 OK created sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__seeds .. [SUCCESS 1 in 0.59s]
18:57:25  38 of 136 START sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__snapshot_executions  [RUN]
18:57:26  38 of 136 OK created sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__snapshot_executions  [SUCCESS 1 in 0.77s]
18:57:26  39 of 136 START sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__snapshots ... [RUN]
18:57:26  39 of 136 OK created sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__snapshots  [SUCCESS 1 in 0.82s]
18:57:26  40 of 136 START sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__sources ..... [RUN]
18:57:27  40 of 136 OK created sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__sources  [SUCCESS 1 in 0.63s]
18:57:27  41 of 136 START sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__test_executions  [RUN]
18:57:28  41 of 136 OK created sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__test_executions  [SUCCESS 1 in 0.59s]
18:57:28  42 of 136 START sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__tests ....... [RUN]
18:57:28  42 of 136 OK created sql view model USERDEV_PREP.dbt_artifacts.stg_dbt__tests .. [SUCCESS 1 in 0.67s]
18:57:28  43 of 136 START sql view model USERDEV_PREP.workspace.hub_logs_parsed .......... [RUN]
18:57:29  43 of 136 OK created sql view model USERDEV_PREP.workspace.hub_logs_parsed ..... [SUCCESS 1 in 0.98s]
18:57:29  44 of 136 START sql table model DEFAULT.list_issues ............................ [RUN]
18:57:32  44 of 136 OK created sql table model DEFAULT.list_issues ....................... [SUCCESS 1 in 2.36s]
18:57:32  45 of 136 START sql view model USERDEV_PREP.github_search.stg_github_search__issues  [RUN]
18:57:32  45 of 136 OK created sql view model USERDEV_PREP.github_search.stg_github_search__issues  [SUCCESS 1 in 0.66s]
18:57:32  46 of 136 START sql view model USERDEV_PREP.github_search.stg_github_search__pull_requests  [RUN]
18:57:33  46 of 136 OK created sql view model USERDEV_PREP.github_search.stg_github_search__pull_requests  [SUCCESS 1 in 0.66s]
18:57:33  47 of 136 START sql table model meltano_hub.fact_repo_metrics .................. [RUN]
18:57:35  47 of 136 OK created sql table model meltano_hub.fact_repo_metrics ............. [SUCCESS 1 in 1.76s]
18:57:35  48 of 136 START sql view model USERDEV_PREP.workspace.username_mapping ......... [RUN]
18:57:36  48 of 136 OK created sql view model USERDEV_PREP.workspace.username_mapping .... [SUCCESS 1 in 0.90s]
18:57:36  49 of 136 START sql table model meltano_hub.hub_bot_plugins .................... [RUN]
18:57:38  49 of 136 OK created sql table model meltano_hub.hub_bot_plugins ............... [SUCCESS 1 in 2.05s]
18:57:38  50 of 136 START sql table model community.slack_members_daily .................. [RUN]
18:57:40  50 of 136 OK created sql table model community.slack_members_daily ............. [SUCCESS 1 in 2.46s]
18:57:40  51 of 136 START sql table model community.slack_new_members .................... [RUN]
18:57:42  51 of 136 OK created sql table model community.slack_new_members ............... [SUCCESS 1 in 2.04s]
18:57:42  52 of 136 START sql table model USERDEV_PREP.snowplow.snowplow_bad_parsed ...... [RUN]
19:01:53  52 of 136 OK created sql table model USERDEV_PREP.snowplow.snowplow_bad_parsed . [SUCCESS 1 in 251.08s]
19:01:53  53 of 136 START sql view model dbt_artifacts.dim_dbt__exposures ................ [RUN]
19:01:54  53 of 136 OK created sql view model dbt_artifacts.dim_dbt__exposures ........... [SUCCESS 1 in 1.03s]
19:01:54  54 of 136 START sql view model dbt_artifacts.fct_dbt__invocations .............. [RUN]
19:01:55  54 of 136 OK created sql view model dbt_artifacts.fct_dbt__invocations ......... [SUCCESS 1 in 0.96s]
19:01:55  55 of 136 START sql view model dbt_artifacts.fct_dbt__model_executions ......... [RUN]
19:01:56  55 of 136 OK created sql view model dbt_artifacts.fct_dbt__model_executions .... [SUCCESS 1 in 0.67s]
19:01:56  56 of 136 START sql view model dbt_artifacts.dim_dbt__current_models ........... [RUN]
19:01:57  56 of 136 OK created sql view model dbt_artifacts.dim_dbt__current_models ...... [SUCCESS 1 in 0.98s]
19:01:57  57 of 136 START sql view model dbt_artifacts.dim_dbt__models ................... [RUN]
19:01:58  57 of 136 OK created sql view model dbt_artifacts.dim_dbt__models .............. [SUCCESS 1 in 0.91s]
19:01:58  58 of 136 START sql view model dbt_artifacts.fct_dbt__seed_executions .......... [RUN]
19:01:59  58 of 136 OK created sql view model dbt_artifacts.fct_dbt__seed_executions ..... [SUCCESS 1 in 0.68s]
19:01:59  59 of 136 START sql view model dbt_artifacts.dim_dbt__seeds .................... [RUN]
19:02:00  59 of 136 OK created sql view model dbt_artifacts.dim_dbt__seeds ............... [SUCCESS 1 in 0.67s]
19:02:00  60 of 136 START sql view model dbt_artifacts.fct_dbt__snapshot_executions ...... [RUN]
19:02:00  60 of 136 OK created sql view model dbt_artifacts.fct_dbt__snapshot_executions . [SUCCESS 1 in 0.68s]
19:02:00  61 of 136 START sql view model dbt_artifacts.dim_dbt__snapshots ................ [RUN]
19:02:01  61 of 136 OK created sql view model dbt_artifacts.dim_dbt__snapshots ........... [SUCCESS 1 in 0.67s]
19:02:01  62 of 136 START sql view model dbt_artifacts.dim_dbt__sources .................. [RUN]
19:02:02  62 of 136 OK created sql view model dbt_artifacts.dim_dbt__sources ............. [SUCCESS 1 in 0.69s]
19:02:02  63 of 136 START sql view model dbt_artifacts.fct_dbt__test_executions .......... [RUN]
19:02:02  63 of 136 OK created sql view model dbt_artifacts.fct_dbt__test_executions ..... [SUCCESS 1 in 0.70s]
19:02:02  64 of 136 START sql view model dbt_artifacts.dim_dbt__tests .................... [RUN]
19:02:03  64 of 136 OK created sql view model dbt_artifacts.dim_dbt__tests ............... [SUCCESS 1 in 0.78s]
19:02:03  65 of 136 START sql table model telemetry.fact_hub_api_requests ................ [RUN]
19:02:39  65 of 136 OK created sql table model telemetry.fact_hub_api_requests ........... [SUCCESS 1 in 35.58s]
19:02:39  66 of 136 START sql table model community.singer_contributions ................. [RUN]
19:02:43  66 of 136 OK created sql table model community.singer_contributions ............ [SUCCESS 1 in 3.76s]
19:02:43  67 of 136 START sql view model community.contributions ......................... [RUN]
19:02:44  67 of 136 OK created sql view model community.contributions .................... [SUCCESS 1 in 1.24s]
19:02:44  68 of 136 START sql table model community.slack_company_domains ................ [RUN]
19:02:46  68 of 136 OK created sql table model community.slack_company_domains ........... [SUCCESS 1 in 1.73s]
19:02:46  69 of 136 START sql incremental model USERDEV_PREP.snowplow.stg_snowplow__events_union_all  [RUN]
19:03:54  69 of 136 OK created sql incremental model USERDEV_PREP.snowplow.stg_snowplow__events_union_all  [SUCCESS 35129 in 68.48s]
19:03:54  70 of 136 START sql view model slack_notifications.slack_alerts ................ [RUN]
19:03:55  70 of 136 OK created sql view model slack_notifications.slack_alerts ........... [SUCCESS 1 in 0.98s]
19:03:55  71 of 136 START sql table model community.fact_contributions ................... [RUN]
19:03:58  71 of 136 OK created sql table model community.fact_contributions .............. [SUCCESS 1 in 3.23s]
19:03:58  72 of 136 START sql view model slack_notifications.github_activity_notifications  [RUN]
19:03:59  72 of 136 OK created sql view model slack_notifications.github_activity_notifications  [SUCCESS 1 in 0.96s]
19:03:59  73 of 136 START sql table model USERDEV_PREP.snowplow.stg_snowplow__events ..... [RUN]
19:43:10  73 of 136 OK created sql table model USERDEV_PREP.snowplow.stg_snowplow__events  [SUCCESS 1 in 2350.32s]
19:43:10  74 of 136 START sql table model USERDEV_PREP.workspace.event_unstruct .......... [RUN]
19:49:44  74 of 136 OK created sql table model USERDEV_PREP.workspace.event_unstruct ..... [SUCCESS 1 in 394.45s]
19:49:44  75 of 136 START sql incremental model USERDEV_PREP.workspace.context_base ...... [RUN]
19:50:25  75 of 136 OK created sql incremental model USERDEV_PREP.workspace.context_base . [SUCCESS 171222 in 40.90s]
19:50:25  76 of 136 START sql table model USERDEV_PREP.workspace.event_block ............. [RUN]
19:50:38  76 of 136 OK created sql table model USERDEV_PREP.workspace.event_block ........ [SUCCESS 1 in 12.90s]
19:50:38  77 of 136 START sql table model USERDEV_PREP.workspace.event_cli ............... [RUN]
19:51:15  77 of 136 OK created sql table model USERDEV_PREP.workspace.event_cli .......... [SUCCESS 1 in 37.68s]
19:51:15  78 of 136 START sql table model USERDEV_PREP.workspace.event_exit .............. [RUN]
19:51:54  78 of 136 OK created sql table model USERDEV_PREP.workspace.event_exit ......... [SUCCESS 1 in 38.73s]
19:51:54  79 of 136 START sql table model USERDEV_PREP.workspace.event_legacy_with_context  [RUN]
19:52:05  79 of 136 OK created sql table model USERDEV_PREP.workspace.event_legacy_with_context  [SUCCESS 1 in 10.33s]
19:52:05  80 of 136 START sql table model USERDEV_PREP.workspace.event_telemetry_state_change  [RUN]
19:52:10  80 of 136 OK created sql table model USERDEV_PREP.workspace.event_telemetry_state_change  [SUCCESS 1 in 5.36s]
19:52:10  81 of 136 START sql table model USERDEV_PREP.workspace.context_cli ............. [RUN]
19:56:39  81 of 136 OK created sql table model USERDEV_PREP.workspace.context_cli ........ [SUCCESS 1 in 268.73s]
19:56:39  82 of 136 START sql table model USERDEV_PREP.workspace.context_environment ..... [RUN]
20:08:02  82 of 136 OK created sql table model USERDEV_PREP.workspace.context_environment  [SUCCESS 1 in 683.24s]
20:08:02  83 of 136 START sql table model USERDEV_PREP.workspace.context_exception ....... [RUN]
20:11:53  83 of 136 OK created sql table model USERDEV_PREP.workspace.context_exception .. [SUCCESS 1 in 231.08s]
20:11:53  84 of 136 START sql table model USERDEV_PREP.workspace.context_identify ........ [RUN]
20:12:03  84 of 136 OK created sql table model USERDEV_PREP.workspace.context_identify ... [SUCCESS 1 in 10.33s]
20:12:03  85 of 136 START sql table model USERDEV_PREP.workspace.context_plugins ......... [RUN]
20:16:21  85 of 136 OK created sql table model USERDEV_PREP.workspace.context_plugins .... [SUCCESS 1 in 257.60s]
20:16:21  86 of 136 START sql table model USERDEV_PREP.workspace.context_project ......... [RUN]
20:19:28  86 of 136 OK created sql table model USERDEV_PREP.workspace.context_project .... [SUCCESS 1 in 186.35s]
20:19:28  87 of 136 START sql view model USERDEV_PREP.workspace.ip_org_mapping_lm ........ [RUN]
20:19:29  87 of 136 OK created sql view model USERDEV_PREP.workspace.ip_org_mapping_lm ... [SUCCESS 1 in 0.92s]
20:19:29  88 of 136 START sql table model USERDEV_PREP.workspace.unstruct_context_flattened  [RUN]
20:42:31  88 of 136 OK created sql table model USERDEV_PREP.workspace.unstruct_context_flattened  [SUCCESS 1 in 1382.36s]
20:42:31  89 of 136 START sql table model USERDEV_PREP.workspace.unstruct_event_flattened  [RUN]
21:04:06  89 of 136 OK created sql table model USERDEV_PREP.workspace.unstruct_event_flattened  [SUCCESS 1 in 1295.37s]
21:04:06  90 of 136 START sql table model USERDEV_PREP.workspace.opt_outs ................ [RUN]
21:04:08  90 of 136 OK created sql table model USERDEV_PREP.workspace.opt_outs ........... [SUCCESS 1 in 1.56s]
21:04:08  91 of 136 START sql view model USERDEV_PREP.workspace.plugin_executions_block .. [RUN]
21:04:09  91 of 136 OK created sql view model USERDEV_PREP.workspace.plugin_executions_block  [SUCCESS 1 in 0.77s]
21:04:09  92 of 136 START sql table model USERDEV_PREP.workspace.unstruct_exec_flattened . [RUN]
21:28:08  92 of 136 OK created sql table model USERDEV_PREP.workspace.unstruct_exec_flattened  [SUCCESS 1 in 1439.73s]
21:28:08  93 of 136 START sql view model USERDEV_PREP.workspace.event_src_activation ..... [RUN]
21:28:09  93 of 136 OK created sql view model USERDEV_PREP.workspace.event_src_activation  [SUCCESS 1 in 0.99s]
21:28:09  94 of 136 START sql table model USERDEV_PREP.workspace.cli_execs_blended ....... [RUN]
21:31:10  94 of 136 OK created sql table model USERDEV_PREP.workspace.cli_execs_blended .. [SUCCESS 1 in 180.36s]
21:31:10  95 of 136 START sql table model USERDEV_PREP.workspace.structured_executions ... [RUN]
21:34:16  95 of 136 OK created sql table model USERDEV_PREP.workspace.structured_executions  [SUCCESS 1 in 186.75s]
21:34:16  96 of 136 START sql table model USERDEV_PREP.workspace.unstructured_executions . [RUN]
21:41:26  96 of 136 OK created sql table model USERDEV_PREP.workspace.unstructured_executions  [SUCCESS 1 in 429.29s]
21:41:26  97 of 136 START sql view model USERDEV_PREP.workspace.event_commands_parsed .... [RUN]
21:41:27  97 of 136 OK created sql view model USERDEV_PREP.workspace.event_commands_parsed  [SUCCESS 1 in 0.94s]
21:41:27  98 of 136 START sql view model USERDEV_PREP.workspace.unique_commands .......... [RUN]
21:41:28  98 of 136 OK created sql view model USERDEV_PREP.workspace.unique_commands ..... [SUCCESS 1 in 0.91s]
21:41:28  99 of 136 START sql table model USERDEV_PREP.workspace.ip_address_dim .......... [RUN]
21:42:48  99 of 136 OK created sql table model USERDEV_PREP.workspace.ip_address_dim ..... [SUCCESS 1 in 80.39s]
21:42:48  100 of 136 START sql view model USERDEV_PREP.workspace.unstruct_plugins_base ... [RUN]
21:42:49  100 of 136 OK created sql view model USERDEV_PREP.workspace.unstruct_plugins_base  [SUCCESS 1 in 0.87s]
21:42:49  101 of 136 START sql view model USERDEV_PREP.workspace.args_parsed ............. [RUN]
21:42:50  101 of 136 OK created sql view model USERDEV_PREP.workspace.args_parsed ........ [SUCCESS 1 in 0.80s]
21:42:50  102 of 136 START sql view model USERDEV_PREP.workspace.unstruct_plugins ........ [RUN]
21:42:51  102 of 136 OK created sql view model USERDEV_PREP.workspace.unstruct_plugins ... [SUCCESS 1 in 0.83s]
21:42:51  103 of 136 START sql view model USERDEV_PREP.workspace.cmd_parsed_add_remove ... [RUN]
21:42:51  103 of 136 OK created sql view model USERDEV_PREP.workspace.cmd_parsed_add_remove  [SUCCESS 1 in 0.93s]
21:42:51  104 of 136 START sql view model USERDEV_PREP.workspace.cmd_parsed_elt .......... [RUN]
21:42:52  104 of 136 OK created sql view model USERDEV_PREP.workspace.cmd_parsed_elt ..... [SUCCESS 1 in 0.93s]
21:42:52  105 of 136 START sql view model USERDEV_PREP.workspace.cmd_parsed_invoke ....... [RUN]
21:42:53  105 of 136 OK created sql view model USERDEV_PREP.workspace.cmd_parsed_invoke .. [SUCCESS 1 in 0.72s]
21:42:53  106 of 136 START sql view model USERDEV_PREP.workspace.cmd_parsed_run .......... [RUN]
21:42:54  106 of 136 OK created sql view model USERDEV_PREP.workspace.cmd_parsed_run ..... [SUCCESS 1 in 0.75s]
21:42:54  107 of 136 START sql view model USERDEV_PREP.workspace.cmd_parsed_schedule ..... [RUN]
21:42:55  107 of 136 OK created sql view model USERDEV_PREP.workspace.cmd_parsed_schedule  [SUCCESS 1 in 0.97s]
21:42:55  108 of 136 START sql view model USERDEV_PREP.workspace.cmd_parsed_select ....... [RUN]
21:42:56  108 of 136 OK created sql view model USERDEV_PREP.workspace.cmd_parsed_select .. [SUCCESS 1 in 0.67s]
21:42:56  109 of 136 START sql view model USERDEV_PREP.workspace.cmd_parsed_test ......... [RUN]
21:42:56  109 of 136 OK created sql view model USERDEV_PREP.workspace.cmd_parsed_test .... [SUCCESS 1 in 0.86s]
21:42:56  110 of 136 START sql view model USERDEV_PREP.workspace.unstruct_plugin_executions  [RUN]
21:42:58  110 of 136 OK created sql view model USERDEV_PREP.workspace.unstruct_plugin_executions  [SUCCESS 1 in 1.11s]
21:42:58  111 of 136 START sql table model USERDEV_PREP.workspace.cmd_parsed_all ......... [RUN]
21:43:42  111 of 136 OK created sql table model USERDEV_PREP.workspace.cmd_parsed_all .... [SUCCESS 1 in 44.87s]
21:43:42  112 of 136 START sql view model USERDEV_PREP.workspace.environments ............ [RUN]
21:43:43  112 of 136 OK created sql view model USERDEV_PREP.workspace.environments ....... [SUCCESS 1 in 0.84s]
21:43:43  113 of 136 START sql view model USERDEV_PREP.workspace.struct_plugins .......... [RUN]
21:43:44  113 of 136 OK created sql view model USERDEV_PREP.workspace.struct_plugins ..... [SUCCESS 1 in 0.91s]
21:43:44  114 of 136 START sql table model USERDEV_PREP.workspace.struct_plugin_executions  [RUN]
21:43:58  114 of 136 OK created sql table model USERDEV_PREP.workspace.struct_plugin_executions  [SUCCESS 1 in 13.75s]
21:43:58  115 of 136 START sql table model USERDEV_PREP.workspace.plugin_executions ...... [RUN]
21:48:50  115 of 136 OK created sql table model USERDEV_PREP.workspace.plugin_executions . [SUCCESS 1 in 291.83s]
21:48:50  116 of 136 START sql table model USERDEV_PREP.workspace.cli_executions_base .... [RUN]
21:55:52  116 of 136 OK created sql table model USERDEV_PREP.workspace.cli_executions_base  [SUCCESS 1 in 421.54s]
21:55:52  117 of 136 START sql view model USERDEV_PREP.workspace.pipeline_executions ..... [RUN]
21:55:53  117 of 136 OK created sql view model USERDEV_PREP.workspace.pipeline_executions  [SUCCESS 1 in 0.91s]
21:55:53  118 of 136 START sql view model USERDEV_PREP.workspace.project_org_mapping ..... [RUN]
21:55:54  118 of 136 OK created sql view model USERDEV_PREP.workspace.project_org_mapping  [SUCCESS 1 in 1.04s]
21:55:54  119 of 136 START sql table model telemetry.pipeline_dim ........................ [RUN]
21:56:20  119 of 136 OK created sql table model telemetry.pipeline_dim ................... [SUCCESS 1 in 26.41s]
21:56:20  120 of 136 START sql view model USERDEV_PREP.workspace.project_base ............ [RUN]
21:56:21  120 of 136 OK created sql view model USERDEV_PREP.workspace.project_base ....... [SUCCESS 1 in 1.20s]
21:56:21  121 of 136 START sql table model USERDEV_PREP.workspace.active_projects_base ... [RUN]
21:58:10  121 of 136 OK created sql table model USERDEV_PREP.workspace.active_projects_base  [SUCCESS 1 in 108.30s]
21:58:10  122 of 136 START sql table model telemetry.daily_active_projects ............... [RUN]
21:58:12  122 of 136 OK created sql table model telemetry.daily_active_projects .......... [SUCCESS 1 in 2.73s]
21:58:12  123 of 136 START sql table model telemetry.project_plugins ..................... [RUN]
21:58:23  123 of 136 OK created sql table model telemetry.project_plugins ................ [SUCCESS 1 in 10.75s]
21:58:23  124 of 136 START sql table model telemetry.project_dim ......................... [RUN]
22:00:18  124 of 136 OK created sql table model telemetry.project_dim .................... [SUCCESS 1 in 114.56s]
22:00:18  125 of 136 START sql table model telemetry.fact_cli_cohorts .................... [RUN]
22:00:25  125 of 136 OK created sql table model telemetry.fact_cli_cohorts ............... [SUCCESS 1 in 7.27s]
22:00:25  126 of 136 START sql table model telemetry.fact_cli_executions ................. [RUN]
22:02:08  126 of 136 OK created sql table model telemetry.fact_cli_executions ............ [SUCCESS 1 in 102.86s]
22:02:08  127 of 136 START sql table model telemetry.fact_cli_projects ................... [RUN]
22:02:13  127 of 136 OK created sql table model telemetry.fact_cli_projects .............. [SUCCESS 1 in 5.22s]
22:02:13  128 of 136 START sql table model telemetry.fact_plugin_usage ................... [RUN]
22:03:54  128 of 136 OK created sql table model telemetry.fact_plugin_usage .............. [SUCCESS 1 in 101.25s]
22:03:54  129 of 136 START sql table model telemetry.active_projects_28d ................. [RUN]
22:04:01  129 of 136 OK created sql table model telemetry.active_projects_28d ............ [SUCCESS 1 in 6.76s]
22:04:01  130 of 136 START sql table model telemetry.project_funnel_cohort ............... [RUN]
22:04:05  130 of 136 OK created sql table model telemetry.project_funnel_cohort .......... [SUCCESS 1 in 3.68s]
22:04:05  131 of 136 START sql table model telemetry.project_funnel_cohort_codespaces .... [RUN]
22:04:08  131 of 136 OK created sql table model telemetry.project_funnel_cohort_codespaces  [SUCCESS 1 in 3.41s]
22:04:08  132 of 136 START sql table model telemetry.fact_el_executions .................. [RUN]
22:05:13  132 of 136 OK created sql table model telemetry.fact_el_executions ............. [SUCCESS 1 in 64.48s]
22:05:13  133 of 136 START sql table model meltano_hub.fact_hub_metrics .................. [RUN]
22:05:15  133 of 136 OK created sql table model meltano_hub.fact_hub_metrics ............. [SUCCESS 1 in 2.64s]
22:05:15  134 of 136 START sql table model meltano_hub.fact_variant_hub_metrics .......... [RUN]
22:06:04  134 of 136 OK created sql table model meltano_hub.fact_variant_hub_metrics ..... [SUCCESS 1 in 48.59s]
22:06:04  135 of 136 START sql table model meltano_hub.hub_metrics_audit ................. [RUN]
22:06:05  135 of 136 OK created sql table model meltano_hub.hub_metrics_audit ............ [SUCCESS 1 in 1.63s]
22:06:05  136 of 136 START sql view model hubspot.org_activity ........................... [RUN]
22:06:06  136 of 136 OK created sql view model hubspot.org_activity ...................... [SUCCESS 1 in 0.87s]
22:06:06
22:06:06  Running 1 on-run-end hook
22:06:06  1 of 1 START hook: squared.on-run-end.0 ........................................ [RUN]
22:06:06  1 of 1 OK hook: squared.on-run-end.0 ........................................... [OK in 0.00s]
22:06:06
22:06:06
22:06:06  Finished running 13 incremental models, 69 view models, 54 table models, 1 hook in 3 hours 9 minutes and 45.66 seconds (11385.66s).
22:06:06
22:06:06  Completed successfully
22:06:06
22:06:06  Done. PASS=136 WARN=0 ERROR=0 SKIP=0 TOTAL=136

@aaronsteers aaronsteers temporarily deployed to test February 28, 2023 20:51 — with GitHub Actions Inactive
@aaronsteers aaronsteers temporarily deployed to test February 28, 2023 20:51 — with GitHub Actions Inactive
@aaronsteers aaronsteers mentioned this pull request Feb 28, 2023
Closed
@aaronsteers aaronsteers temporarily deployed to test February 28, 2023 20:57 — with GitHub Actions Inactive
@aaronsteers aaronsteers temporarily deployed to test February 28, 2023 20:57 — with GitHub Actions Inactive
@aaronsteers
Copy link
Contributor Author

aaronsteers commented Feb 28, 2023 •
edited
Loading

@pnadolny13 - Do you have expected runtime durations for the top 5 or so jobs on your side?

This PR isn't ready to go as of now, and some of these changes need additional thought. I'm curious though if the above runtimes are better, the same, or worse than the runtimes you have on your side - especially for the slowest 5-7 tables that make up the bulk of the runtime. (I should mention that those logs force threading to 1 in order to be easy to scan and debug.)

@aaronsteers aaronsteers temporarily deployed to test February 28, 2023 21:01 — with GitHub Actions Inactive
@aaronsteers aaronsteers temporarily deployed to test February 28, 2023 21:01 — with GitHub Actions Inactive
@aaronsteers aaronsteers temporarily deployed to test February 28, 2023 21:03 — with GitHub Actions Inactive
@aaronsteers aaronsteers temporarily deployed to test February 28, 2023 21:03 — with GitHub Actions Inactive
@aaronsteers aaronsteers temporarily deployed to test February 28, 2023 21:03 — with GitHub Actions Inactive
@pnadolny13
Copy link
Contributor

pnadolny13 commented Feb 28, 2023 •
edited
Loading

@aaronsteers I recently was working on #524 which made a difference but with telemetry data in there my thought was that it will always be pretty hard to do a clean rebuild. The way I get around this when I'm developing is by making myself a clone of prod to start then only running the models that I've changed. I'm definitely open to suggestions on this though. For CICD I limited the telemetry data to a few days worth so it finishes a full run in ~30 mins but thats only for a subset of data.

The project is configured to use dbt-artifacts as a post run hook so we collect all cicd/prod runtimes. Here is the nightly build from last night ordered by models with the longest runtime:

Screen Shot 2023-02-28 at 4 35 54 PM

Thats using incremental so most of the large tables build quick vs a rebuild that would take much longer. So the longest running model is ~16 mins.

@aaronsteers
Copy link
Contributor Author

aaronsteers commented Mar 1, 2023 •
edited
Loading

@pnadolny13 re:

For CICD I limited the telemetry data to a few days worth so it finishes a full run in ~30 mins but thats only for a subset of data.

I couldn't find the logic for this limit. Could you point me to that for use in #580 ? I think its probably reasonable to have at least the option for shorter limit on the telemetry data for local dev.

@pnadolny13
Copy link
Contributor

@aaronsteers the limit logic is in

squared/data/transform/models/staging/snowplow/stg_snowplow__events.sql

Line 11 in ac3eee5

{% if env_var("MELTANO_ENVIRONMENT") == "cicd" %}
. In CI all sources are fed by taps other than snowplow so we pull the data directly from RAW. Adding a configurable setting for dev environments to toggle this subset filter might be a good idea.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers
No reviews
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
2 participants
@aaronsteers @pnadolny13