on-run-end hook take a long time to finish

[papost]

Hey folks,

I am trying to initialize and use the elementary package (it's awesome), but I am skeptical if we are going to use it. Even If I run a single view model with no transformations & calculations, it takes a long time to finish the on-run-end hook of elementary. Although it is a great tool, this problem will waste a lot of our time while we are developing new models. Am I missing something? Does anyone have the same issue as me? Waiting for your answers!

[oravi]

Hi @papost !

Thanks for reaching out and sorry to hear that it takes a long time for you to run. Please let me share some context on what happens during the on-run-end hook and then we can think together what might be the issue.

on-run-end is responsible for the following -

• Upload metadata about all the resources in your project into plain tables in your warehouse. For example, all your model configurations and settings are being uploaded into dbt_models, all the tests configurations are being uploaded to dbt_tests , etc. We do have a caching mechanism here that will automatically detect if there's no change in the configuration - nothing will be re-uploaded during the next dbt runs. Only if you change a model setting for example, we will reupload the metadata into dbt_models.

  • For some huge projects this could take a relatively long time (a few minutes) but only for the first run. This can be also disabled using a flag and then you can trigger this upload on a different schedule. I can share details about it if we understand that this is the issue in your case.

• Upload run results about all the models or tests that participated in this run. This part uploads details like execution times for each model / test, execution status for each model / test, errors and traceback for each failed model / test, and more.

  • Usually this is not the heavy part and must be uploaded as the result is only available for the current run. That said, we have a flag to disable this as well if really needed.

• Upload invocation details about the command invocation. Details like what selector were used during the run, what was the command and more.

  • Usually this part is very lightweight as it's only one insert query.

Another thing to note - some of our users enable this metadata and run results collection only in prod so it doesn't slow down their local work. You can see the following to learn how to configure it -

models:
  elementary:
    +schema: "elementary"
    +enabled: "{{ target.name == 'prod' }}"

[mattxxi]

Hello !
Thanks for opening this issue, I have the same issue here, the post hook takes forever to run:
Here is an example in the CI/CD, the model runs in 3.10s but with the post hook it lasts 75.77s

[FredericoCoelhoNunes]

I have a similar issue, but in my case it's weirder since it seems environment dependent. I am comparing two runs, one local run (MacOS) and one on AWS ECS Fargate (running Linux). Both environment have the exact same version of all packages installed (dbt-core==1.7.19 and elementary-data==0.16.1).

The issue arises when flattening/uploading the artifacts, and it's mostly noticeable on the dbt_tests/dbt_columns artifacts.

Her's an example for dbt_columns: locally it is pretty fast (37 seconds):

Elementary: Measured durations for context - upload_artifacts_to_table[dbt_columns]:
Elementary:     upload_artifacts_to_table[dbt_columns].artifacts_flatten: 0:00:18.207704 (1 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows.get_columns_in_relation: 0:00:00.770069 (2 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows.get_insert_rows_queries.base_query_calc: 0:00:00.004717 (2 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows.get_insert_rows_queries.render_row_to_sql: 0:00:00.205223 (19 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows.get_insert_rows_queries: 0:00:00.232276 (2 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows.run_insert_rows_query: 0:00:00.320875 (2 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows: 0:00:01.348811 (2 runs)
Elementary:     upload_artifacts_to_table[dbt_columns]: 0:00:37.807316 (1 runs)
Elementary: Uploaded dbt artifacts.

whereas on the "cloud" environment it takes ~4:30 minutes:

Elementary: Measured durations for context - upload_artifacts_to_table[dbt_columns]:
Elementary:     upload_artifacts_to_table[dbt_columns].artifacts_flatten: 0:02:18.100996 (1 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows.get_columns_in_relation: 0:00:00.829232 (2 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows.get_insert_rows_queries.base_query_calc: 0:00:00.002618 (2 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows.get_insert_rows_queries.render_row_to_sql: 0:00:00.242554 (14 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows.get_insert_rows_queries: 0:00:00.265012 (2 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows.run_insert_rows_query: 0:00:00.168162 (2 runs)
Elementary:     upload_artifacts_to_table[dbt_columns].insert_rows: 0:00:01.280985 (2 runs)
Elementary:     upload_artifacts_to_table[dbt_columns]: 0:04:29.138608 (1 runs)
Elementary: Uploaded dbt artifacts.

My first guess would be a networking issue, which could explain the slow inserting of data on Redshift, but I can't explain the artifact flattening taking longer.

From my understanding, flattening the artifacts is a purely local operation, so I don't understand why it would take an order of magnitude longer to do in our prod environment than on my local machine.

If anyone has any insights regarding this, I would love to discuss!

EDIT: PROBLEM (mostly) SOLVED 🥳 - increasing the CPU of my task + disabling the upload of the columns artifacts using the disable_dbt_columns_autoupload: true var improved on-run-end hook performance by 80%+.