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.

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

Cache + minimize registry requests in dbt deps #4983

Closed
wants to merge 2 commits into from

Conversation

jtcohen6
Copy link
Contributor

@jtcohen6 jtcohen6 commented Mar 31, 2022

resolves #4342

Toplines: Up to 80% faster + 80% fewer requests

Description

Thoughts:

  • This definitely ups the memory requirements, since dbt is caching a lot more. I don't believe this is huge cause for concer. The response for all versions of dbt_utils (https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json) is ~25KB, if my back-of-google-search arithmetic is to be believed
  • We already use memoize (a.k.a. functools.cache) to cache the registry index here, and explicitly call the cached version here. I'm sure that's the better the way to do this, rather than the jank global I'm using :)
  • If the registry redeploys / updates data during the <10 seconds between start and finish... I don't think we should try to handle for it. (I don't think we really handle for it currently, either.)

Anecdotal findings

Using our internal analytics project

Before:

  • 171 registry requests (Hub API)
  • 35 seconds before any package is actually downloaded (from GitHub tarball)
logs/dbt.log
============================== 2022-03-31 15:01:48.715296 | 0651fbdd-9a95-40d9-a530-7452367e657d ==============================
15:01:48.715296 [info ] [MainThread]: Running with dbt=1.0.3
15:01:48.715966 [debug] [MainThread]: running dbt with arguments Namespace(record_timing_info=None, debug=True, log_format=None, write_json=None, use_colors=None, printer_width=None, warn_error=None, version_check=None, partial_parse=None, single_threaded=False, use_experimental_parser=None, static_parser=None, profiles_dir='/Users/jerco/.dbt', send_anonymous_usage_stats=None, fail_fast=None, event_buffer_size=None, project_dir=None, profile=None, target=None, vars='{}', log_cache_events=False, defer=None, state=None, cls=<class 'dbt.task.deps.DepsTask'>, which='deps', rpc_method='deps')
15:01:48.716175 [debug] [MainThread]: Tracking: do not track
15:01:48.743134 [debug] [MainThread]: Set downloads directory='/var/folders/7h/hj5_fw9j291c58hwfdvy5xbm0000gp/T/dbt-downloads-2y9vlzju'
15:01:48.744169 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/index.json
15:01:48.938450 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/index.json 200
15:01:48.939287 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/audit_helper.json
15:01:49.112202 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/audit_helper.json 200
15:01:49.121947 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/audit_helper/0.5.0.json
15:01:49.284618 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/audit_helper/0.5.0.json 200
15:01:49.286913 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json
15:01:49.448459 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json 200
15:01:49.456709 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen/0.5.0.json
15:01:49.619097 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen/0.5.0.json 200
15:01:49.621165 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
15:01:49.779310 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
15:01:49.825389 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json
15:01:49.968680 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json 200
15:01:49.970417 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/snowplow.json
15:01:50.120185 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/snowplow.json 200
15:01:50.154029 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/snowplow/0.14.0.json
15:01:50.293088 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/snowplow/0.14.0.json 200
15:01:50.295411 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/hubspot.json
15:01:50.443854 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/hubspot.json 200
15:01:50.453002 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/hubspot/0.5.0.json
15:01:50.606405 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/hubspot/0.5.0.json 200
15:01:50.607766 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/zendesk_source.json
15:01:50.760025 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/zendesk_source.json 200
15:01:50.771361 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/zendesk_source/0.5.0.json
15:01:50.921988 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/zendesk_source/0.5.0.json 200
15:01:50.923505 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/ad_reporting.json
15:01:51.084740 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/ad_reporting.json 200
15:01:51.095366 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/ad_reporting/0.7.0.json
15:01:51.251576 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/ad_reporting/0.7.0.json 200
15:01:51.254118 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/social_media_reporting.json
15:01:51.417685 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/social_media_reporting.json 200
15:01:51.421271 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/social_media_reporting/0.1.0.json
15:01:51.579035 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/social_media_reporting/0.1.0.json 200
15:01:51.585399 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
15:01:51.739432 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
15:01:51.785340 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json
15:01:51.939745 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json 200
15:01:51.941783 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/hubspot_source.json
15:01:52.096582 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/hubspot_source.json 200
15:01:52.112640 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/hubspot_source/0.5.3.json
15:01:52.265040 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/hubspot_source/0.5.3.json 200
15:01:52.266592 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
15:01:52.413280 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json 200
15:01:52.436860 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils/0.3.5.json
15:01:52.587515 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils/0.3.5.json 200
15:01:52.589290 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/pinterest.json
15:01:52.746219 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/pinterest.json 200
15:01:52.756256 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/pinterest/0.5.0.json
15:01:52.936366 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/pinterest/0.5.0.json 200
15:01:52.938601 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads.json
15:01:53.098481 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads.json 200
15:01:53.110644 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads/0.4.1.json
15:01:53.273689 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads/0.4.1.json 200
15:01:53.276682 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin.json
15:01:53.441711 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin.json 200
15:01:53.466802 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin/0.4.0.json
15:01:54.330882 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin/0.4.0.json 200
15:01:54.333427 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/google_ads.json
15:01:54.661939 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/google_ads.json 200
15:01:54.667939 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/google_ads/0.6.1.json
15:01:54.812379 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/google_ads/0.6.1.json 200
15:01:54.814045 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads.json
15:01:55.186397 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads.json 200
15:01:55.190184 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads/0.1.1.json
15:01:55.356485 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads/0.1.1.json 200
15:01:55.358059 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads.json
15:01:55.530197 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads.json 200
15:01:55.537204 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads/0.4.0.json
15:01:55.850802 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads/0.4.0.json 200
15:01:55.852803 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads.json
15:01:56.264667 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads.json 200
15:01:56.270983 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads/0.4.1.json
15:01:56.415360 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads/0.4.1.json 200
15:01:56.416712 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads.json
15:01:56.757489 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads.json 200
15:01:56.762586 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads/0.3.0.json
15:01:56.922649 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads/0.3.0.json 200
15:01:56.923755 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages.json
15:01:57.284776 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages.json 200
15:01:57.287223 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages/0.1.0.json
15:01:57.438149 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages/0.1.0.json 200
15:01:57.439550 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business.json
15:01:57.611952 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business.json 200
15:01:57.613278 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business/0.1.0.json
15:01:57.928877 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business/0.1.0.json 200
15:01:57.930794 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic.json
15:01:58.331940 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic.json 200
15:01:58.334568 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic/0.1.0.json
15:01:58.504978 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic/0.1.0.json 200
15:01:58.507111 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages.json
15:01:58.675323 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages.json 200
15:01:58.679080 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages/0.1.1.json
15:01:58.968017 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages/0.1.1.json 200
15:01:58.970737 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
15:01:59.148542 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json 200
15:01:59.164744 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils/0.3.5.json
15:01:59.541555 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils/0.3.5.json 200
15:01:59.545226 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
15:01:59.902729 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
15:01:59.937195 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json
15:02:00.100515 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json 200
15:02:00.102497 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/pinterest_source.json
15:02:00.362441 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/pinterest_source.json 200
15:02:00.369829 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/pinterest_source/0.5.0.json
15:02:00.547546 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/pinterest_source/0.5.0.json 200
15:02:00.548976 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source.json
15:02:00.712153 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source.json 200
15:02:00.719993 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source/0.5.0.json
15:02:01.045927 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source/0.5.0.json 200
15:02:01.047471 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_source.json
15:02:01.218184 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_source.json 200
15:02:01.224389 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_source/0.4.0.json
15:02:01.500250 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_source/0.4.0.json 200
15:02:01.502467 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/google_ads_source.json
15:02:01.703373 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/google_ads_source.json 200
15:02:01.710202 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/google_ads_source/0.6.0.json
15:02:02.033101 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/google_ads_source/0.6.0.json 200
15:02:02.035227 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source.json
15:02:02.204833 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source.json 200
15:02:02.208296 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source/0.1.1.json
15:02:02.459590 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source/0.1.1.json 200
15:02:02.462549 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source.json
15:02:02.627938 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source.json 200
15:02:02.634881 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source/0.4.0.json
15:02:02.832624 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source/0.4.0.json 200
15:02:02.834863 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history.json
15:02:03.172791 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history.json 200
15:02:03.178916 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history/0.4.0.json
15:02:03.443175 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history/0.4.0.json 200
15:02:03.445158 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source.json
15:02:03.619257 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source.json 200
15:02:03.625826 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source/0.3.1.json
15:02:03.785606 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source/0.3.1.json 200
15:02:03.787778 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source.json
15:02:04.100031 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source.json 200
15:02:04.102271 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source/0.1.0.json
15:02:04.288181 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source/0.1.0.json 200
15:02:04.290356 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business_source.json
15:02:04.514561 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business_source.json 200
15:02:04.516442 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business_source/0.1.0.json
15:02:04.673547 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business_source/0.1.0.json 200
15:02:04.675802 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source.json
15:02:04.849617 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source.json 200
15:02:04.852226 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source/0.1.0.json
15:02:05.172429 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source/0.1.0.json 200
15:02:05.174999 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source.json
15:02:05.351814 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source.json 200
15:02:05.357055 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source/0.1.2.json
15:02:05.608305 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source/0.1.2.json 200
15:02:05.614243 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
15:02:05.771326 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
15:02:05.805423 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json
15:02:06.031194 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json 200
15:02:06.039543 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
15:02:06.343918 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json 200
15:02:06.361016 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils/0.3.5.json
15:02:06.620840 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils/0.3.5.json 200
15:02:06.629025 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json
15:02:06.809411 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json 200
15:02:06.815324 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils/0.3.0.json
15:02:06.965863 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils/0.3.0.json 200
15:02:06.967775 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/calogica/dbt_expectations.json
15:02:07.303025 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/calogica/dbt_expectations.json 200
15:02:07.323561 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/calogica/dbt_expectations/0.5.4.json
15:02:07.509884 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/calogica/dbt_expectations/0.5.4.json 200
15:02:07.511942 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source.json
15:02:07.770109 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source.json 200
15:02:07.776954 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source/0.4.0.json
15:02:07.964612 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source/0.4.0.json 200
15:02:07.971165 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
15:02:08.122033 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
15:02:08.154438 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json
15:02:08.460839 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json 200
15:02:08.462616 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/calogica/dbt_date.json
15:02:08.688717 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/calogica/dbt_date.json 200
15:02:08.703326 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/calogica/dbt_date/0.5.4.json
15:02:08.862906 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/calogica/dbt_date/0.5.4.json 200
15:02:08.872324 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
15:02:09.058488 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json 200
15:02:09.074241 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils/0.3.5.json
15:02:09.369444 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils/0.3.5.json 200
15:02:09.378301 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json
15:02:09.558975 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json 200
15:02:09.564968 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils/0.3.0.json
15:02:09.804711 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils/0.3.0.json 200
15:02:09.811741 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
15:02:09.996547 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
15:02:10.031412 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json
15:02:10.220794 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json 200
15:02:10.222445 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/audit_helper.json
15:02:10.532107 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/audit_helper.json 200
15:02:10.538950 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json
15:02:10.781191 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json 200
15:02:10.792310 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
15:02:10.992105 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
15:02:11.025723 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/snowplow.json
15:02:11.196072 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/snowplow.json 200
15:02:11.221780 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/hubspot.json
15:02:11.532329 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/hubspot.json 200
15:02:11.537943 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/zendesk_source.json
15:02:11.711245 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/zendesk_source.json 200
15:02:11.717330 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/ad_reporting.json
15:02:11.982477 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/ad_reporting.json 200
15:02:11.992227 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/social_media_reporting.json
15:02:12.191629 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/social_media_reporting.json 200
15:02:12.195580 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/hubspot_source.json
15:02:12.490026 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/hubspot_source.json 200
15:02:12.509511 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
15:02:12.673099 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json 200
15:02:12.685433 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/pinterest.json
15:02:12.944714 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/pinterest.json 200
15:02:12.951821 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads.json
15:02:13.108189 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads.json 200
15:02:13.115290 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin.json
15:02:13.308517 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin.json 200
15:02:13.315249 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/google_ads.json
15:02:13.630633 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/google_ads.json 200
15:02:13.639349 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads.json
15:02:13.831644 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads.json 200
15:02:13.836349 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads.json
15:02:14.094606 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads.json 200
15:02:14.101903 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads.json
15:02:14.299439 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads.json 200
15:02:14.306354 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads.json
15:02:14.615928 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads.json 200
15:02:14.621264 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages.json
15:02:14.788876 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages.json 200
15:02:14.791523 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business.json
15:02:14.988252 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business.json 200
15:02:14.990144 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic.json
15:02:15.136158 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic.json 200
15:02:15.141204 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages.json
15:02:15.300830 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages.json 200
15:02:15.305599 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/pinterest_source.json
15:02:15.476703 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/pinterest_source.json 200
15:02:15.486545 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source.json
15:02:15.635423 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source.json 200
15:02:15.644141 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_source.json
15:02:15.797702 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_source.json 200
15:02:15.805050 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/google_ads_source.json
15:02:15.952879 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/google_ads_source.json 200
15:02:15.965229 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source.json
15:02:16.116252 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source.json 200
15:02:16.119380 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source.json
15:02:16.263861 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source.json 200
15:02:16.267489 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history.json
15:02:16.406432 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history.json 200
15:02:16.413046 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source.json
15:02:16.551305 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source.json 200
15:02:16.553519 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source.json
15:02:16.769253 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source.json 200
15:02:16.774087 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business_source.json
15:02:16.906965 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business_source.json 200
15:02:16.908660 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source.json
15:02:17.054674 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source.json 200
15:02:17.056774 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source.json
15:02:17.210448 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source.json 200
15:02:17.223714 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json
15:02:17.371654 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json 200
15:02:17.380373 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/calogica/dbt_expectations.json
15:02:17.528043 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/calogica/dbt_expectations.json 200
15:02:17.537628 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source.json
15:02:17.675762 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source.json 200
15:02:17.681348 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/calogica/dbt_date.json
15:02:17.812863 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/calogica/dbt_date.json 200
15:02:17.820681 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/audit_helper/0.5.0.json
15:02:17.963088 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/audit_helper/0.5.0.json 200
15:02:17.965585 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen/0.5.0.json
15:02:18.114337 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen/0.5.0.json 200
15:02:18.115986 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json
15:02:18.262193 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils/0.8.0.json 200
15:02:18.263339 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/snowplow/0.14.0.json
15:02:18.543546 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/snowplow/0.14.0.json 200
15:02:18.544633 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/hubspot/0.5.0.json
15:02:18.689175 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/hubspot/0.5.0.json 200
15:02:18.690283 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/zendesk_source/0.5.0.json
15:02:18.834952 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/zendesk_source/0.5.0.json 200
15:02:18.836379 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/ad_reporting/0.7.0.json
15:02:18.989255 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/ad_reporting/0.7.0.json 200
15:02:18.990758 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/social_media_reporting/0.1.0.json
15:02:19.144762 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/social_media_reporting/0.1.0.json 200
15:02:19.146459 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/hubspot_source/0.5.3.json
15:02:19.303151 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/hubspot_source/0.5.3.json 200
15:02:19.305009 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils/0.3.5.json
15:02:19.465326 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils/0.3.5.json 200
15:02:19.466971 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/pinterest/0.5.0.json
15:02:19.612955 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/pinterest/0.5.0.json 200
15:02:19.630083 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads/0.4.1.json
15:02:19.781909 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads/0.4.1.json 200
15:02:19.783703 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin/0.4.0.json
15:02:19.929612 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin/0.4.0.json 200
15:02:19.931375 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/google_ads/0.6.1.json
15:02:20.088794 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/google_ads/0.6.1.json 200
15:02:20.090511 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads/0.1.1.json
15:02:20.241187 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads/0.1.1.json 200
15:02:20.242676 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads/0.4.0.json
15:02:20.393122 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads/0.4.0.json 200
15:02:20.394993 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads/0.4.1.json
15:02:20.536122 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads/0.4.1.json 200
15:02:20.537634 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads/0.3.0.json
15:02:20.682611 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads/0.3.0.json 200
15:02:20.683587 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages/0.1.0.json
15:02:20.831648 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages/0.1.0.json 200
15:02:20.832584 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business/0.1.0.json
15:02:20.973535 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business/0.1.0.json 200
15:02:20.975102 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic/0.1.0.json
15:02:21.127376 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic/0.1.0.json 200
15:02:21.129012 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages/0.1.1.json
15:02:21.279231 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages/0.1.1.json 200
15:02:21.280877 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/pinterest_source/0.5.0.json
15:02:21.434249 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/pinterest_source/0.5.0.json 200
15:02:21.435767 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source/0.5.0.json
15:02:21.587834 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source/0.5.0.json 200
15:02:21.589255 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_source/0.4.0.json
15:02:21.740442 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_source/0.4.0.json 200
15:02:21.742304 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/google_ads_source/0.6.0.json
15:02:21.891039 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/google_ads_source/0.6.0.json 200
15:02:21.893195 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source/0.1.1.json
15:02:22.039529 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source/0.1.1.json 200
15:02:22.041127 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source/0.4.0.json
15:02:22.197094 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source/0.4.0.json 200
15:02:22.198729 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history/0.4.0.json
15:02:22.352276 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history/0.4.0.json 200
15:02:22.353667 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source/0.3.1.json
15:02:22.506329 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source/0.3.1.json 200
15:02:22.507868 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source/0.1.0.json
15:02:22.664174 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source/0.1.0.json 200
15:02:22.665752 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business_source/0.1.0.json
15:02:22.818388 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business_source/0.1.0.json 200
15:02:22.820015 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source/0.1.0.json
15:02:22.969315 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source/0.1.0.json 200
15:02:22.970196 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source/0.1.2.json
15:02:23.110138 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source/0.1.2.json 200
15:02:23.111661 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils/0.3.0.json
15:02:23.283744 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils/0.3.0.json 200
15:02:23.285171 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/calogica/dbt_expectations/0.5.4.json
15:02:23.433851 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/calogica/dbt_expectations/0.5.4.json 200
15:02:23.435255 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source/0.4.0.json
15:02:23.587160 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source/0.4.0.json 200
15:02:23.588608 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/calogica/dbt_date/0.5.4.json
15:02:23.738777 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/calogica/dbt_date/0.5.4.json 200

After:

  • 39 registry requests
  • 132 cache hits
  • 7 seconds before any package is actually downloaded (from GitHub tarball)
logs/dbt.log
============================== 2022-03-31 14:59:07.195400 | c8e07478-bd3b-4bc3-bfcc-330c97f1d68e ==============================
14:59:07.195421 [info ] [MainThread]: Running with dbt=1.1.0-b1
14:59:07.196157 [debug] [MainThread]: running dbt with arguments {'debug': True, 'write_json': True, 'use_colors': True, 'printer_width': 80, 'version_check': False, 'partial_parse': False, 'static_parser': True, 'profiles_dir': '/Users/jerco/.dbt', 'send_anonymous_usage_stats': False, 'event_buffer_size': 100000, 'quiet': False, 'which': 'deps', 'rpc_method': 'deps', 'indirect_selection': 'eager'}
14:59:07.196350 [debug] [MainThread]: Tracking: do not track
14:59:07.233647 [debug] [MainThread]: Set downloads directory='/var/folders/7h/hj5_fw9j291c58hwfdvy5xbm0000gp/T/dbt-downloads-nsxazsx7'
14:59:07.235071 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/index.json
14:59:07.421712 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/index.json 200
14:59:07.422299 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/audit_helper.json
14:59:07.559613 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/audit_helper.json 200
14:59:07.566489 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/audit_helper.json
14:59:07.567375 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json
14:59:07.711940 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/codegen.json 200
14:59:07.718018 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/codegen.json
14:59:07.718701 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:07.863755 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json 200
14:59:07.900681 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:07.901224 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/snowplow.json
14:59:08.045237 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/snowplow.json 200
14:59:08.072092 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/snowplow.json
14:59:08.072673 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/hubspot.json
14:59:08.218499 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/hubspot.json 200
14:59:08.223912 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/hubspot.json
14:59:08.224702 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/zendesk_source.json
14:59:08.377197 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/zendesk_source.json 200
14:59:08.383423 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/zendesk_source.json
14:59:08.384528 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/ad_reporting.json
14:59:08.525919 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/ad_reporting.json 200
14:59:08.536402 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/ad_reporting.json
14:59:08.537776 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/social_media_reporting.json
14:59:08.688537 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/social_media_reporting.json 200
14:59:08.691260 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/social_media_reporting.json
14:59:08.694770 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:08.727825 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:08.728381 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/hubspot_source.json
14:59:08.872012 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/hubspot_source.json 200
14:59:08.888213 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/hubspot_source.json
14:59:08.888939 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
14:59:09.033410 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json 200
14:59:09.051775 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
14:59:09.052601 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/pinterest.json
14:59:09.201484 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/pinterest.json 200
14:59:09.210185 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/pinterest.json
14:59:09.211287 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads.json
14:59:09.357686 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads.json 200
14:59:09.364092 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/microsoft_ads.json
14:59:09.364915 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin.json
14:59:09.515535 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin.json 200
14:59:09.523366 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin.json
14:59:09.524311 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/google_ads.json
14:59:09.674963 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/google_ads.json 200
14:59:09.684209 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/google_ads.json
14:59:09.685234 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads.json
14:59:09.833867 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads.json 200
14:59:09.838119 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/tiktok_ads.json
14:59:09.839429 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads.json
14:59:09.990025 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads.json 200
14:59:09.996714 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_ads.json
14:59:09.997654 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads.json
14:59:10.147858 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads.json 200
14:59:10.154628 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_ads.json
14:59:10.155625 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads.json
14:59:10.307121 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads.json 200
14:59:10.312710 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/snapchat_ads.json
14:59:10.313786 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages.json
14:59:10.546486 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages.json 200
14:59:10.549579 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_pages.json
14:59:10.550697 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business.json
14:59:10.877623 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business.json 200
14:59:10.880176 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/instagram_business.json
14:59:10.881515 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic.json
14:59:11.108257 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic.json 200
14:59:11.110150 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_organic.json
14:59:11.111176 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages.json
14:59:11.350091 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages.json 200
14:59:11.354139 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin_pages.json
14:59:11.356001 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
14:59:11.371895 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
14:59:11.374786 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:11.400800 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:11.401207 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/pinterest_source.json
14:59:11.534271 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/pinterest_source.json 200
14:59:11.540717 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/pinterest_source.json
14:59:11.541484 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source.json
14:59:11.689738 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source.json 200
14:59:11.699416 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source.json
14:59:11.700471 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_source.json
14:59:11.849178 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_source.json 200
14:59:11.856333 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin_source.json
14:59:11.857388 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/google_ads_source.json
14:59:12.005526 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/google_ads_source.json 200
14:59:12.015798 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/google_ads_source.json
14:59:12.016854 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source.json
14:59:12.164887 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source.json 200
14:59:12.168801 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source.json
14:59:12.169920 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source.json
14:59:12.321373 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source.json 200
14:59:12.327687 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source.json
14:59:12.328649 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history.json
14:59:12.472875 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history.json 200
14:59:12.476306 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history.json
14:59:12.476910 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source.json
14:59:12.611788 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source.json 200
14:59:12.623553 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source.json
14:59:12.625021 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source.json
14:59:12.863142 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source.json 200
14:59:12.865383 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source.json
14:59:12.867213 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business_source.json
14:59:13.107125 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/instagram_business_source.json 200
14:59:13.110876 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/instagram_business_source.json
14:59:13.112418 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source.json
14:59:13.358629 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source.json 200
14:59:13.362776 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source.json
14:59:13.366888 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source.json
14:59:13.638856 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source.json 200
14:59:13.648068 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source.json
14:59:13.664039 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:13.725483 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:13.731249 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
14:59:13.741867 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
14:59:13.745589 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json
14:59:13.885102 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json 200
14:59:13.892687 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json
14:59:13.893886 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/calogica/dbt_expectations.json
14:59:14.044536 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/calogica/dbt_expectations.json 200
14:59:14.079236 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/calogica/dbt_expectations.json
14:59:14.080162 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source.json
14:59:14.236147 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source.json 200
14:59:14.247803 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source.json
14:59:14.254823 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:14.289533 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:14.290083 [debug] [MainThread]: Making package registry request: GET https://hub.getdbt.com/api/v1/calogica/dbt_date.json
14:59:14.431557 [debug] [MainThread]: Response from registry: GET https://hub.getdbt.com/api/v1/calogica/dbt_date.json 200
14:59:14.451283 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/calogica/dbt_date.json
14:59:14.459780 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
14:59:14.472790 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
14:59:14.477456 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json
14:59:14.480286 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json
14:59:14.483514 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:14.503260 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:14.503473 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/audit_helper.json
14:59:14.505722 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/codegen.json
14:59:14.509924 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:14.524184 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/snowplow.json
14:59:14.533353 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/hubspot.json
14:59:14.534762 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/zendesk_source.json
14:59:14.536148 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/ad_reporting.json
14:59:14.538831 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/social_media_reporting.json
14:59:14.539287 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/hubspot_source.json
14:59:14.546256 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
14:59:14.552055 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/pinterest.json
14:59:14.553986 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/microsoft_ads.json
14:59:14.555866 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin.json
14:59:14.557626 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/google_ads.json
14:59:14.560051 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/tiktok_ads.json
14:59:14.560835 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_ads.json
14:59:14.562583 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_ads.json
14:59:14.564270 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/snapchat_ads.json
14:59:14.565457 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_pages.json
14:59:14.565907 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/instagram_business.json
14:59:14.566355 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_organic.json
14:59:14.566798 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin_pages.json
14:59:14.567577 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/pinterest_source.json
14:59:14.569704 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source.json
14:59:14.572017 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin_source.json
14:59:14.573773 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/google_ads_source.json
14:59:14.576457 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source.json
14:59:14.577250 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source.json
14:59:14.579015 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history.json
14:59:14.580597 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source.json
14:59:14.582342 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source.json
14:59:14.582795 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/instagram_business_source.json
14:59:14.583240 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source.json
14:59:14.583676 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source.json
14:59:14.586919 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json
14:59:14.588504 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/calogica/dbt_expectations.json
14:59:14.595714 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source.json
14:59:14.597458 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/calogica/dbt_date.json
14:59:14.602157 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/audit_helper.json
14:59:14.602346 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/codegen.json
14:59:14.602503 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/dbt_utils.json
14:59:14.602650 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/snowplow.json
14:59:14.602797 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/hubspot.json
14:59:14.602945 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/zendesk_source.json
14:59:14.603093 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/ad_reporting.json
14:59:14.603271 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/social_media_reporting.json
14:59:14.603433 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/hubspot_source.json
14:59:14.603581 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/fivetran_utils.json
14:59:14.603728 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/pinterest.json
14:59:14.603874 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/microsoft_ads.json
14:59:14.604022 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin.json
14:59:14.604171 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/google_ads.json
14:59:14.604319 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/tiktok_ads.json
14:59:14.604465 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_ads.json
14:59:14.604611 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_ads.json
14:59:14.604759 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/snapchat_ads.json
14:59:14.604907 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_pages.json
14:59:14.605054 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/instagram_business.json
14:59:14.605200 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_organic.json
14:59:14.605357 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin_pages.json
14:59:14.605504 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/pinterest_source.json
14:59:14.605659 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/microsoft_ads_source.json
14:59:14.605812 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin_source.json
14:59:14.606000 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/google_ads_source.json
14:59:14.606168 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/tiktok_ads_source.json
14:59:14.606322 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_ads_source.json
14:59:14.606480 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_ads_creative_history.json
14:59:14.606630 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/snapchat_ads_source.json
14:59:14.606780 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_pages_source.json
14:59:14.606930 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/instagram_business_source.json
14:59:14.607081 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/twitter_organic_source.json
14:59:14.607231 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/linkedin_pages_source.json
14:59:14.607380 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/dbt-labs/spark_utils.json
14:59:14.607520 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/calogica/dbt_expectations.json
14:59:14.607665 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/fivetran/facebook_ads_source.json
14:59:14.607816 [debug] [MainThread]: Using cached registry response for: https://hub.getdbt.com/api/v1/calogica/dbt_date.json

That's almost 80% fewer requests :)

This would be most effective in projects that:

  • Have lots of Hub package dependencies
  • Those Hub packages depend on other Hub packages (dbt_utils is a common favorite)

Checklist

  • I have signed the CLA
  • I have run this code in development and it appears to resolve the stated issue
  • This PR includes tests, or tests are not required/relevant for this PR
  • I have added information about my change to be included in the CHANGELOG.

@cla-bot cla-bot bot added the cla:yes label Mar 31, 2022
@github-actions
Copy link
Contributor

Thank you for your pull request! We could not find a changelog entry for this change. For details on how to document a change, see the contributing guide.

fire_event(RegistryProgressMakingGETRequest(url=url))
resp = requests.get(url, timeout=30)
fire_event(RegistryProgressGETResponse(url=url, resp_code=resp.status_code))
resp.raise_for_status()

json_response = (
resp.json() # if this fails, it should raise requests.exceptions.JSONDecodeError and trigger retry
Copy link

@barberscott barberscott Mar 31, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One observation here is that if we have standards about not just that the response is JSON, but that the JSON is constructed in a very specific way, we would need those logic checks here.

e.g. the def package(name, registry_base_url=None): block makes some assumptions about the structure of the json itself that resp.json() won't catch if the response is JSON, but not the right JSON. My hypothesis is that ~60% of the current failures we see in Cloud logging, that's exactly what's happening. We get a JSON back, just not the JSON we want, hence the failure with the NoneType in the package() call.

In the case of separate invocations of deps, we would still, I would imagine, want to retry if the cache was empty -- so I am gathering url = _get_url(path, registry_base_url) is doing that with the changes above in if url in REGISTRY_CACHE.keys().

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jtcohen6 your recommended changes in #4982 probably sort that and would get pulled in here.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

not the right JSON. My hypothesis is that ~60% of the current failures we see in Cloud logging, that's exactly what's happening. We get a JSON back, just not the JSON we want, hence the failure with the NoneType in the package() call.

@barberscott That's illuminating!

@emmyoop It sounds to me like we might need, in addition to validating whether the JSON is a valid list/dict (#4982), to be able to either:

  • Pass a set of "expected" keys into _get (e.g. versions, namespace, name, downloads, ...), and have it raise a ContentDecodingError if a valid-but-incorrect/incomplete JSON body is returned
  • Move more validation logic, such as RegistryPackageMetadata.from_dict(), from deps/registry.py to clients/registry.py, within the methods where we can retry those requests. It's less-clean code, and worse separation of concerns... but it's also an acknowledgment that these concerns are not easily separated.

The appeal of the change in this PR is that it narrows us down to making only two types of requests: api/v1/index.json and api/v1/{packagename}.json. Some cluttering of the code for two doesn't feel quite as costly as it would for many.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In the case of separate invocations of deps, we would still, I would imagine, want to retry if the cache was empty

Yeah, this cache won't be persisted at all between separate invocations. I feel even better saying that after having switched out my janky "global" for the Python stdlib approach.

Copy link
Member

@emmyoop emmyoop left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I like this. Speeds things up and also reduces the chance of errors.

I think, as you pointed out, you would be able to use it without the global. If you define _get_cached = memoized(_get) and replace the _get in _get_with_retries() with get_cached. I did a quick test and it seems to work.

@dataclass
class RegistryCacheHit(DebugLevel):
url: str
code: str = "M010"
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

super minor but M010 lives somewhere else. I think it's up to M022 now.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good call. I think the memoized approach preempts the log message entirely. No need to take a victory lap for a thing we should have been doing anyway :)

@@ -49,6 +64,7 @@ def index(registry_base_url=None):
index_cached = memoized(index)


# not used, and this "endpoint" returns 'null'. here for backwards compatibility?
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I removed this in #4942 since it wasn't called.

Comment on lines +2425 to +2426
RegistryProgressMakingGETRequest(url="")
RegistryProgressGETResponse(url="", resp_code=1234)
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd noticed that these were missing from the mypy type checking list. No longer relevant to this PR, happy to leave in or split out as a separate (tiny) tech debt ticket, i.e. ensure complete type checking coverage for all event types defined in the file

return json_response


_get_cached = memoized(_get)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is the indenting right here?

Copy link
Contributor Author

@jtcohen6 jtcohen6 Apr 1, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think so? Could alternatively try using the @cache decorator on _get above: https://docs.python.org/3/library/functools.html#functools.cache

index_cached = memoized(index)


def packages(registry_base_url=None):
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this just not used anywhere?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not used anywhere, and this API doesn't return anything: https://hub.getdbt.com/api/v1/packages.json

@emmyoop found the same thing in #4982

@@ -80,7 +83,8 @@ def package(name, registry_base_url=None):


def package_version(name, version, registry_base_url=None):
return _get_with_retries("api/v1/{}/{}.json".format(name, version), registry_base_url)
response = package(name, registry_base_url)
return response["versions"][version]
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does the API return all the available versions when we don't pass a version to it? If the version doesn't exist (is that possible?), do we handle that correctly?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if not target:
package_version_not_found(self.package, range_, installable)

That gets the set of available versions from get_available_versions (defined below), which is hitting the same endpoint as this method. E.g.

09:12:54  Encountered an error:
Could not find a matching version for package dbt-labs/dbt_utils
  Requested range: =0.141.24, =0.141.24
  Available versions: ['0.0.1', '0.1.0', '0.1.1', '0.1.2', '0.1.3', '0.1.4', '0.1.5', '0.1.6', '0.1.7', '0.1.8', '0.1.9', '0.1.10', '0.1.11', '0.1.12', '0.1.13', '0.1.14', '0.1.15', '0.1.16', '0.1.17', '0.1.18', '0.1.19', '0.1.20', '0.1.21', '0.1.22', '0.1.23', '0.1.24', '0.1.25', '0.2.0', '0.2.1', '0.2.2', '0.2.3', '0.2.4', '0.2.5', '0.3.0', '0.4.0', '0.4.1', '0.5.0', '0.5.1', '0.6.0', '0.6.1', '0.6.2', '0.6.3', '0.6.4', '0.6.5', '0.6.6', '0.7.0', '0.7.1', '0.7.2', '0.7.3', '0.7.4', '0.7.5', '0.7.6', '0.8.0', '0.8.1', '0.8.2']



def index(registry_base_url=None):
return _get_with_retries("api/v1/index.json", registry_base_url)


# is this redundant, now that all _get responses are being cached?
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch!

@emmyoop
Copy link
Member

emmyoop commented Apr 1, 2022

I've pulled this branch into #4982 since it was very intertwined.

@jtcohen6
Copy link
Contributor Author

jtcohen6 commented Apr 2, 2022

Happily closing in favor of #4982!

@jtcohen6 jtcohen6 closed this Apr 2, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[Bug] dbt deps sometimes takes >90sec to complete
4 participants