saving unfinished test

* adds new function fire_event_if

.bumpversion.cfg

@@ -1,5 +1,5 @@
 [bumpversion]
-current_version = 1.0.0rc3
+current_version = 1.0.1
 parse = (?P<major>\d+)
 	\.(?P<minor>\d+)
 	\.(?P<patch>\d+)

.github/workflows/release.yml

@@ -95,7 +95,9 @@ jobs:
       - uses: actions/upload-artifact@v2
         with:
           name: dist
-          path: dist/
+          path: |
+            dist/
+            !dist/dbt-${{github.event.inputs.version_number}}.tar.gz
 
   test-build:
     name: verify packages

.github/workflows/structured-logging-schema-check.yml

@@ -0,0 +1,71 @@
+# This Action checks makes a dbt run to sample json structured logs
+# and checks that they conform to the currently documented schema.
+# 
+# If this action fails it either means we have unintentionally deviated
+# from our documented structured logging schema, or we need to bump the
+# version of our structured logging and add new documentation to
+# communicate these changes.
+
+
+name: Structured Logging Schema Check
+on:
+  push:
+    branches:
+      - "main"
+      - "*.latest"
+      - "releases/*"
+  pull_request:
+  workflow_dispatch:
+
+permissions: read-all
+
+jobs:
+  # run the performance measurements on the current or default branch
+  test-schema:
+    name: Test Log Schema
+    runs-on: ubuntu-latest
+    env:
+      # turns warnings into errors
+      RUSTFLAGS: "-D warnings"
+      # points tests to the log file
+      LOG_DIR: "/home/runner/work/dbt-core/dbt-core/logs"
+      # tells integration tests to output into json format
+      DBT_LOG_FORMAT: 'json'
+    steps:
+
+      - name: checkout dev
+        uses: actions/checkout@v2
+        with:
+          persist-credentials: false
+
+      - name: Setup Python
+        uses: actions/setup-python@v2.2.2
+        with:
+          python-version: "3.8"
+
+      - uses: actions-rs/toolchain@v1
+        with:
+          profile: minimal
+          toolchain: stable
+          override: true
+
+      - name: install dbt
+        run: pip install -r dev-requirements.txt -r editable-requirements.txt
+
+      - name: Set up postgres
+        uses: ./.github/actions/setup-postgres-linux
+
+      - name: ls
+        run: ls
+
+      # integration tests generate a ton of logs in different files. the next step will find them all.
+      # we actually care if these pass, because the normal test run doesn't usually include many json log outputs
+      - name: Run integration tests
+        run: tox -e py38-postgres -- -nauto
+
+      # apply our schema tests to every log event from the previous step
+      # skips any output that isn't valid json
+      - uses: actions-rs/cargo@v1
+        with:
+          command: run
+          args: --manifest-path test/interop/log_parsing/Cargo.toml

CHANGELOG.md

@@ -1,4 +1,70 @@
-## dbt-core 1.0.0 (Release TBD)
+## dbt-core 1.1.0 (TBD)
+
+### Features
+- New Dockerfile to support specific db adapters and platforms.  See docker/README.md for details ([#4495](https://github.com/dbt-labs/dbt-core/issues/4495), [#4487](https://github.com/dbt-labs/dbt-core/pull/4487))
+
+### Under the hood
+- Testing cleanup ([#4496](https://github.com/dbt-labs/dbt-core/pull/4496), [#4509](https://github.com/dbt-labs/dbt-core/pull/4509))
+- Clean up test deprecation warnings ([#3988](https://github.com/dbt-labs/dbt-core/issue/3988), [#4556](https://github.com/dbt-labs/dbt-core/pull/4556))
+
+## dbt-core 1.0.2 (TBD)
+
+### Fixes
+- Projects created using `dbt init` now have the correct `seeds` directory created (instead of `data`) ([#4588](https://github.com/dbt-labs/dbt-core/issues/4588), [#4599](https://github.com/dbt-labs/dbt-core/pull/4589))
+- Don't require a profile for dbt deps and clean commands ([#4554](https://github.com/dbt-labs/dbt-core/issues/4554), [#4610](https://github.com/dbt-labs/dbt-core/pull/4610))
+- Select modified.body works correctly when new model added([#4570](https://github.com/dbt-labs/dbt-core/issues/4570), [#4631](https://github.com/dbt-labs/dbt-core/pull/4631))
+- Fix bug in retry logic for bad response from hub and when there is a bad git tarball download. ([#4577](https://github.com/dbt-labs/dbt-core/issues/4577), [#4579](https://github.com/dbt-labs/dbt-core/issues/4579), [#4609](https://github.com/dbt-labs/dbt-core/pull/4609)) 
+- Restore previous log level (DEBUG) when a test depends on a disabled resource. Still WARN if the resource is missing ([#4594](https://github.com/dbt-labs/dbt-core/issues/4594), [#4647](https://github.com/dbt-labs/dbt-core/pull/4647))
+- User wasn't asked for permission to overwite a profile entry when running init inside an existing project ([#4375](https://github.com/dbt-labs/dbt-core/issues/4375), [#4447](https://github.com/dbt-labs/dbt-core/pull/4447))
+
+Contributors:
+- [@NiallRees](https://github.com/NiallRees) ([#4447](https://github.com/dbt-labs/dbt-core/pull/4447))
+
+## dbt-core 1.0.1 (January 03, 2022)
+
+## dbt-core 1.0.1rc1 (December 20, 2021)
+
+### Fixes
+- Fix wrong url in the dbt docs overview homepage ([#4442](https://github.com/dbt-labs/dbt-core/pull/4442))
+- Fix redefined status param of SQLQueryStatus to typecheck the string which passes on `._message` value of `AdapterResponse` or the `str` value sent by adapter plugin.  ([#4463](https://github.com/dbt-labs/dbt-core/pull/4463#issuecomment-990174166))
+- Fix `DepsStartPackageInstall` event to use package name instead of version number. ([#4482](https://github.com/dbt-labs/dbt-core/pull/4482))
+- Reimplement log message to use adapter name instead of the object method. ([#4501](https://github.com/dbt-labs/dbt-core/pull/4501))
+- Issue better error message for incompatible schemas ([#4470](https://github.com/dbt-labs/dbt-core/pull/4442), [#4497](https://github.com/dbt-labs/dbt-core/pull/4497))
+- Remove secrets from error related to packages. ([#4507](https://github.com/dbt-labs/dbt-core/pull/4507))
+- Prevent coercion of boolean values (`True`, `False`) to numeric values (`0`, `1`) in query results ([#4511](https://github.com/dbt-labs/dbt-core/issues/4511), [#4512](https://github.com/dbt-labs/dbt-core/pull/4512))
+- Fix error with an env_var in a project hook ([#4523](https://github.com/dbt-labs/dbt-core/issues/4523), [#4524](https://github.com/dbt-labs/dbt-core/pull/4524))
+
+###  Docs
+- Fix missing data on exposures in docs ([#4467](https://github.com/dbt-labs/dbt-core/issues/4467))
+
+Contributors:
+- [remoyson](https://github.com/remoyson) ([#4442](https://github.com/dbt-labs/dbt-core/pull/4442))
+
+## dbt-core 1.0.0 (December 3, 2021)
+
+### Fixes
+- Configure the CLI logger destination to use stdout instead of stderr ([#4368](https://github.com/dbt-labs/dbt-core/pull/4368))
+- Make the size of `EVENT_HISTORY` configurable, via `EVENT_BUFFER_SIZE` global config ([#4411](https://github.com/dbt-labs/dbt-core/pull/4411), [#4416](https://github.com/dbt-labs/dbt-core/pull/4416))
+- Change type of `log_format` in `profiles.yml` user config to be string, not boolean ([#4394](https://github.com/dbt-labs/dbt-core/pull/4394))
+
+### Under the hood
+- Only log cache events if `LOG_CACHE_EVENTS` is enabled, and disable by default. This restores previous behavior ([#4369](https://github.com/dbt-labs/dbt-core/pull/4369))
+- Move event codes to be a top-level attribute of JSON-formatted logs, rather than nested in `data` ([#4381](https://github.com/dbt-labs/dbt-core/pull/4381))
+- Fix failing integration test on Windows ([#4380](https://github.com/dbt-labs/dbt-core/pull/4380))
+- Clean up warning messages for `clean` + `deps` ([#4366](https://github.com/dbt-labs/dbt-core/pull/4366))
+- Use RFC3339 timestamps for log messages ([#4384](https://github.com/dbt-labs/dbt-core/pull/4384))
+- Different text output for console (info) and file (debug) logs ([#4379](https://github.com/dbt-labs/dbt-core/pull/4379), [#4418](https://github.com/dbt-labs/dbt-core/pull/4418))
+- Remove unused events. More structured `ConcurrencyLine`. Replace `\n` message starts/ends with `EmptyLine` events, and exclude `EmptyLine` from JSON-formatted output ([#4388](https://github.com/dbt-labs/dbt-core/pull/4388))
+- Update `events` module README ([#4395](https://github.com/dbt-labs/dbt-core/pull/4395))
+- Rework approach to JSON serialization for events with non-standard properties ([#4396](https://github.com/dbt-labs/dbt-core/pull/4396))
+- Update legacy logger file name to `dbt.log.legacy` ([#4402](https://github.com/dbt-labs/dbt-core/pull/4402))
+- Rollover `dbt.log` at 10 MB, and keep up to 5 backups, restoring previous behavior ([#4405](https://github.com/dbt-labs/dbt-core/pull/4405))
+- Use reference keys instead of full relation objects in cache events ([#4410](https://github.com/dbt-labs/dbt-core/pull/4410))
+- Add `node_type` contextual info to more events ([#4378](https://github.com/dbt-labs/dbt-core/pull/4378))
+- Make `materialized` config optional in `node_type` ([#4417](https://github.com/dbt-labs/dbt-core/pull/4417))
+- Stringify exception in `GenericExceptionOnRun` to support JSON serialization ([#4424](https://github.com/dbt-labs/dbt-core/pull/4424))
+- Add "interop" tests for machine consumption of structured log output ([#4327](https://github.com/dbt-labs/dbt-core/pull/4327))
+- Relax version specifier for `dbt-extractor` to `~=0.4.0`, to support compiled wheels for additional architectures when available ([#4427](https://github.com/dbt-labs/dbt-core/pull/4427))
 
 ## dbt-core 1.0.0rc3 (November 30, 2021)
 
@@ -176,7 +242,7 @@ Contributors:
 - [@laxjesse](https://github.com/laxjesse) ([#4019](https://github.com/dbt-labs/dbt-core/pull/4019))
 - [@gitznik](https://github.com/Gitznik) ([#4124](https://github.com/dbt-labs/dbt-core/pull/4124))
 
-## dbt 0.21.1 (Release TBD)
+## dbt 0.21.1 (November 29, 2021)
 
 ### Fixes
 - Add `get_where_subquery` to test macro namespace, fixing custom generic tests that rely on introspecting the `model` arg at parse time ([#4195](https://github.com/dbt-labs/dbt/issues/4195), [#4197](https://github.com/dbt-labs/dbt/pull/4197))
@@ -320,7 +386,7 @@ Contributors:
 - [@jmriego](https://github.com/jmriego) ([#3526](https://github.com/dbt-labs/dbt-core/pull/3526))
 - [@danielefrigo](https://github.com/danielefrigo) ([#3547](https://github.com/dbt-labs/dbt-core/pull/3547))
 
-## dbt 0.20.2 (Release TBD)
+## dbt 0.20.2 (September 07, 2021)
 
 ### Under the hood
 

core/dbt/adapters/base/impl.py

@@ -39,7 +39,7 @@ from dbt.adapters.base.relation import (
     ComponentName, BaseRelation, InformationSchema, SchemaSearchMap
 )
 from dbt.adapters.base import Column as BaseColumn
-from dbt.adapters.cache import RelationsCache
+from dbt.adapters.cache import RelationsCache, _make_key
 
 
 SeedModel = Union[ParsedSeedNode, CompiledSeedNode]
@@ -291,7 +291,7 @@ class BaseAdapter(metaclass=AdapterMeta):
         if (database, schema) not in self.cache:
             fire_event(
                 CacheMiss(
-                    conn_name=self.nice_connection_name,
+                    conn_name=self.nice_connection_name(),
                     database=database,
                     schema=schema
                 )
@@ -676,7 +676,11 @@ class BaseAdapter(metaclass=AdapterMeta):
         relations = self.list_relations_without_caching(
             schema_relation
         )
-        fire_event(ListRelations(database=database, schema=schema, relations=relations))
+        fire_event(ListRelations(
+            database=database,
+            schema=schema,
+            relations=[_make_key(x) for x in relations]
+        ))
 
         return relations
 

core/dbt/adapters/cache.py

@@ -1,10 +1,10 @@
 import threading
-from collections import namedtuple
 from copy import deepcopy
 from typing import Any, Dict, Iterable, List, Optional, Set, Tuple
 
+from dbt.adapters.reference_keys import _make_key, _ReferenceKey
 import dbt.exceptions
-from dbt.events.functions import fire_event
+from dbt.events.functions import fire_event, fire_event_if
 from dbt.events.types import (
     AddLink,
     AddRelation,
@@ -20,20 +20,9 @@ from dbt.events.types import (
     UncachedRelation,
     UpdateReference
 )
+import dbt.flags as flags
 from dbt.utils import lowercase
 
-_ReferenceKey = namedtuple('_ReferenceKey', 'database schema identifier')
-
-
-def _make_key(relation) -> _ReferenceKey:
-    """Make _ReferenceKeys with lowercase values for the cache so we don't have
-    to keep track of quoting
-    """
-    # databases and schemas can both be None
-    return _ReferenceKey(lowercase(relation.database),
-                         lowercase(relation.schema),
-                         lowercase(relation.identifier))
-
 
 def dot_separated(key: _ReferenceKey) -> str:
     """Return the key in dot-separated string form.
@@ -334,12 +323,12 @@ class RelationsCache:
         :param BaseRelation relation: The underlying relation.
         """
         cached = _CachedRelation(relation)
-        fire_event(AddRelation(relation=cached))
-        fire_event(DumpBeforeAddGraph(dump=self.dump_graph()))
+        fire_event(AddRelation(relation=_make_key(cached)))
+        fire_event_if(flags.LOG_CACHE_EVENTS, lambda: DumpBeforeAddGraph(dump=self.dump_graph()))
 
         with self.lock:
             self._setdefault(cached)
-        fire_event(DumpAfterAddGraph(dump=self.dump_graph()))
+        fire_event_if(flags.LOG_CACHE_EVENTS, lambda: DumpAfterAddGraph(dump=self.dump_graph()))
 
     def _remove_refs(self, keys):
         """Removes all references to all entries in keys. This does not
@@ -452,8 +441,10 @@ class RelationsCache:
         old_key = _make_key(old)
         new_key = _make_key(new)
         fire_event(RenameSchema(old_key=old_key, new_key=new_key))
-
-        fire_event(DumpBeforeRenameSchema(dump=self.dump_graph()))
+        fire_event_if(
+            flags.LOG_CACHE_EVENTS,
+            lambda: DumpBeforeRenameSchema(dump=self.dump_graph())
+        )
 
         with self.lock:
             if self._check_rename_constraints(old_key, new_key):
@@ -461,7 +452,10 @@ class RelationsCache:
             else:
                 self._setdefault(_CachedRelation(new))
 
-        fire_event(DumpAfterRenameSchema(dump=self.dump_graph()))
+        fire_event_if(
+            flags.LOG_CACHE_EVENTS,
+            lambda: DumpAfterRenameSchema(dump=self.dump_graph())
+        )
 
     def get_relations(
         self, database: Optional[str], schema: Optional[str]

core/dbt/adapters/reference_keys.py

@@ -0,0 +1,24 @@
+# this module exists to resolve circular imports with the events module
+
+from collections import namedtuple
+from typing import Optional
+
+
+_ReferenceKey = namedtuple('_ReferenceKey', 'database schema identifier')
+
+
+def lowercase(value: Optional[str]) -> Optional[str]:
+    if value is None:
+        return None
+    else:
+        return value.lower()
+
+
+def _make_key(relation) -> _ReferenceKey:
+    """Make _ReferenceKeys with lowercase values for the cache so we don't have
+    to keep track of quoting
+    """
+    # databases and schemas can both be None
+    return _ReferenceKey(lowercase(relation.database),
+                         lowercase(relation.schema),
+                         lowercase(relation.identifier))

core/dbt/adapters/sql/connections.py

@@ -75,7 +75,8 @@ class SQLConnectionManager(BaseConnectionManager):
 
             fire_event(
                 SQLQueryStatus(
-                    status=str(self.get_response(cursor)), elapsed=round((time.time() - pre), 2)
+                    status=str(self.get_response(cursor)),
+                    elapsed=round((time.time() - pre), 2)
                 )
             )
 

core/dbt/adapters/sql/impl.py

@@ -5,6 +5,7 @@ import dbt.clients.agate_helper
 from dbt.contracts.connection import Connection
 import dbt.exceptions
 from dbt.adapters.base import BaseAdapter, available
+from dbt.adapters.cache import _make_key
 from dbt.adapters.sql import SQLConnectionManager
 from dbt.events.functions import fire_event
 from dbt.events.types import ColTypeChange, SchemaCreation, SchemaDrop
@@ -182,7 +183,7 @@ class SQLAdapter(BaseAdapter):
 
     def create_schema(self, relation: BaseRelation) -> None:
         relation = relation.without_identifier()
-        fire_event(SchemaCreation(relation=relation))
+        fire_event(SchemaCreation(relation=_make_key(relation)))
         kwargs = {
             'relation': relation,
         }
@@ -193,7 +194,7 @@ class SQLAdapter(BaseAdapter):
 
     def drop_schema(self, relation: BaseRelation) -> None:
         relation = relation.without_identifier()
-        fire_event(SchemaDrop(relation=relation))
+        fire_event(SchemaDrop(relation=_make_key(relation)))
         kwargs = {
             'relation': relation,
         }

core/dbt/clients/agate_helper.py

@@ -13,6 +13,18 @@ from dbt.exceptions import RuntimeException
 BOM = BOM_UTF8.decode('utf-8')  # '\ufeff'
 
 
+class Number(agate.data_types.Number):
+    # undo the change in https://github.com/wireservice/agate/pull/733
+    # i.e. do not cast True and False to numeric 1 and 0
+    def cast(self, d):
+        if type(d) == bool:
+            raise agate.exceptions.CastError(
+                'Do not cast True to 1 or False to 0.'
+            )
+        else:
+            return super().cast(d)
+
+
 class ISODateTime(agate.data_types.DateTime):
     def cast(self, d):
         # this is agate.data_types.DateTime.cast with the "clever" bits removed
@@ -41,7 +53,7 @@ def build_type_tester(
 ) -> agate.TypeTester:
 
     types = [
-        agate.data_types.Number(null_values=('null', '')),
+        Number(null_values=('null', '')),
         agate.data_types.Date(null_values=('null', ''),
                               date_format='%Y-%m-%d'),
         agate.data_types.DateTime(null_values=('null', ''),

core/dbt/clients/git.py

@@ -8,7 +8,10 @@ from dbt.events.types import (
     GitProgressUpdatingExistingDependency, GitProgressPullingNewDependency,
     GitNothingToDo, GitProgressUpdatedCheckoutRange, GitProgressCheckedOutAt
 )
-import dbt.exceptions
+from dbt.exceptions import (
+    CommandResultError, RuntimeException, bad_package_spec, raise_git_cloning_error,
+    raise_git_cloning_problem
+)
 from packaging import version
 
 
@@ -22,9 +25,9 @@ def _raise_git_cloning_error(repo, revision, error):
     if 'usage: git' in stderr:
         stderr = stderr.split('\nusage: git')[0]
     if re.match("fatal: destination path '(.+)' already exists", stderr):
-        raise error
+        raise_git_cloning_error(error)
 
-    dbt.exceptions.bad_package_spec(repo, revision, stderr)
+    bad_package_spec(repo, revision, stderr)
 
 
 def clone(repo, cwd, dirname=None, remove_git_dir=False, revision=None, subdirectory=None):
@@ -53,7 +56,7 @@ def clone(repo, cwd, dirname=None, remove_git_dir=False, revision=None, subdirec
         clone_cmd.append(dirname)
     try:
         result = run_cmd(cwd, clone_cmd, env={'LC_ALL': 'C'})
-    except dbt.exceptions.CommandResultError as exc:
+    except CommandResultError as exc:
         _raise_git_cloning_error(repo, revision, exc)
 
     if subdirectory:
@@ -61,7 +64,7 @@ def clone(repo, cwd, dirname=None, remove_git_dir=False, revision=None, subdirec
         clone_cmd_subdir = ['git', 'sparse-checkout', 'set', subdirectory]
         try:
             run_cmd(cwd_subdir, clone_cmd_subdir)
-        except dbt.exceptions.CommandResultError as exc:
+        except CommandResultError as exc:
             _raise_git_cloning_error(repo, revision, exc)
 
     if remove_git_dir:
@@ -105,9 +108,9 @@ def checkout(cwd, repo, revision=None):
         revision = 'HEAD'
     try:
         return _checkout(cwd, repo, revision)
-    except dbt.exceptions.CommandResultError as exc:
+    except CommandResultError as exc:
         stderr = exc.stderr.decode('utf-8').strip()
-    dbt.exceptions.bad_package_spec(repo, revision, stderr)
+    bad_package_spec(repo, revision, stderr)
 
 
 def get_current_sha(cwd):
@@ -131,14 +134,11 @@ def clone_and_checkout(repo, cwd, dirname=None, remove_git_dir=False,
             remove_git_dir=remove_git_dir,
             subdirectory=subdirectory,
         )
-    except dbt.exceptions.CommandResultError as exc:
+    except CommandResultError as exc:
         err = exc.stderr.decode('utf-8')
         exists = re.match("fatal: destination path '(.+)' already exists", err)
         if not exists:
-            print(
-                '\nSomething went wrong while cloning {}'.format(repo) +
-                '\nCheck the debug logs for more information')
-            raise
+            raise_git_cloning_problem(repo)
 
     directory = None
     start_sha = None
@@ -148,7 +148,7 @@ def clone_and_checkout(repo, cwd, dirname=None, remove_git_dir=False,
     else:
         matches = re.match("Cloning into '(.+)'", err.decode('utf-8'))
         if matches is None:
-            raise dbt.exceptions.RuntimeException(
+            raise RuntimeException(
                 f'Error cloning {repo} - never saw "Cloning into ..." from git'
             )
         directory = matches.group(1)

core/dbt/clients/registry.py

@@ -33,7 +33,12 @@ def _get(path, registry_base_url=None):
     resp = requests.get(url, timeout=30)
     fire_event(RegistryProgressGETResponse(url=url, resp_code=resp.status_code))
     resp.raise_for_status()
-    if resp is None:
+
+    # It is unexpected for the content of the response to be None so if it is, raising this error
+    # will cause this function to retry (if called within _get_with_retries) and hopefully get
+    # a response.  This seems to happen when there's an issue with the Hub.
+    # See https://github.com/dbt-labs/dbt-core/issues/4577
+    if resp.json() is None:
         raise requests.exceptions.ContentDecodingError(
             'Request error: The response is None', response=resp
         )

core/dbt/clients/system.py

@@ -485,7 +485,7 @@ def untar_package(
 ) -> None:
     tar_path = convert_path(tar_path)
     tar_dir_name = None
-    with tarfile.open(tar_path, 'r') as tarball:
+    with tarfile.open(tar_path, 'r:gz') as tarball:
         tarball.extractall(dest_dir)
         tar_dir_name = os.path.commonprefix(tarball.getnames())
     if rename_to:

core/dbt/config/project.py

@@ -45,7 +45,7 @@ INVALID_VERSION_ERROR = """\
 This version of dbt is not supported with the '{package}' package.
   Installed version of dbt: {installed}
   Required version of dbt for '{package}': {version_spec}
-Check the requirements for the '{package}' package, or run dbt again with \
+Check for a different version of the '{package}' package, or run dbt again with \
 --no-version-check
 """
 
@@ -54,7 +54,7 @@ IMPOSSIBLE_VERSION_ERROR = """\
 The package version requirement can never be satisfied for the '{package}
 package.
   Required versions of dbt for '{package}': {version_spec}
-Check the requirements for the '{package}' package, or run dbt again with \
+Check for a different version of the '{package}' package, or run dbt again with \
 --no-version-check
 """
 

core/dbt/config/runtime.py

@@ -1,7 +1,7 @@
 import itertools
 import os
 from copy import deepcopy
-from dataclasses import dataclass, fields
+from dataclasses import dataclass
 from pathlib import Path
 from typing import (
     Dict, Any, Optional, Mapping, Iterator, Iterable, Tuple, List, MutableSet,
@@ -13,20 +13,17 @@ from .project import Project
 from .renderer import DbtProjectYamlRenderer, ProfileRenderer
 from .utils import parse_cli_vars
 from dbt import flags
-from dbt import tracking
 from dbt.adapters.factory import get_relation_class_by_name, get_include_paths
 from dbt.helper_types import FQNPath, PathSet
+from dbt.config.profile import read_user_config
 from dbt.contracts.connection import AdapterRequiredConfig, Credentials
 from dbt.contracts.graph.manifest import ManifestMetadata
 from dbt.contracts.relation import ComponentName
-from dbt.events.types import ProfileLoadError, ProfileNotFound
-from dbt.events.functions import fire_event
 from dbt.ui import warning_tag
 
 from dbt.contracts.project import Configuration, UserConfig
 from dbt.exceptions import (
     RuntimeException,
-    DbtProfileError,
     DbtProjectError,
     validator_error_message,
     warn_or_error,
@@ -191,6 +188,7 @@ class RuntimeConfig(Project, Profile, AdapterRequiredConfig):
         profile_renderer: ProfileRenderer,
         profile_name: Optional[str],
     ) -> Profile:
+
         return Profile.render_from_args(
             args, profile_renderer, profile_name
         )
@@ -412,21 +410,12 @@ class UnsetCredentials(Credentials):
         return ()
 
 
-class UnsetConfig(UserConfig):
-    def __getattribute__(self, name):
-        if name in {f.name for f in fields(UserConfig)}:
-            raise AttributeError(
-                f"'UnsetConfig' object has no attribute {name}"
-            )
-
-    def __post_serialize__(self, dct):
-        return {}
-
-
+# This is used by UnsetProfileConfig, for commands which do
+# not require a profile, i.e. dbt deps and clean
 class UnsetProfile(Profile):
     def __init__(self):
         self.credentials = UnsetCredentials()
-        self.user_config = UnsetConfig()
+        self.user_config = UserConfig()  # This will be read in _get_rendered_profile
         self.profile_name = ''
         self.target_name = ''
         self.threads = -1
@@ -443,6 +432,8 @@ class UnsetProfile(Profile):
         return Profile.__getattribute__(self, name)
 
 
+# This class is used by the dbt deps and clean commands, because they don't
+# require a functioning profile.
 @dataclass
 class UnsetProfileConfig(RuntimeConfig):
     """This class acts a lot _like_ a RuntimeConfig, except if your profile is
@@ -525,7 +516,7 @@ class UnsetProfileConfig(RuntimeConfig):
             profile_env_vars=profile.profile_env_vars,
             profile_name='',
             target_name='',
-            user_config=UnsetConfig(),
+            user_config=UserConfig(),
             threads=getattr(args, 'threads', 1),
             credentials=UnsetCredentials(),
             args=args,
@@ -540,17 +531,12 @@ class UnsetProfileConfig(RuntimeConfig):
         profile_renderer: ProfileRenderer,
         profile_name: Optional[str],
     ) -> Profile:
-        try:
-            profile = Profile.render_from_args(
-                args, profile_renderer, profile_name
-            )
-        except (DbtProjectError, DbtProfileError) as exc:
-            fire_event(ProfileLoadError(exc=exc))
-            fire_event(ProfileNotFound(profile_name=profile_name))
-            # return the poisoned form
-            profile = UnsetProfile()
-            # disable anonymous usage statistics
-            tracking.disable_tracking()
+
+        profile = UnsetProfile()
+        # The profile (for warehouse connection) is not needed, but we want
+        # to get the UserConfig, which is also in profiles.yml
+        user_config = read_user_config(flags.PROFILES_DIR)
+        profile.user_config = user_config
         return profile
 
     @classmethod
@@ -565,9 +551,6 @@ class UnsetProfileConfig(RuntimeConfig):
         :raises ValidationException: If the cli variables are invalid.
         """
         project, profile = cls.collect_parts(args)
-        if not isinstance(profile, UnsetProfile):
-            # if it's a real profile, return a real config
-            cls = RuntimeConfig
 
         return cls.from_parts(
             project=project,

core/dbt/context/providers.py

@@ -1186,10 +1186,12 @@ class ProviderContext(ManifestContext):
             # If this is compiling, do not save because it's irrelevant to parsing.
             if self.model and not hasattr(self.model, 'compiled'):
                 self.manifest.env_vars[var] = return_value
-                source_file = self.manifest.files[self.model.file_id]
-                # Schema files should never get here
-                if source_file.parse_file_type != 'schema':
-                    source_file.env_vars.append(var)
+                # hooks come from dbt_project.yml which doesn't have a real file_id
+                if self.model.file_id in self.manifest.files:
+                    source_file = self.manifest.files[self.model.file_id]
+                    # Schema files should never get here
+                    if source_file.parse_file_type != 'schema':
+                        source_file.env_vars.append(var)
             return return_value
         else:
             msg = f"Env var required but not provided: '{var}'"

core/dbt/context/secret.py

@@ -4,6 +4,7 @@ from typing import Any, Dict, Optional
 from .base import BaseContext, contextmember
 
 from dbt.exceptions import raise_parsing_error
+from dbt.logger import SECRET_ENV_PREFIX
 
 
 class SecretContext(BaseContext):
@@ -27,7 +28,11 @@ class SecretContext(BaseContext):
             return_value = default
 
         if return_value is not None:
-            self.env_vars[var] = return_value
+            # do not save secret environment variables
+            if not var.startswith(SECRET_ENV_PREFIX):
+                self.env_vars[var] = return_value
+
+            # return the value even if its a secret
             return return_value
         else:
             msg = f"Env var required but not provided: '{var}'"

core/dbt/contracts/graph/parsed.py

@@ -431,6 +431,10 @@ class ParsedSingularTestNode(ParsedNode):
     # refactor the various configs.
     config: TestConfig = field(default_factory=TestConfig)  # type: ignore
 
+    @property
+    def test_node_type(self):
+        return 'singular'
+
 
 @dataclass
 class ParsedGenericTestNode(ParsedNode, HasTestMetadata):
@@ -452,6 +456,10 @@ class ParsedGenericTestNode(ParsedNode, HasTestMetadata):
             True
         )
 
+    @property
+    def test_node_type(self):
+        return 'generic'
+
 
 @dataclass
 class IntermediateSnapshotNode(ParsedNode):

core/dbt/contracts/project.py

@@ -231,7 +231,7 @@ class UserConfig(ExtensibleDbtClassMixin, Replaceable, UserConfigContract):
     printer_width: Optional[int] = None
     write_json: Optional[bool] = None
     warn_error: Optional[bool] = None
-    log_format: Optional[bool] = None
+    log_format: Optional[str] = None
     debug: Optional[bool] = None
     version_check: Optional[bool] = None
     fail_fast: Optional[bool] = None

core/dbt/contracts/state.py

@@ -14,7 +14,8 @@ class PreviousState:
         manifest_path = self.path / 'manifest.json'
         if manifest_path.exists() and manifest_path.is_file():
             try:
-                self.manifest = WritableManifest.read(str(manifest_path))
+                # we want to bail with an error if schema versions don't match
+                self.manifest = WritableManifest.read_and_check_versions(str(manifest_path))
             except IncompatibleSchemaException as exc:
                 exc.add_filename(str(manifest_path))
                 raise
@@ -22,7 +23,8 @@ class PreviousState:
         results_path = self.path / 'run_results.json'
         if results_path.exists() and results_path.is_file():
             try:
-                self.results = RunResultsArtifact.read(str(results_path))
+                # we want to bail with an error if schema versions don't match
+                self.results = RunResultsArtifact.read_and_check_versions(str(results_path))
             except IncompatibleSchemaException as exc:
                 exc.add_filename(str(results_path))
                 raise

core/dbt/contracts/util.py

@@ -9,6 +9,7 @@ from dbt.clients.system import write_json, read_json
 from dbt.exceptions import (
     InternalException,
     RuntimeException,
+    IncompatibleSchemaException
 )
 from dbt.version import __version__
 from dbt.events.functions import get_invocation_id
@@ -158,6 +159,8 @@ def get_metadata_env() -> Dict[str, str]:
     }
 
 
+# This is used in the ManifestMetadata, RunResultsMetadata, RunOperationResultMetadata,
+# FreshnessMetadata, and CatalogMetadata classes
 @dataclasses.dataclass
 class BaseArtifactMetadata(dbtClassMixin):
     dbt_schema_version: str
@@ -177,6 +180,17 @@ class BaseArtifactMetadata(dbtClassMixin):
         return dct
 
 
+# This is used as a class decorator to set the schema_version in the
+# 'dbt_schema_version' class attribute. (It's copied into the metadata objects.)
+# Name attributes of SchemaVersion in classes with the 'schema_version' decorator:
+#   manifest
+#   run-results
+#   run-operation-result
+#   sources
+#   catalog
+#   remote-compile-result
+#   remote-execution-result
+#   remote-run-result
 def schema_version(name: str, version: int):
     def inner(cls: Type[VersionedSchema]):
         cls.dbt_schema_version = SchemaVersion(
@@ -187,6 +201,7 @@ def schema_version(name: str, version: int):
     return inner
 
 
+# This is used in the ArtifactMixin and RemoteResult classes
 @dataclasses.dataclass
 class VersionedSchema(dbtClassMixin):
     dbt_schema_version: ClassVar[SchemaVersion]
@@ -198,6 +213,30 @@ class VersionedSchema(dbtClassMixin):
             result['$id'] = str(cls.dbt_schema_version)
         return result
 
+    @classmethod
+    def read_and_check_versions(cls, path: str):
+        try:
+            data = read_json(path)
+        except (EnvironmentError, ValueError) as exc:
+            raise RuntimeException(
+                f'Could not read {cls.__name__} at "{path}" as JSON: {exc}'
+            ) from exc
+
+        # Check metadata version. There is a class variable 'dbt_schema_version', but
+        # that doesn't show up in artifacts, where it only exists in the 'metadata'
+        # dictionary.
+        if hasattr(cls, 'dbt_schema_version'):
+            if 'metadata' in data and 'dbt_schema_version' in data['metadata']:
+                previous_schema_version = data['metadata']['dbt_schema_version']
+                # cls.dbt_schema_version is a SchemaVersion object
+                if str(cls.dbt_schema_version) != previous_schema_version:
+                    raise IncompatibleSchemaException(
+                        expected=str(cls.dbt_schema_version),
+                        found=previous_schema_version
+                    )
+
+        return cls.from_dict(data)  # type: ignore
+
 
 T = TypeVar('T', bound='ArtifactMixin')
 
@@ -205,6 +244,8 @@ T = TypeVar('T', bound='ArtifactMixin')
 # metadata should really be a Generic[T_M] where T_M is a TypeVar bound to
 # BaseArtifactMetadata. Unfortunately this isn't possible due to a mypy issue:
 # https://github.com/python/mypy/issues/7520
+# This is used in the WritableManifest, RunResultsArtifact, RunOperationResultsArtifact,
+# and CatalogArtifact
 @dataclasses.dataclass(init=False)
 class ArtifactMixin(VersionedSchema, Writable, Readable):
     metadata: BaseArtifactMetadata

core/dbt/deprecations.py

@@ -36,9 +36,9 @@ class DBTDeprecation:
         if self.name not in active_deprecations:
             desc = self.description.format(**kwargs)
             msg = ui.line_wrap_message(
-                desc, prefix='* Deprecation Warning:\n\n'
+                desc, prefix='Deprecated functionality\n\n'
             )
-            dbt.exceptions.warn_or_error(msg)
+            dbt.exceptions.warn_or_error(msg, log_fmt=ui.warning_tag('{}'))
             self.track_deprecation_warn()
             active_deprecations.add(self.name)
 
@@ -62,7 +62,7 @@ class PackageInstallPathDeprecation(DBTDeprecation):
 
 class ConfigPathDeprecation(DBTDeprecation):
     _description = '''\
-    The `{deprecated_path}` config has been deprecated in favor of `{exp_path}`.
+    The `{deprecated_path}` config has been renamed to `{exp_path}`.
     Please update your `dbt_project.yml` configuration to reflect this change.
     '''
 

core/dbt/deps/registry.py

@@ -1,4 +1,5 @@
 import os
+import functools
 from typing import List
 
 from dbt import semver
@@ -14,6 +15,7 @@ from dbt.exceptions import (
     DependencyException,
     package_not_found,
 )
+from dbt.utils import _connection_exception_retry as connection_exception_retry
 
 
 class RegistryPackageMixin:
@@ -68,9 +70,28 @@ class RegistryPinnedPackage(RegistryPackageMixin, PinnedPackage):
         system.make_directory(os.path.dirname(tar_path))
 
         download_url = metadata.downloads.tarball
-        system.download_with_retries(download_url, tar_path)
         deps_path = project.packages_install_path
         package_name = self.get_project_name(project, renderer)
+
+        download_untar_fn = functools.partial(
+            self.download_and_untar,
+            download_url,
+            tar_path,
+            deps_path,
+            package_name
+        )
+        connection_exception_retry(download_untar_fn, 5)
+
+    def download_and_untar(self, download_url, tar_path, deps_path, package_name):
+        """
+        Sometimes the download of the files fails and we want to retry.  Sometimes the
+        download appears successful but the file did not make it through as expected
+        (generally due to a github incident).  Either way we want to retry downloading
+        and untarring to see if we can get a success.  Call this within
+        `_connection_exception_retry`
+        """
+
+        system.download(download_url, tar_path)
         system.untar_package(tar_path, deps_path, package_name)
 
 

core/dbt/events/README.md

@@ -6,7 +6,53 @@ The Events module is the implmentation for structured logging. These events repr
 The event module provides types that represent what is happening in dbt in `events.types`. These types are intended to represent an exhaustive list of all things happening within dbt that will need to be logged, streamed, or printed. To fire an event, `events.functions::fire_event` is the entry point to the module from everywhere in dbt.
 
 # Adding a New Event
-In `events.types` add a new class that represents the new event. This may be a simple class with no values, or it may be a dataclass with some values to construct downstream messaging. Only include the data necessary to construct this message within this class. You must extend all destinations (e.g. - if your log message belongs on the cli, extend `CliEventABC`) as well as the loglevel this event belongs to.
+In `events.types` add a new class that represents the new event. All events must be a dataclass with, at minimum, a code.  You may also include some other values to construct downstream messaging. Only include the data necessary to construct this message within this class. You must extend all destinations (e.g. - if your log message belongs on the cli, extend `Cli`) as well as the loglevel this event belongs to.  This system has been designed to take full advantage of mypy so running it will catch anything you may miss.
+
+## Required for Every Event
+
+- a string attribute `code`, that's unique across events
+- assign a log level by extending `DebugLevel`, `InfoLevel`, `WarnLevel`, or `ErrorLevel`
+- a message()
+- extend `File` and/or `Cli` based on where it should output
+
+Example
+```
+@dataclass
+class PartialParsingDeletedExposure(DebugLevel, Cli, File):
+    unique_id: str
+    code: str = "I049"
+
+    def message(self) -> str:
+        return f"Partial parsing: deleted exposure {self.unique_id}"
+
+```
+
+## Optional (based on your event)
+
+- Events associated with node status changes must have `report_node_data` passed in and be extended with `NodeInfo`
+- define `asdict` if your data is not serializable to json
+
+Example
+```
+@dataclass
+class SuperImportantNodeEvent(InfoLevel, File, NodeInfo):
+    node_name: str
+    run_result: RunResult
+    report_node_data: ParsedModelNode  # may vary
+    code: str = "Q036"
+
+    def message(self) -> str:
+        return f"{self.node_name} had overly verbose result of {run_result}"
+
+    @classmethod
+    def asdict(cls, data: list) -> dict:
+        return dict((k, str(v)) for k, v in data)
+
+```
+
+All values other than `code` and `report_node_data` will be included in the `data` node of the json log output.
+
+Once your event has been added, add a dummy call to your new event at the bottom of `types.py` and also add your new Event to the list `sample_values` in `test/unit/test_events.py'.
 
 # Adapter Maintainers
 To integrate existing log messages from adapters, you likely have a line of code like this in your adapter already:

core/dbt/events/base_types.py

@@ -1,7 +1,6 @@
 from abc import ABCMeta, abstractmethod, abstractproperty
 from dataclasses import dataclass
 from datetime import datetime
-import json
 import os
 import threading
 from typing import Any, Optional
@@ -38,6 +37,11 @@ class ErrorLevel():
         return "error"
 
 
+class Cache():
+    # Events with this class will only be logged when the `--log-cache-events` flag is passed
+    pass
+
+
 @dataclass
 class Node():
     node_path: str
@@ -70,6 +74,7 @@ class Event(metaclass=ABCMeta):
     # fields that should be on all events with their default implementations
     log_version: int = 1
     ts: Optional[datetime] = None  # use getter for non-optional
+    ts_rfc3339: Optional[str] = None  # use getter for non-optional
     pid: Optional[int] = None  # use getter for non-optional
     node_info: Optional[Node]
 
@@ -91,32 +96,20 @@ class Event(metaclass=ABCMeta):
     def message(self) -> str:
         raise Exception("msg not implemented for Event")
 
-    # override this method to convert non-json serializable fields to json.
-    # for override examples, see existing concrete types.
-    #
-    # there is no type-level mechanism to have mypy enforce json serializability, so we just try
-    # to serialize and raise an exception at runtime when that fails. This safety mechanism
-    # only works if we have attempted to serialize every concrete event type in our tests.
-    def fields_to_json(self, field_value: Any) -> Any:
-        try:
-            json.dumps(field_value, sort_keys=True)
-            return field_value
-        except TypeError:
-            val_type = type(field_value).__name__
-            event_type = type(self).__name__
-            return Exception(
-                f"type {val_type} is not serializable to json."
-                f" First make sure that the call sites for {event_type} match the type hints"
-                f" and if they do, you can override Event::fields_to_json in {event_type} in"
-                " types.py to define your own serialization function to any valid json type"
-            )
-
     # exactly one time stamp per concrete event
     def get_ts(self) -> datetime:
         if not self.ts:
-            self.ts = datetime.now()
+            self.ts = datetime.utcnow()
+            self.ts_rfc3339 = self.ts.strftime('%Y-%m-%dT%H:%M:%S.%fZ')
         return self.ts
 
+    # preformatted time stamp
+    def get_ts_rfc3339(self) -> str:
+        if not self.ts_rfc3339:
+            # get_ts() creates the formatted string too so all time logic is centralized
+            self.get_ts()
+        return self.ts_rfc3339  # type: ignore
+
     # exactly one pid per concrete event
     def get_pid(self) -> int:
         if not self.pid:
@@ -132,6 +125,21 @@ class Event(metaclass=ABCMeta):
         from dbt.events.functions import get_invocation_id
         return get_invocation_id()
 
+    # default dict factory for all events. can override on concrete classes.
+    @classmethod
+    def asdict(cls, data: list) -> dict:
+        d = dict()
+        for k, v in data:
+            # stringify all exceptions
+            if isinstance(v, Exception) or isinstance(v, BaseException):
+                d[k] = str(v)
+            # skip all binary data
+            elif isinstance(v, bytes):
+                continue
+            else:
+                d[k] = v
+        return d
+
 
 @dataclass  # type: ignore
 class NodeInfo(Event, metaclass=ABCMeta):
@@ -143,7 +151,7 @@ class NodeInfo(Event, metaclass=ABCMeta):
             node_name=self.report_node_data.name,
             unique_id=self.report_node_data.unique_id,
             resource_type=self.report_node_data.resource_type.value,
-            materialized=self.report_node_data.config.materialized,
+            materialized=self.report_node_data.config.get('materialized'),
             node_status=str(self.report_node_data._event_status.get('node_status')),
             node_started_at=self.report_node_data._event_status.get("started_at"),
             node_finished_at=self.report_node_data._event_status.get("finished_at")

core/dbt/events/functions.py

@@ -2,8 +2,8 @@
 from colorama import Style
 from datetime import datetime
 import dbt.events.functions as this  # don't worry I hate it too.
-from dbt.events.base_types import Cli, Event, File, ShowException, NodeInfo
-from dbt.events.types import EventBufferFull, T_Event
+from dbt.events.base_types import Cli, Event, File, ShowException, NodeInfo, Cache
+from dbt.events.types import EventBufferFull, T_Event, MainReportVersion, EmptyLine
 import dbt.flags as flags
 # TODO this will need to move eventually
 from dbt.logger import SECRET_ENV_PREFIX, make_log_dir_if_missing, GLOBAL_LOGGER
@@ -13,19 +13,21 @@ from io import StringIO, TextIOWrapper
 import logbook
 import logging
 from logging import Logger
+import sys
 from logging.handlers import RotatingFileHandler
 import os
 import uuid
+import threading
 from typing import Any, Callable, Dict, List, Optional, Union
 import dataclasses
 from collections import deque
 
 
-# create the global event history buffer with a max size of 100k records
+# create the global event history buffer with the default max size (10k)
 # python 3.7 doesn't support type hints on globals, but mypy requires them. hence the ignore.
-# TODO: make the maxlen something configurable from the command line via args(?)
+# TODO the flags module has not yet been resolved when this is created
 global EVENT_HISTORY
-EVENT_HISTORY = deque(maxlen=100000)  # type: ignore
+EVENT_HISTORY = deque(maxlen=flags.EVENT_BUFFER_SIZE)  # type: ignore
 
 # create the global file logger with no configuration
 global FILE_LOG
@@ -38,7 +40,7 @@ FILE_LOG.addHandler(null_handler)
 global STDOUT_LOG
 STDOUT_LOG = logging.getLogger('default_stdout')
 STDOUT_LOG.setLevel(logging.INFO)
-stdout_handler = logging.StreamHandler()
+stdout_handler = logging.StreamHandler(sys.stdout)
 stdout_handler.setLevel(logging.INFO)
 STDOUT_LOG.addHandler(stdout_handler)
 
@@ -48,6 +50,10 @@ invocation_id: Optional[str] = None
 
 
 def setup_event_logger(log_path, level_override=None):
+    # flags have been resolved, and log_path is known
+    global EVENT_HISTORY
+    EVENT_HISTORY = deque(maxlen=flags.EVENT_BUFFER_SIZE)  # type: ignore
+
     make_log_dir_if_missing(log_path)
     this.format_json = flags.LOG_FORMAT == 'json'
     # USE_COLORS can be None if the app just started and the cli flags
@@ -64,7 +70,7 @@ def setup_event_logger(log_path, level_override=None):
     FORMAT = "%(message)s"
     stdout_passthrough_formatter = logging.Formatter(fmt=FORMAT)
 
-    stdout_handler = logging.StreamHandler()
+    stdout_handler = logging.StreamHandler(sys.stdout)
     stdout_handler.setFormatter(stdout_passthrough_formatter)
     stdout_handler.setLevel(level)
     # clear existing stdout TextIOWrapper stream handlers
@@ -80,7 +86,12 @@ def setup_event_logger(log_path, level_override=None):
 
     file_passthrough_formatter = logging.Formatter(fmt=FORMAT)
 
-    file_handler = RotatingFileHandler(filename=log_dest, encoding='utf8')
+    file_handler = RotatingFileHandler(
+        filename=log_dest,
+        encoding='utf8',
+        maxBytes=10 * 1024 * 1024,  # 10 mb
+        backupCount=5
+    )
     file_handler.setFormatter(file_passthrough_formatter)
     file_handler.setLevel(logging.DEBUG)  # always debug regardless of user input
     this.FILE_LOG.handlers.clear()
@@ -130,17 +141,25 @@ def event_to_serializable_dict(
 ) -> Dict[str, Any]:
     data = dict()
     node_info = dict()
-    if hasattr(e, '__dataclass_fields__'):
-        for field, value in dataclasses.asdict(e).items():  # type: ignore[attr-defined]
-            _json_value = e.fields_to_json(value)
+    log_line = dict()
+    try:
+        log_line = dataclasses.asdict(e, dict_factory=type(e).asdict)
+    except AttributeError:
+        event_type = type(e).__name__
+        raise Exception(  # TODO this may hang async threads
+            f"type {event_type} is not serializable to json."
+            f" First make sure that the call sites for {event_type} match the type hints"
+            f" and if they do, you can override the dataclass method `asdict` in {event_type} in"
+            " types.py to define your own serialization function to a dictionary of valid json"
+            " types"
+        )
 
-            if isinstance(e, NodeInfo):
-                node_info = dataclasses.asdict(e.get_node_info())
+    if isinstance(e, NodeInfo):
+        node_info = dataclasses.asdict(e.get_node_info())
 
-            if not isinstance(_json_value, Exception):
-                data[field] = _json_value
-            else:
-                data[field] = f"JSON_SERIALIZE_FAILED: {type(value).__name__, 'NA'}"
+    for field, value in log_line.items():  # type: ignore[attr-defined]
+        if field not in ["code", "report_node_data"]:
+            data[field] = value
 
     event_dict = {
         'type': 'log_line',
@@ -152,7 +171,8 @@ def event_to_serializable_dict(
         'data': data,
         'invocation_id': e.get_invocation_id(),
         'thread_name': e.get_thread_name(),
-        'node_info': node_info
+        'node_info': node_info,
+        'code': e.code
     }
 
     return event_dict
@@ -161,35 +181,64 @@ def event_to_serializable_dict(
 # translates an Event to a completely formatted text-based log line
 # you have to specify which message you want. (i.e. - e.message, e.cli_msg(), e.file_msg())
 # type hinting everything as strings so we don't get any unintentional string conversions via str()
-def create_text_log_line(e: T_Event, msg_fn: Callable[[T_Event], str]) -> str:
+def create_info_text_log_line(e: T_Event, msg_fn: Callable[[T_Event], str]) -> str:
     color_tag: str = '' if this.format_color else Style.RESET_ALL
     ts: str = e.get_ts().strftime("%H:%M:%S")
     scrubbed_msg: str = scrub_secrets(msg_fn(e), env_secrets())
+    log_line: str = f"{color_tag}{ts}  {scrubbed_msg}"
+    return log_line
+
+
+def create_debug_text_log_line(e: T_Event, msg_fn: Callable[[T_Event], str]) -> str:
+    log_line: str = ''
+    # Create a separator if this is the beginning of an invocation
+    if type(e) == MainReportVersion:
+        separator = 30 * '='
+        log_line = f'\n\n{separator} {e.get_ts()} | {get_invocation_id()} {separator}\n'
+    color_tag: str = '' if this.format_color else Style.RESET_ALL
+    ts: str = e.get_ts().strftime("%H:%M:%S.%f")
+    scrubbed_msg: str = scrub_secrets(msg_fn(e), env_secrets())
     level: str = e.level_tag() if len(e.level_tag()) == 5 else f"{e.level_tag()} "
-    log_line: str = f"{color_tag}{ts} | [ {level} ] | {scrubbed_msg}"
+    thread = ''
+    if threading.current_thread().getName():
+        thread_name = threading.current_thread().getName()
+        thread_name = thread_name[:10]
+        thread_name = thread_name.ljust(10, ' ')
+        thread = f' [{thread_name}]:'
+    log_line = log_line + f"{color_tag}{ts} [{level}]{thread} {scrubbed_msg}"
     return log_line
 
 
 # translates an Event to a completely formatted json log line
 # you have to specify which message you want. (i.e. - e.message(), e.cli_msg(), e.file_msg())
-def create_json_log_line(e: T_Event, msg_fn: Callable[[T_Event], str]) -> str:
-    values = event_to_serializable_dict(e, lambda dt: dt.isoformat(), lambda x: msg_fn(x))
+def create_json_log_line(e: T_Event, msg_fn: Callable[[T_Event], str]) -> Optional[str]:
+    if type(e) == EmptyLine:
+        return None  # will not be sent to logger
+    # using preformatted string instead of formatting it here to be extra careful about timezone
+    values = event_to_serializable_dict(e, lambda _: e.get_ts_rfc3339(), lambda x: msg_fn(x))
     raw_log_line = json.dumps(values, sort_keys=True)
     return scrub_secrets(raw_log_line, env_secrets())
 
 
-# calls create_text_log_line() or create_json_log_line() according to logger config
-def create_log_line(e: T_Event, msg_fn: Callable[[T_Event], str]) -> str:
-    return (
-        create_json_log_line(e, msg_fn)
-        if this.format_json else
-        create_text_log_line(e, msg_fn)
-    )
+# calls create_stdout_text_log_line() or create_json_log_line() according to logger config
+def create_log_line(
+    e: T_Event,
+    msg_fn: Callable[[T_Event], str],
+    file_output=False
+) -> Optional[str]:
+    if this.format_json:
+        return create_json_log_line(e, msg_fn)  # json output, both console and file
+    elif file_output is True or flags.DEBUG:
+        return create_debug_text_log_line(e, msg_fn)  # default file output
+    else:
+        return create_info_text_log_line(e, msg_fn)  # console output
 
 
 # allows for resuse of this obnoxious if else tree.
 # do not use for exceptions, it doesn't pass along exc_info, stack_info, or extra
 def send_to_logger(l: Union[Logger, logbook.Logger], level_tag: str, log_line: str):
+    if not log_line:
+        return
     if level_tag == 'test':
         # TODO after implmenting #3977 send to new test level
         l.debug(log_line)
@@ -257,33 +306,46 @@ def send_exc_to_logger(
         )
 
 
+# an alternative to fire_event which only creates and logs the event value
+# if the condition is met. Does nothing otherwise.
+def fire_event_if(conditional: bool, lazy_e: Callable[[], Event]) -> None:
+    if conditional:
+        fire_event(lazy_e())
+
+
 # top-level method for accessing the new eventing system
 # this is where all the side effects happen branched by event type
 # (i.e. - mutating the event history, printing to stdout, logging
 # to files, etc.)
 def fire_event(e: Event) -> None:
+    # skip logs when `--log-cache-events` is not passed
+    if isinstance(e, Cache) and not flags.LOG_CACHE_EVENTS:
+        return
+
     # if and only if the event history deque will be completely filled by this event
     # fire warning that old events are now being dropped
     global EVENT_HISTORY
-    if len(EVENT_HISTORY) == ((EVENT_HISTORY.maxlen or 100000) - 1):
+    if len(EVENT_HISTORY) == (flags.EVENT_BUFFER_SIZE - 1):
+        EVENT_HISTORY.append(e)
         fire_event(EventBufferFull())
-
-    EVENT_HISTORY.append(e)
+    else:
+        EVENT_HISTORY.append(e)
 
     # backwards compatibility for plugins that require old logger (dbt-rpc)
     if flags.ENABLE_LEGACY_LOGGER:
         # using Event::message because the legacy logger didn't differentiate messages by
         # destination
         log_line = create_log_line(e, msg_fn=lambda x: x.message())
-
-        send_to_logger(GLOBAL_LOGGER, e.level_tag(), log_line)
+        if log_line:
+            send_to_logger(GLOBAL_LOGGER, e.level_tag(), log_line)
         return  # exit the function to avoid using the current logger as well
 
     # always logs debug level regardless of user input
     if isinstance(e, File):
-        log_line = create_log_line(e, msg_fn=lambda x: x.file_msg())
+        log_line = create_log_line(e, msg_fn=lambda x: x.file_msg(), file_output=True)
         # doesn't send exceptions to exception logger
-        send_to_logger(FILE_LOG, level_tag=e.level_tag(), log_line=log_line)
+        if log_line:
+            send_to_logger(FILE_LOG, level_tag=e.level_tag(), log_line=log_line)
 
     if isinstance(e, Cli):
         # explicitly checking the debug flag here so that potentially expensive-to-construct
@@ -292,18 +354,19 @@ def fire_event(e: Event) -> None:
             return  # eat the message in case it was one of the expensive ones
 
         log_line = create_log_line(e, msg_fn=lambda x: x.cli_msg())
-        if not isinstance(e, ShowException):
-            send_to_logger(STDOUT_LOG, level_tag=e.level_tag(), log_line=log_line)
-        # CliEventABC and ShowException
-        else:
-            send_exc_to_logger(
-                STDOUT_LOG,
-                level_tag=e.level_tag(),
-                log_line=log_line,
-                exc_info=e.exc_info,
-                stack_info=e.stack_info,
-                extra=e.extra
-            )
+        if log_line:
+            if not isinstance(e, ShowException):
+                send_to_logger(STDOUT_LOG, level_tag=e.level_tag(), log_line=log_line)
+            # CliEventABC and ShowException
+            else:
+                send_exc_to_logger(
+                    STDOUT_LOG,
+                    level_tag=e.level_tag(),
+                    log_line=log_line,
+                    exc_info=e.exc_info,
+                    stack_info=e.stack_info,
+                    extra=e.extra
+                )
 
 
 def get_invocation_id() -> str:

core/dbt/events/types.py

@@ -1,16 +1,16 @@
 import argparse
 from dataclasses import dataclass
+from dbt.adapters.reference_keys import _make_key, _ReferenceKey
 from dbt.events.stubs import (
     _CachedRelation,
     BaseRelation,
-    ParsedModelNode,
     ParsedHookNode,
-    _ReferenceKey,
+    ParsedModelNode,
     RunResult
 )
 from dbt import ui
 from dbt.events.base_types import (
-    Cli, Event, File, DebugLevel, InfoLevel, WarnLevel, ErrorLevel, ShowException, NodeInfo
+    Cli, Event, File, DebugLevel, InfoLevel, WarnLevel, ErrorLevel, ShowException, NodeInfo, Cache
 )
 from dbt.events.format import format_fancy_output_line, pluralize
 from dbt.node_types import NodeType
@@ -115,14 +115,6 @@ class MainEncounteredError(ErrorLevel, Cli):
     def message(self) -> str:
         return f"Encountered an error:\n{str(self.e)}"
 
-    # overriding default json serialization for this event
-    def fields_to_json(self, val: Any) -> Any:
-        # equality on BaseException is not good enough of a comparison here
-        if isinstance(val, BaseException):
-            return str(val)
-
-        return val
-
 
 @dataclass
 class MainStackTrace(DebugLevel, Cli):
@@ -150,12 +142,9 @@ class MainReportArgs(DebugLevel, Cli, File):
     def message(self):
         return f"running dbt with arguments {str(self.args)}"
 
-    # overriding default json serialization for this event
-    def fields_to_json(self, val: Any) -> Any:
-        if isinstance(val, argparse.Namespace):
-            return str(val)
-
-        return val
+    @classmethod
+    def asdict(cls, data: list) -> dict:
+        return dict((k, str(v)) for k, v in data)
 
 
 @dataclass
@@ -354,13 +343,6 @@ class SystemCouldNotWrite(DebugLevel, Cli, File):
             f"{self.reason}\nexception: {self.exc}"
         )
 
-    # overriding default json serialization for this event
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 @dataclass
 class SystemExecutingCmd(DebugLevel, Cli, File):
@@ -397,40 +379,6 @@ class SystemReportReturnCode(DebugLevel, Cli, File):
     def message(self) -> str:
         return f"command return code={self.returncode}"
 
-# TODO remove?? Not called outside of this file
-
-
-@dataclass
-class SelectorAlertUpto3UnusedNodes(InfoLevel, Cli, File):
-    node_names: List[str]
-    code: str = "I_NEED_A_CODE_5"
-
-    def message(self) -> str:
-        summary_nodes_str = ("\n  - ").join(self.node_names[:3])
-        and_more_str = (
-            f"\n  - and {len(self.node_names) - 3} more" if len(self.node_names) > 4 else ""
-        )
-        return (
-            f"\nSome tests were excluded because at least one parent is not selected. "
-            f"Use the --greedy flag to include them."
-            f"\n  - {summary_nodes_str}{and_more_str}"
-        )
-
-# TODO remove?? Not called outside of this file
-
-
-@dataclass
-class SelectorAlertAllUnusedNodes(DebugLevel, Cli, File):
-    node_names: List[str]
-    code: str = "I_NEED_A_CODE_6"
-
-    def message(self) -> str:
-        debug_nodes_str = ("\n  - ").join(self.node_names)
-        return (
-            f"Full list of tests that were excluded:"
-            f"\n  - {debug_nodes_str}"
-        )
-
 
 @dataclass
 class SelectorReportInvalidSelector(InfoLevel, Cli, File):
@@ -542,7 +490,7 @@ class Rollback(DebugLevel, Cli, File):
 
 @dataclass
 class CacheMiss(DebugLevel, Cli, File):
-    conn_name: Any  # TODO mypy says this is `Callable[[], str]`??  ¯\_(ツ)_/¯
+    conn_name: str
     database: Optional[str]
     schema: str
     code: str = "E013"
@@ -558,12 +506,20 @@ class CacheMiss(DebugLevel, Cli, File):
 class ListRelations(DebugLevel, Cli, File):
     database: Optional[str]
     schema: str
-    relations: List[BaseRelation]
+    relations: List[_ReferenceKey]
     code: str = "E014"
 
     def message(self) -> str:
         return f"with database={self.database}, schema={self.schema}, relations={self.relations}"
 
+    @classmethod
+    def asdict(cls, data: list) -> dict:
+        d = dict()
+        for k, v in data:
+            if type(v) == list:
+                d[k] = [str(x) for x in v]
+        return d
+
 
 @dataclass
 class ConnectionUsed(DebugLevel, Cli, File):
@@ -587,7 +543,7 @@ class SQLQuery(DebugLevel, Cli, File):
 
 @dataclass
 class SQLQueryStatus(DebugLevel, Cli, File):
-    status: str  # could include AdapterResponse if we resolve circular imports
+    status: str
     elapsed: float
     code: str = "E017"
 
@@ -617,7 +573,7 @@ class ColTypeChange(DebugLevel, Cli, File):
 
 @dataclass
 class SchemaCreation(DebugLevel, Cli, File):
-    relation: BaseRelation
+    relation: _ReferenceKey
     code: str = "E020"
 
     def message(self) -> str:
@@ -626,17 +582,21 @@ class SchemaCreation(DebugLevel, Cli, File):
 
 @dataclass
 class SchemaDrop(DebugLevel, Cli, File):
-    relation: BaseRelation
+    relation: _ReferenceKey
     code: str = "E021"
 
     def message(self) -> str:
         return f'Dropping schema "{self.relation}".'
 
+    @classmethod
+    def asdict(cls, data: list) -> dict:
+        return dict((k, str(v)) for k, v in data)
+
 
 # TODO pretty sure this is only ever called in dead code
 # see: core/dbt/adapters/cache.py _add_link vs add_link
 @dataclass
-class UncachedRelation(DebugLevel, Cli, File):
+class UncachedRelation(DebugLevel, Cli, File, Cache):
     dep_key: _ReferenceKey
     ref_key: _ReferenceKey
     code: str = "E022"
@@ -650,7 +610,7 @@ class UncachedRelation(DebugLevel, Cli, File):
 
 
 @dataclass
-class AddLink(DebugLevel, Cli, File):
+class AddLink(DebugLevel, Cli, File, Cache):
     dep_key: _ReferenceKey
     ref_key: _ReferenceKey
     code: str = "E023"
@@ -660,23 +620,16 @@ class AddLink(DebugLevel, Cli, File):
 
 
 @dataclass
-class AddRelation(DebugLevel, Cli, File):
-    relation: _CachedRelation
+class AddRelation(DebugLevel, Cli, File, Cache):
+    relation: _ReferenceKey
     code: str = "E024"
 
     def message(self) -> str:
         return f"Adding relation: {str(self.relation)}"
 
-    # overriding default json serialization for this event
-    def fields_to_json(self, val: Any) -> Any:
-        if isinstance(val, _CachedRelation):
-            return str(val)
-
-        return val
-
 
 @dataclass
-class DropMissingRelation(DebugLevel, Cli, File):
+class DropMissingRelation(DebugLevel, Cli, File, Cache):
     relation: _ReferenceKey
     code: str = "E025"
 
@@ -685,7 +638,7 @@ class DropMissingRelation(DebugLevel, Cli, File):
 
 
 @dataclass
-class DropCascade(DebugLevel, Cli, File):
+class DropCascade(DebugLevel, Cli, File, Cache):
     dropped: _ReferenceKey
     consequences: Set[_ReferenceKey]
     code: str = "E026"
@@ -693,9 +646,19 @@ class DropCascade(DebugLevel, Cli, File):
     def message(self) -> str:
         return f"drop {self.dropped} is cascading to {self.consequences}"
 
+    @classmethod
+    def asdict(cls, data: list) -> dict:
+        d = dict()
+        for k, v in data:
+            if isinstance(v, list):
+                d[k] = [str(x) for x in v]
+            else:
+                d[k] = str(v)  # type: ignore
+        return d
+
 
 @dataclass
-class DropRelation(DebugLevel, Cli, File):
+class DropRelation(DebugLevel, Cli, File, Cache):
     dropped: _ReferenceKey
     code: str = "E027"
 
@@ -704,7 +667,7 @@ class DropRelation(DebugLevel, Cli, File):
 
 
 @dataclass
-class UpdateReference(DebugLevel, Cli, File):
+class UpdateReference(DebugLevel, Cli, File, Cache):
     old_key: _ReferenceKey
     new_key: _ReferenceKey
     cached_key: _ReferenceKey
@@ -716,7 +679,7 @@ class UpdateReference(DebugLevel, Cli, File):
 
 
 @dataclass
-class TemporaryRelation(DebugLevel, Cli, File):
+class TemporaryRelation(DebugLevel, Cli, File, Cache):
     key: _ReferenceKey
     code: str = "E029"
 
@@ -725,7 +688,7 @@ class TemporaryRelation(DebugLevel, Cli, File):
 
 
 @dataclass
-class RenameSchema(DebugLevel, Cli, File):
+class RenameSchema(DebugLevel, Cli, File, Cache):
     old_key: _ReferenceKey
     new_key: _ReferenceKey
     code: str = "E030"
@@ -735,8 +698,8 @@ class RenameSchema(DebugLevel, Cli, File):
 
 
 @dataclass
-class DumpBeforeAddGraph(DebugLevel, Cli, File):
-    # large value. delay not necessary since every debug level message is logged anyway.
+class DumpBeforeAddGraph(DebugLevel, Cli, File, Cache):
+    # large value. delay creation with fire_event_if.
     dump: Dict[str, List[str]]
     code: str = "E031"
 
@@ -745,8 +708,8 @@ class DumpBeforeAddGraph(DebugLevel, Cli, File):
 
 
 @dataclass
-class DumpAfterAddGraph(DebugLevel, Cli, File):
-    # large value. delay not necessary since every debug level message is logged anyway.
+class DumpAfterAddGraph(DebugLevel, Cli, File, Cache):
+    # large value. delay creation with fire_event_if.
     dump: Dict[str, List[str]]
     code: str = "E032"
 
@@ -755,8 +718,8 @@ class DumpAfterAddGraph(DebugLevel, Cli, File):
 
 
 @dataclass
-class DumpBeforeRenameSchema(DebugLevel, Cli, File):
-    # large value. delay not necessary since every debug level message is logged anyway.
+class DumpBeforeRenameSchema(DebugLevel, Cli, File, Cache):
+    # large value. delay creation with fire_event_if.
     dump: Dict[str, List[str]]
     code: str = "E033"
 
@@ -765,8 +728,8 @@ class DumpBeforeRenameSchema(DebugLevel, Cli, File):
 
 
 @dataclass
-class DumpAfterRenameSchema(DebugLevel, Cli, File):
-    # large value. delay not necessary since every debug level message is logged anyway.
+class DumpAfterRenameSchema(DebugLevel, Cli, File, Cache):
+    # large value. delay creation with fire_event_if.
     dump: Dict[str, List[str]]
     code: str = "E034"
 
@@ -782,11 +745,9 @@ class AdapterImportError(InfoLevel, Cli, File):
     def message(self) -> str:
         return f"Error importing adapter: {self.exc}"
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val())
-
-        return val
+    @classmethod
+    def asdict(cls, data: list) -> dict:
+        return dict((k, str(v)) for k, v in data)
 
 
 @dataclass
@@ -834,114 +795,12 @@ class MissingProfileTarget(InfoLevel, Cli, File):
         return f"target not specified in profile '{self.profile_name}', using '{self.target_name}'"
 
 
-@dataclass
-class ProfileLoadError(ShowException, DebugLevel, Cli, File):
-    exc: Exception
-    code: str = "A006"
-
-    def message(self) -> str:
-        return f"Profile not loaded due to error: {self.exc}"
-
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
-
-@dataclass
-class ProfileNotFound(InfoLevel, Cli, File):
-    profile_name: Optional[str]
-    code: str = "A007"
-
-    def message(self) -> str:
-        return f'No profile "{self.profile_name}" found, continuing with no target'
-
-
 @dataclass
 class InvalidVarsYAML(ErrorLevel, Cli, File):
     code: str = "A008"
 
     def message(self) -> str:
-        return "The YAML provided in the --vars argument is not valid.\n"
-
-
-# TODO: Remove? (appears to be uncalled)
-@dataclass
-class CatchRunException(ShowException, DebugLevel, Cli, File):
-    build_path: Any
-    exc: Exception
-    code: str = "I_NEED_A_CODE_1"
-
-    def message(self) -> str:
-        INTERNAL_ERROR_STRING = """This is an error in dbt. Please try again. If the \
-                            error persists, open an issue at https://github.com/dbt-labs/dbt-core
-                            """.strip()
-        prefix = f'Internal error executing {self.build_path}'
-        error = "{prefix}\n{error}\n\n{note}".format(
-                prefix=ui.red(prefix),
-                error=str(self.exc).strip(),
-                note=INTERNAL_ERROR_STRING
-        )
-        return error
-
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
-
-# TODO: Remove? (appears to be uncalled)
-@dataclass
-class HandleInternalException(ShowException, DebugLevel, Cli, File):
-    exc: Exception
-    code: str = "I_NEED_A_CODE_2"
-
-    def message(self) -> str:
-        return str(self.exc)
-
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
-# TODO: Remove? (appears to be uncalled)
-
-
-@dataclass
-class MessageHandleGenericException(ErrorLevel, Cli, File):
-    build_path: str
-    unique_id: str
-    exc: Exception
-    code: str = "I_NEED_A_CODE_3"
-
-    def message(self) -> str:
-        node_description = self.build_path
-        if node_description is None:
-            node_description = self.unique_id
-        prefix = "Unhandled error while executing {}".format(node_description)
-        return "{prefix}\n{error}".format(
-            prefix=ui.red(prefix),
-            error=str(self.exc).strip()
-        )
-
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
-# TODO: Remove? (appears to be uncalled)
-
-
-@dataclass
-class DetailsHandleGenericException(ShowException, DebugLevel, Cli, File):
-    code: str = "I_NEED_A_CODE_4"
-
-    def message(self) -> str:
-        return ''
+        return "The YAML provided in the --vars argument is not valid."
 
 
 @dataclass
@@ -1110,12 +969,6 @@ class ParsedFileLoadFailed(ShowException, DebugLevel, Cli, File):
     def message(self) -> str:
         return f"Failed to load parsed file from disk at {self.path}: {self.exc}"
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 @dataclass
 class PartialParseSaveFileNotFound(InfoLevel, Cli, File):
@@ -1313,12 +1166,12 @@ class InvalidDisabledSourceInTestNode(WarnLevel, Cli, File):
 
 
 @dataclass
-class InvalidRefInTestNode(WarnLevel, Cli, File):
+class InvalidRefInTestNode(DebugLevel, Cli, File):
     msg: str
     code: str = "I051"
 
     def message(self) -> str:
-        return ui.warning_tag(self.msg)
+        return self.msg
 
 
 @dataclass
@@ -1329,12 +1182,6 @@ class RunningOperationCaughtError(ErrorLevel, Cli, File):
     def message(self) -> str:
         return f'Encountered an error while running operation: {self.exc}'
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 @dataclass
 class RunningOperationUncaughtError(ErrorLevel, Cli, File):
@@ -1344,12 +1191,6 @@ class RunningOperationUncaughtError(ErrorLevel, Cli, File):
     def message(self) -> str:
         return f'Encountered an error while running operation: {self.exc}'
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 @dataclass
 class DbtProjectError(ErrorLevel, Cli, File):
@@ -1367,12 +1208,6 @@ class DbtProjectErrorException(ErrorLevel, Cli, File):
     def message(self) -> str:
         return f"  ERROR: {str(self.exc)}"
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 @dataclass
 class DbtProfileError(ErrorLevel, Cli, File):
@@ -1390,12 +1225,6 @@ class DbtProfileErrorException(ErrorLevel, Cli, File):
     def message(self) -> str:
         return f"  ERROR: {str(self.exc)}"
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 @dataclass
 class ProfileListTitle(InfoLevel, Cli, File):
@@ -1443,12 +1272,6 @@ class CatchableExceptionOnRun(ShowException, DebugLevel, Cli, File):
     def message(self) -> str:
         return str(self.exc)
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 @dataclass
 class InternalExceptionOnRun(DebugLevel, Cli, File):
@@ -1469,12 +1292,6 @@ the error persists, open an issue at https://github.com/dbt-labs/dbt-core
             note=INTERNAL_ERROR_STRING
         )
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 # This prints the stack trace at the debug level while allowing just the nice exception message
 # at the error level - or whatever other level chosen.  Used in multiple places.
@@ -1488,9 +1305,9 @@ class PrintDebugStackTrace(ShowException, DebugLevel, Cli, File):
 
 @dataclass
 class GenericExceptionOnRun(ErrorLevel, Cli, File):
-    build_path: str
+    build_path: Optional[str]
     unique_id: str
-    exc: Exception
+    exc: str  # TODO: make this the actual exception once we have a better searilization strategy
     code: str = "W004"
 
     def message(self) -> str:
@@ -1503,12 +1320,6 @@ class GenericExceptionOnRun(ErrorLevel, Cli, File):
             error=str(self.exc).strip()
         )
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 @dataclass
 class NodeConnectionReleaseError(ShowException, DebugLevel, Cli, File):
@@ -1520,12 +1331,6 @@ class NodeConnectionReleaseError(ShowException, DebugLevel, Cli, File):
         return ('Error releasing connection for node {}: {!s}'
                 .format(self.node_name, self.exc))
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 @dataclass
 class CheckCleanPath(InfoLevel, Cli):
@@ -1591,11 +1396,11 @@ class DepsNoPackagesFound(InfoLevel, Cli, File):
 
 @dataclass
 class DepsStartPackageInstall(InfoLevel, Cli, File):
-    package: str
+    package_name: str
     code: str = "M014"
 
     def message(self) -> str:
-        return f"Installing {self.package}"
+        return f"Installing {self.package_name}"
 
 
 @dataclass
@@ -1639,7 +1444,7 @@ class DepsNotifyUpdatesAvailable(InfoLevel, Cli, File):
     code: str = "M019"
 
     def message(self) -> str:
-        return ('\nUpdates available for packages: {} \
+        return ('Updates available for packages: {} \
                 \nUpdate your versions in packages.yml, then run dbt deps'.format(self.packages))
 
 
@@ -1756,7 +1561,7 @@ class ServingDocsExitInfo(InfoLevel, Cli, File):
     code: str = "Z020"
 
     def message(self) -> str:
-        return "Press Ctrl+C to exit.\n\n"
+        return "Press Ctrl+C to exit."
 
 
 @dataclass
@@ -1807,7 +1612,7 @@ class StatsLine(InfoLevel, Cli, File):
     code: str = "Z023"
 
     def message(self) -> str:
-        stats_line = ("\nDone. PASS={pass} WARN={warn} ERROR={error} SKIP={skip} TOTAL={total}")
+        stats_line = ("Done. PASS={pass} WARN={warn} ERROR={error} SKIP={skip} TOTAL={total}")
         return stats_line.format(**self.stats)
 
 
@@ -1846,12 +1651,6 @@ class SQlRunnerException(ShowException, DebugLevel, Cli, File):
     def message(self) -> str:
         return f"Got an exception: {self.exc}"
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 @dataclass
 class CheckNodeTestFailure(InfoLevel, Cli, File):
@@ -1910,7 +1709,7 @@ class PrintStartLine(InfoLevel, Cli, File, NodeInfo):
     index: int
     total: int
     report_node_data: ParsedModelNode
-    code: str = "Z031"
+    code: str = "Q033"
 
     def message(self) -> str:
         msg = f"START {self.description}"
@@ -1928,8 +1727,8 @@ class PrintHookStartLine(InfoLevel, Cli, File, NodeInfo):
     index: int
     total: int
     truncate: bool
-    report_node_data: Any  # TODO use ParsedHookNode here
-    code: str = "Z032"
+    report_node_data: Any  # TODO: resolve ParsedHookNode circular import
+    code: str = "Q032"
 
     def message(self) -> str:
         msg = f"START hook: {self.statement}"
@@ -1948,7 +1747,7 @@ class PrintHookEndLine(InfoLevel, Cli, File, NodeInfo):
     total: int
     execution_time: int
     truncate: bool
-    report_node_data: Any  # TODO use ParsedHookNode here
+    report_node_data: Any  # TODO: resolve ParsedHookNode circular import
     code: str = "Q007"
 
     def message(self) -> str:
@@ -1969,7 +1768,7 @@ class SkippingDetails(InfoLevel, Cli, File, NodeInfo):
     index: int
     total: int
     report_node_data: ParsedModelNode
-    code: str = "Z033"
+    code: str = "Q034"
 
     def message(self) -> str:
         if self.resource_type in NodeType.refable():
@@ -2084,7 +1883,7 @@ class PrintModelErrorResultLine(ErrorLevel, Cli, File, NodeInfo):
     total: int
     execution_time: int
     report_node_data: ParsedModelNode
-    code: str = "Z035"
+    code: str = "Q035"
 
     def message(self) -> str:
         info = "ERROR creating"
@@ -2322,6 +2121,10 @@ class NodeFinished(DebugLevel, Cli, File, NodeInfo):
     def message(self) -> str:
         return f"Finished running node {self.unique_id}"
 
+    @classmethod
+    def asdict(cls, data: list) -> dict:
+        return dict((k, str(v)) for k, v in data)
+
 
 @dataclass
 class QueryCancelationUnsupported(InfoLevel, Cli, File):
@@ -2337,11 +2140,12 @@ class QueryCancelationUnsupported(InfoLevel, Cli, File):
 
 @dataclass
 class ConcurrencyLine(InfoLevel, Cli, File):
-    concurrency_line: str
+    num_threads: int
+    target_name: str
     code: str = "Q026"
 
     def message(self) -> str:
-        return self.concurrency_line
+        return f"Concurrency: {self.num_threads} threads (target='{self.target_name}')"
 
 
 @dataclass
@@ -2606,12 +2410,6 @@ class GeneralWarningException(WarnLevel, Cli, File):
             return self.log_fmt.format(str(self.exc))
         return str(self.exc)
 
-    def fields_to_json(self, val: Any) -> Any:
-        if val == self.exc:
-            return str(val)
-
-        return val
-
 
 @dataclass
 class EventBufferFull(WarnLevel, Cli, File):
@@ -2675,8 +2473,8 @@ if 1 == 0:
     SQLQueryStatus(status="", elapsed=0.1)
     SQLCommit(conn_name="")
     ColTypeChange(orig_type="", new_type="", table="")
-    SchemaCreation(relation=BaseRelation())
-    SchemaDrop(relation=BaseRelation())
+    SchemaCreation(relation=_make_key(BaseRelation()))
+    SchemaDrop(relation=_make_key(BaseRelation()))
     UncachedRelation(
         dep_key=_ReferenceKey(database="", schema="", identifier=""),
         ref_key=_ReferenceKey(database="", schema="", identifier=""),
@@ -2685,7 +2483,7 @@ if 1 == 0:
         dep_key=_ReferenceKey(database="", schema="", identifier=""),
         ref_key=_ReferenceKey(database="", schema="", identifier=""),
     )
-    AddRelation(relation=_CachedRelation())
+    AddRelation(relation=_make_key(_CachedRelation()))
     DropMissingRelation(relation=_ReferenceKey(database="", schema="", identifier=""))
     DropCascade(
         dropped=_ReferenceKey(database="", schema="", identifier=""),
@@ -2708,14 +2506,10 @@ if 1 == 0:
     AdapterImportError(ModuleNotFoundError())
     PluginLoadError()
     SystemReportReturnCode(returncode=0)
-    SelectorAlertUpto3UnusedNodes(node_names=[])
-    SelectorAlertAllUnusedNodes(node_names=[])
     NewConnectionOpening(connection_state='')
     TimingInfoCollected()
     MergedFromState(nbr_merged=0, sample=[])
     MissingProfileTarget(profile_name='', target_name='')
-    ProfileLoadError(exc=Exception(''))
-    ProfileNotFound(profile_name='')
     InvalidVarsYAML()
     GenericTestFileParse(path='')
     MacroFileParse(path='')
@@ -2755,8 +2549,6 @@ if 1 == 0:
     PartialParsingDeletedExposure(unique_id='')
     InvalidDisabledSourceInTestNode(msg='')
     InvalidRefInTestNode(msg='')
-    MessageHandleGenericException(build_path='', unique_id='', exc=Exception(''))
-    DetailsHandleGenericException()
     RunningOperationCaughtError(exc=Exception(''))
     RunningOperationUncaughtError(exc=Exception(''))
     DbtProjectError()
@@ -2769,7 +2561,7 @@ if 1 == 0:
     ProfileHelpMessage()
     CatchableExceptionOnRun(exc=Exception(''))
     InternalExceptionOnRun(build_path='', exc=Exception(''))
-    GenericExceptionOnRun(build_path='', unique_id='', exc=Exception(''))
+    GenericExceptionOnRun(build_path='', unique_id='', exc='')
     NodeConnectionReleaseError(node_name='', exc=Exception(''))
     CheckCleanPath(path='')
     ConfirmCleanPath(path='')
@@ -2777,7 +2569,7 @@ if 1 == 0:
     FinishedCleanPaths()
     OpenCommand(open_cmd='', profiles_dir='')
     DepsNoPackagesFound()
-    DepsStartPackageInstall(package='')
+    DepsStartPackageInstall(package_name='')
     DepsInstallInfo(version_name='')
     DepsUpdateAvailable(version_latest='')
     DepsListSubdirectory(subdirectory='')
@@ -2952,7 +2744,7 @@ if 1 == 0:
     NodeStart(report_node_data=ParsedModelNode(), unique_id='')
     NodeFinished(report_node_data=ParsedModelNode(), unique_id='', run_result=RunResult())
     QueryCancelationUnsupported(type='')
-    ConcurrencyLine(concurrency_line='')
+    ConcurrencyLine(num_threads=0, target_name='')
     NodeCompiling(report_node_data=ParsedModelNode(), unique_id='')
     NodeExecuting(report_node_data=ParsedModelNode(), unique_id='')
     StarterProjectPath(dir='')

core/dbt/exceptions.py

@@ -2,8 +2,7 @@ import builtins
 import functools
 from typing import NoReturn, Optional, Mapping, Any
 
-from dbt.logger import get_secret_env
-from dbt.events.functions import fire_event
+from dbt.events.functions import fire_event, scrub_secrets, env_secrets
 from dbt.events.types import GeneralWarningMsg, GeneralWarningException
 from dbt.node_types import NodeType
 from dbt import flags
@@ -54,7 +53,7 @@ class RuntimeException(RuntimeError, Exception):
     def __init__(self, msg, node=None):
         self.stack = []
         self.node = node
-        self.msg = msg
+        self.msg = scrub_secrets(msg, env_secrets())
 
     def add_node(self, node=None):
         if node is not None and node is not self.node:
@@ -401,8 +400,6 @@ class CommandError(RuntimeException):
         super().__init__(message)
         self.cwd = cwd
         self.cmd = cmd
-        for secret in get_secret_env():
-            self.cmd = str(self.cmd).replace(secret, "*****")
         self.args = (cwd, cmd, message)
 
     def __str__(self):
@@ -466,7 +463,21 @@ def raise_database_error(msg, node=None) -> NoReturn:
 
 
 def raise_dependency_error(msg) -> NoReturn:
-    raise DependencyException(msg)
+    raise DependencyException(scrub_secrets(msg, env_secrets()))
+
+
+def raise_git_cloning_error(error: CommandResultError) -> NoReturn:
+    error.cmd = scrub_secrets(str(error.cmd), env_secrets())
+    raise error
+
+
+def raise_git_cloning_problem(repo) -> NoReturn:
+    repo = scrub_secrets(repo, env_secrets())
+    msg = '''\
+    Something went wrong while cloning {}
+    Check the debug logs for more information
+    '''
+    raise RuntimeException(msg.format(repo))
 
 
 def disallow_secret_env_var(env_var_name) -> NoReturn:
@@ -692,9 +703,9 @@ def missing_materialization(model, adapter_type):
 
 
 def bad_package_spec(repo, spec, error_message):
-    raise InternalException(
-        "Error checking out spec='{}' for repo {}\n{}".format(
-            spec, repo, error_message))
+    msg = "Error checking out spec='{}' for repo {}\n{}".format(spec, repo, error_message)
+
+    raise InternalException(scrub_secrets(msg, env_secrets()))
 
 
 def raise_cache_inconsistent(message):
@@ -763,6 +774,10 @@ def system_error(operation_name):
 
 
 class ConnectionException(Exception):
+    """
+    There was a problem with the connection that returned a bad response,
+    timed out, or resulted in a file that is corrupt.
+    """
     pass
 
 
@@ -999,7 +1014,7 @@ def raise_duplicate_alias(
 
 def warn_or_error(msg, node=None, log_fmt=None):
     if flags.WARN_ERROR:
-        raise_compiler_error(msg, node)
+        raise_compiler_error(scrub_secrets(msg, env_secrets()), node)
     else:
         fire_event(GeneralWarningMsg(msg=msg, log_fmt=log_fmt))
 

core/dbt/flags.py

@@ -33,6 +33,8 @@ SEND_ANONYMOUS_USAGE_STATS = None
 PRINTER_WIDTH = 80
 WHICH = None
 INDIRECT_SELECTION = None
+LOG_CACHE_EVENTS = None
+EVENT_BUFFER_SIZE = 100000
 
 # Global CLI defaults. These flags are set from three places:
 # CLI args, environment variables, and user_config (profiles.yml).
@@ -51,7 +53,9 @@ flag_defaults = {
     "FAIL_FAST": False,
     "SEND_ANONYMOUS_USAGE_STATS": True,
     "PRINTER_WIDTH": 80,
-    "INDIRECT_SELECTION": 'eager'
+    "INDIRECT_SELECTION": 'eager',
+    "LOG_CACHE_EVENTS": False,
+    "EVENT_BUFFER_SIZE": 100000
 }
 
 
@@ -99,7 +103,7 @@ def set_from_args(args, user_config):
         USE_EXPERIMENTAL_PARSER, STATIC_PARSER, WRITE_JSON, PARTIAL_PARSE, \
         USE_COLORS, STORE_FAILURES, PROFILES_DIR, DEBUG, LOG_FORMAT, INDIRECT_SELECTION, \
         VERSION_CHECK, FAIL_FAST, SEND_ANONYMOUS_USAGE_STATS, PRINTER_WIDTH, \
-        WHICH
+        WHICH, LOG_CACHE_EVENTS, EVENT_BUFFER_SIZE
 
     STRICT_MODE = False  # backwards compatibility
     # cli args without user_config or env var option
@@ -122,6 +126,8 @@ def set_from_args(args, user_config):
     SEND_ANONYMOUS_USAGE_STATS = get_flag_value('SEND_ANONYMOUS_USAGE_STATS', args, user_config)
     PRINTER_WIDTH = get_flag_value('PRINTER_WIDTH', args, user_config)
     INDIRECT_SELECTION = get_flag_value('INDIRECT_SELECTION', args, user_config)
+    LOG_CACHE_EVENTS = get_flag_value('LOG_CACHE_EVENTS', args, user_config)
+    EVENT_BUFFER_SIZE = get_flag_value('EVENT_BUFFER_SIZE', args, user_config)
 
 
 def get_flag_value(flag, args, user_config):
@@ -134,7 +140,13 @@ def get_flag_value(flag, args, user_config):
         if env_value is not None and env_value != '':
             env_value = env_value.lower()
             # non Boolean values
-            if flag in ['LOG_FORMAT', 'PRINTER_WIDTH', 'PROFILES_DIR', 'INDIRECT_SELECTION']:
+            if flag in [
+                'LOG_FORMAT',
+                'PRINTER_WIDTH',
+                'PROFILES_DIR',
+                'INDIRECT_SELECTION',
+                'EVENT_BUFFER_SIZE'
+            ]:
                 flag_value = env_value
             else:
                 flag_value = env_set_bool(env_value)
@@ -142,7 +154,7 @@ def get_flag_value(flag, args, user_config):
             flag_value = getattr(user_config, lc_flag)
         else:
             flag_value = flag_defaults[flag]
-    if flag == 'PRINTER_WIDTH':  # printer_width must be an int or it hangs
+    if flag in ['PRINTER_WIDTH', 'EVENT_BUFFER_SIZE']:  # must be ints
         flag_value = int(flag_value)
     if flag == 'PROFILES_DIR':
         flag_value = os.path.abspath(flag_value)
@@ -165,5 +177,7 @@ def get_flag_dict():
         "fail_fast": FAIL_FAST,
         "send_anonymous_usage_stats": SEND_ANONYMOUS_USAGE_STATS,
         "printer_width": PRINTER_WIDTH,
-        "indirect_selection": INDIRECT_SELECTION
+        "indirect_selection": INDIRECT_SELECTION,
+        "log_cache_events": LOG_CACHE_EVENTS,
+        "event_buffer_size": EVENT_BUFFER_SIZE
     }

core/dbt/include/global_project/docs/overview.md

@@ -35,7 +35,7 @@ Note that you can also right-click on models to interactively filter and explore
 
 ### More information
 
-- [What is dbt](https://docs.getdbt.com/docs/overview)?
+- [What is dbt](https://docs.getdbt.com/docs/introduction)?
 - Read the [dbt viewpoint](https://docs.getdbt.com/docs/viewpoint)
 - [Installation](https://docs.getdbt.com/docs/installation)
 - Join the [dbt Community](https://www.getdbt.com/community/) for questions and discussion

core/dbt/logger.py

@@ -424,7 +424,7 @@ class DelayedFileHandler(logbook.RotatingFileHandler, FormatterMixin):
             return
 
         make_log_dir_if_missing(log_dir)
-        log_path = os.path.join(log_dir, 'dbt.log.old')  # TODO hack for now
+        log_path = os.path.join(log_dir, 'dbt.log.legacy')  # TODO hack for now
         self._super_init(log_path)
         self._replay_buffered()
         self._log_path = log_path

core/dbt/main.py

@@ -221,24 +221,22 @@ def track_run(task):
 def run_from_args(parsed):
     log_cache_events(getattr(parsed, 'log_cache_events', False))
 
-    # we can now use the logger for stdout
-    # set log_format in the logger
-    # if 'list' task: set stdout to WARN instead of INFO
-    level_override = parsed.cls.pre_init_hook(parsed)
-
-    fire_event(MainReportVersion(v=str(dbt.version.installed)))
-
     # this will convert DbtConfigErrors into RuntimeExceptions
     # task could be any one of the task objects
     task = parsed.cls.from_args(args=parsed)
-    fire_event(MainReportArgs(args=parsed))
 
+    # Set up logging
     log_path = None
     if task.config is not None:
         log_path = getattr(task.config, 'log_path', None)
-    # we can finally set the file logger up
     log_manager.set_path(log_path)
+    # if 'list' task: set stdout to WARN instead of INFO
+    level_override = parsed.cls.pre_init_hook(parsed)
     setup_event_logger(log_path or 'logs', level_override)
+
+    fire_event(MainReportVersion(v=str(dbt.version.installed)))
+    fire_event(MainReportArgs(args=parsed))
+
     if dbt.tracking.active_user is not None:  # mypy appeasement, always true
         fire_event(MainTrackingUserState(dbt.tracking.active_user.state()))
 
@@ -1078,6 +1076,14 @@ def parse_args(args, cls=DBTArgumentParser):
         '''
     )
 
+    p.add_argument(
+        '--event-buffer-size',
+        dest='event_buffer_size',
+        help='''
+        Sets the max number of events to buffer in EVENT_HISTORY
+        '''
+    )
+
     subs = p.add_subparsers(title="Available sub-commands")
 
     base_subparser = _build_base_subparser()

core/dbt/parser/manifest.py

@@ -246,7 +246,7 @@ class ManifestLoader:
                     project_parser_files = self.partial_parser.get_parsing_files()
                     self.partially_parsing = True
                     self.manifest = self.saved_manifest
-                except Exception:
+                except Exception as exc:
                     # pp_files should still be the full set and manifest is new manifest,
                     # since get_parsing_files failed
                     fire_event(PartialParsingFullReparseBecauseOfError())
@@ -284,6 +284,9 @@ class ManifestLoader:
                         exc_info['full_reparse_reason'] = ReparseReason.exception
                         dbt.tracking.track_partial_parser(exc_info)
 
+                    if os.environ.get('DBT_PP_TEST'):
+                        raise exc
+
         if self.manifest._parsing_info is None:
             self.manifest._parsing_info = ParsingInfo()
 

core/dbt/parser/partial.py

@@ -315,7 +315,7 @@ class PartialParsing:
         if node.patch_path:
             file_id = node.patch_path
             # it might be changed...  then what?
-            if file_id not in self.file_diff['deleted']:
+            if file_id not in self.file_diff['deleted'] and file_id in self.saved_files:
                 # schema_files should already be updated
                 schema_file = self.saved_files[file_id]
                 dict_key = parse_file_type_to_key[source_file.parse_file_type]
@@ -375,7 +375,7 @@ class PartialParsing:
         for unique_id in unique_ids:
             if unique_id in self.saved_manifest.nodes:
                 node = self.saved_manifest.nodes[unique_id]
-                if node.resource_type == NodeType.Test:
+                if node.resource_type == NodeType.Test and node.test_node_type == 'generic':
                     # test nodes are handled separately. Must be removed from schema file
                     continue
                 file_id = node.file_id
@@ -435,7 +435,9 @@ class PartialParsing:
         self.check_for_special_deleted_macros(source_file)
         self.handle_macro_file_links(source_file, follow_references)
         file_id = source_file.file_id
-        self.deleted_manifest.files[file_id] = self.saved_files.pop(file_id)
+        # It's not clear when this file_id would not exist in saved_files
+        if file_id in self.saved_files:
+            self.deleted_manifest.files[file_id] = self.saved_files.pop(file_id)
 
     def check_for_special_deleted_macros(self, source_file):
         for unique_id in source_file.macros:
@@ -498,7 +500,9 @@ class PartialParsing:
         for unique_id in unique_ids:
             if unique_id in self.saved_manifest.nodes:
                 node = self.saved_manifest.nodes[unique_id]
-                if node.resource_type == NodeType.Test:
+                # Both generic tests from yaml files and singular tests have NodeType.Test
+                # so check for generic test.
+                if node.resource_type == NodeType.Test and node.test_node_type == 'generic':
                     schema_file_id = node.file_id
                     schema_file = self.saved_manifest.files[schema_file_id]
                     (key, name) = schema_file.get_key_and_name_for_test(node.unique_id)
@@ -670,8 +674,8 @@ class PartialParsing:
                     continue
                 elem = self.get_schema_element(new_yaml_dict[dict_key], name)
                 if elem:
-                    self.delete_schema_macro_patch(schema_file, macro)
-                    self.merge_patch(schema_file, dict_key, macro)
+                    self.delete_schema_macro_patch(schema_file, elem)
+                    self.merge_patch(schema_file, dict_key, elem)
 
         # exposures
         dict_key = 'exposures'

core/dbt/parser/schemas.py

@@ -960,10 +960,9 @@ class MacroPatchParser(NonSourceParser[UnparsedMacroUpdate, ParsedMacroPatch]):
         unique_id = f'macro.{patch.package_name}.{patch.name}'
         macro = self.manifest.macros.get(unique_id)
         if not macro:
-            warn_or_error(
-                f'WARNING: Found patch for macro "{patch.name}" '
-                f'which was not found'
-            )
+            msg = f'Found patch for macro "{patch.name}" ' \
+                  f'which was not found'
+            warn_or_error(msg, log_fmt=warning_tag('{}'))
             return
         if macro.patch_path:
             package_name, existing_file_path = macro.patch_path.split('://')

core/dbt/task/base.py

@@ -334,7 +334,7 @@ class BaseRunner(metaclass=ABCMeta):
             GenericExceptionOnRun(
                 build_path=self.node.build_path,
                 unique_id=self.node.unique_id,
-                exc=e
+                exc=str(e)  # TODO: unstring this when serialization is fixed
             )
         )
         fire_event(PrintDebugStackTrace())

core/dbt/task/clean.py

@@ -38,7 +38,7 @@ class CleanTask(BaseTask):
         """
         move_to_nearest_project_dir(self.args)
         if ('dbt_modules' in self.config.clean_targets and
-           self.config.packages_install_path != 'dbt_modules'):
+           self.config.packages_install_path not in self.config.clean_targets):
             deprecations.warn('install-packages-path')
         for path in self.config.clean_targets:
             fire_event(CheckCleanPath(path=path))

core/dbt/task/deps.py

@@ -10,7 +10,7 @@ from dbt.deps.resolver import resolve_packages
 from dbt.events.functions import fire_event
 from dbt.events.types import (
     DepsNoPackagesFound, DepsStartPackageInstall, DepsUpdateAvailable, DepsUTD,
-    DepsInstallInfo, DepsListSubdirectory, DepsNotifyUpdatesAvailable
+    DepsInstallInfo, DepsListSubdirectory, DepsNotifyUpdatesAvailable, EmptyLine
 )
 from dbt.clients import system
 
@@ -63,7 +63,7 @@ class DepsTask(BaseTask):
                 source_type = package.source_type()
                 version = package.get_version()
 
-                fire_event(DepsStartPackageInstall(package=package))
+                fire_event(DepsStartPackageInstall(package_name=package_name))
                 package.install(self.config, renderer)
                 fire_event(DepsInstallInfo(version_name=package.nice_version_name()))
                 if source_type == 'hub':
@@ -81,6 +81,7 @@ class DepsTask(BaseTask):
                     source_type=source_type,
                     version=version)
             if packages_to_upgrade:
+                fire_event(EmptyLine())
                 fire_event(DepsNotifyUpdatesAvailable(packages=packages_to_upgrade))
 
     @classmethod

core/dbt/task/init.py

@@ -285,6 +285,8 @@ class InitTask(BaseTask):
             # just setup the user's profile.
             fire_event(SettingUpProfile())
             profile_name = self.get_profile_name_from_current_project()
+            if not self.check_if_can_write_profile(profile_name=profile_name):
+                return
             # If a profile_template.yml exists in the project root, that effectively
             # overrides the profile_template.yml for the given target.
             profile_template_path = Path("profile_template.yml")
@@ -296,8 +298,6 @@ class InitTask(BaseTask):
                     return
                 except Exception:
                     fire_event(InvalidProfileTemplateYAML())
-            if not self.check_if_can_write_profile(profile_name=profile_name):
-                return
             adapter = self.ask_for_adapter_choice()
             self.create_profile_from_target(
                 adapter, profile_name=profile_name

core/dbt/task/printer.py

@@ -65,6 +65,8 @@ def print_run_status_line(results) -> None:
         stats[result_type] += 1
         stats['total'] += 1
 
+    with TextOnly():
+        fire_event(EmptyLine())
     fire_event(StatsLine(stats=stats))
 
 

core/dbt/task/run.py

@@ -11,7 +11,7 @@ from .printer import (
     print_run_end_messages,
     get_counts,
 )
-
+from datetime import datetime
 from dbt import tracking
 from dbt import utils
 from dbt.adapters.base import BaseRelation
@@ -21,7 +21,7 @@ from dbt.contracts.graph.compiled import CompileResultNode
 from dbt.contracts.graph.manifest import WritableManifest
 from dbt.contracts.graph.model_config import Hook
 from dbt.contracts.graph.parsed import ParsedHookNode
-from dbt.contracts.results import NodeStatus, RunResult, RunStatus
+from dbt.contracts.results import NodeStatus, RunResult, RunStatus, RunningStatus
 from dbt.exceptions import (
     CompilationException,
     InternalException,
@@ -342,6 +342,8 @@ class RunTask(CompileTask):
         finishctx = TimestampNamed('node_finished_at')
 
         for idx, hook in enumerate(ordered_hooks, start=1):
+            hook._event_status['started_at'] = datetime.utcnow().isoformat()
+            hook._event_status['node_status'] = RunningStatus.Started
             sql = self.get_hook_sql(adapter, hook, idx, num_hooks,
                                     extra_context)
 
@@ -360,19 +362,21 @@ class RunTask(CompileTask):
                         )
                     )
 
-                status = 'OK'
-
                 with Timer() as timer:
                     if len(sql.strip()) > 0:
-                        status, _ = adapter.execute(sql, auto_begin=False,
-                                                    fetch=False)
-                self.ran_hooks.append(hook)
+                        response, _ = adapter.execute(sql, auto_begin=False, fetch=False)
+                        status = response._message
+                    else:
+                        status = 'OK'
 
+                self.ran_hooks.append(hook)
+                hook._event_status['finished_at'] = datetime.utcnow().isoformat()
                 with finishctx, DbtModelState({'node_status': 'passed'}):
+                    hook._event_status['node_status'] = RunStatus.Success
                     fire_event(
                         PrintHookEndLine(
                             statement=hook_text,
-                            status=str(status),
+                            status=status,
                             index=idx,
                             total=num_hooks,
                             execution_time=timer.elapsed,
@@ -380,6 +384,11 @@ class RunTask(CompileTask):
                             report_node_data=hook
                         )
                     )
+            # `_event_status` dict is only used for logging.  Make sure
+            # it gets deleted when we're done with it
+            del hook._event_status["started_at"]
+            del hook._event_status["finished_at"]
+            del hook._event_status["node_status"]
 
         self._total_executed += len(ordered_hooks)
 

core/dbt/task/runnable.py

@@ -56,6 +56,7 @@ from dbt.parser.manifest import ManifestLoader
 import dbt.exceptions
 from dbt import flags
 import dbt.utils
+from dbt.ui import warning_tag
 
 RESULT_FILE_NAME = 'run_results.json'
 MANIFEST_FILE_NAME = 'manifest.json'
@@ -208,7 +209,7 @@ class GraphRunnableTask(ManifestTask):
         with RUNNING_STATE, uid_context:
             startctx = TimestampNamed('node_started_at')
             index = self.index_offset(runner.node_index)
-            runner.node._event_status['dbt_internal__started_at'] = datetime.utcnow().isoformat()
+            runner.node._event_status['started_at'] = datetime.utcnow().isoformat()
             runner.node._event_status['node_status'] = RunningStatus.Started
             extended_metadata = ModelMetadata(runner.node, index)
 
@@ -224,8 +225,7 @@ class GraphRunnableTask(ManifestTask):
                 result = runner.run_with_hooks(self.manifest)
                 status = runner.get_result_status(result)
                 runner.node._event_status['node_status'] = result.status
-                runner.node._event_status['dbt_internal__finished_at'] = \
-                    datetime.utcnow().isoformat()
+                runner.node._event_status['finished_at'] = datetime.utcnow().isoformat()
             finally:
                 finishctx = TimestampNamed('finished_at')
                 with finishctx, DbtModelState(status):
@@ -238,8 +238,8 @@ class GraphRunnableTask(ManifestTask):
                     )
             # `_event_status` dict is only used for logging.  Make sure
             # it gets deleted when we're done with it
-            del runner.node._event_status["dbt_internal__started_at"]
-            del runner.node._event_status["dbt_internal__finished_at"]
+            del runner.node._event_status["started_at"]
+            del runner.node._event_status["finished_at"]
             del runner.node._event_status["node_status"]
 
         fail_fast = flags.FAIL_FAST
@@ -359,7 +359,7 @@ class GraphRunnableTask(ManifestTask):
         adapter = get_adapter(self.config)
 
         if not adapter.is_cancelable():
-            fire_event(QueryCancelationUnsupported(type=adapter.type))
+            fire_event(QueryCancelationUnsupported(type=adapter.type()))
         else:
             with adapter.connection_named('master'):
                 for conn_name in adapter.cancel_open_connections():
@@ -377,10 +377,8 @@ class GraphRunnableTask(ManifestTask):
         num_threads = self.config.threads
         target_name = self.config.target_name
 
-        text = "Concurrency: {} threads (target='{}')"
-        concurrency_line = text.format(num_threads, target_name)
         with NodeCount(self.num_nodes):
-            fire_event(ConcurrencyLine(concurrency_line=concurrency_line))
+            fire_event(ConcurrencyLine(num_threads=num_threads, target_name=target_name))
         with TextOnly():
             fire_event(EmptyLine())
 
@@ -461,8 +459,11 @@ class GraphRunnableTask(ManifestTask):
             )
 
         if len(self._flattened_nodes) == 0:
-            warn_or_error("\nWARNING: Nothing to do. Try checking your model "
-                          "configs and model specification args")
+            with TextOnly():
+                fire_event(EmptyLine())
+            msg = "Nothing to do. Try checking your model " \
+                  "configs and model specification args"
+            warn_or_error(msg, log_fmt=warning_tag('{}'))
             result = self.get_result(
                 results=[],
                 generated_at=datetime.utcnow(),

core/dbt/task/serve.py

@@ -6,7 +6,7 @@ from dbt.include.global_project import DOCS_INDEX_FILE_PATH
 from http.server import SimpleHTTPRequestHandler
 from socketserver import TCPServer
 from dbt.events.functions import fire_event
-from dbt.events.types import ServingDocsPort, ServingDocsAccessInfo, ServingDocsExitInfo
+from dbt.events.types import ServingDocsPort, ServingDocsAccessInfo, ServingDocsExitInfo, EmptyLine
 
 from dbt.task.base import ConfiguredTask
 
@@ -22,6 +22,8 @@ class ServeTask(ConfiguredTask):
 
         fire_event(ServingDocsPort(address=address, port=port))
         fire_event(ServingDocsAccessInfo(port=port))
+        fire_event(EmptyLine())
+        fire_event(EmptyLine())
         fire_event(ServingDocsExitInfo())
 
         # mypy doesn't think SimpleHTTPRequestHandler is ok here, but it is

core/dbt/ui.py

@@ -66,6 +66,4 @@ def line_wrap_message(
 
 
 def warning_tag(msg: str) -> str:
-    # no longer needed, since new logging includes colorized log level
-    # return f'[{yellow("WARNING")}]: {msg}'
-    return msg
+    return f'[{yellow("WARNING")}]: {msg}'

core/dbt/utils.py

@@ -10,6 +10,7 @@ import jinja2
 import json
 import os
 import requests
+from tarfile import ReadError
 import time
 
 from contextlib import contextmanager
@@ -598,7 +599,9 @@ class MultiDict(Mapping[str, Any]):
 
 def _connection_exception_retry(fn, max_attempts: int, attempt: int = 0):
     """Attempts to run a function that makes an external call, if the call fails
-    on a connection error or timeout, it will be tried up to 5 more times.
+    on a connection error, timeout or decompression issue, it will be tried up to 5 more times.
+    See https://github.com/dbt-labs/dbt-core/issues/4579 for context on this decompression issues
+    specifically.
     """
     try:
         return fn()
@@ -606,6 +609,7 @@ def _connection_exception_retry(fn, max_attempts: int, attempt: int = 0):
         requests.exceptions.ConnectionError,
         requests.exceptions.Timeout,
         requests.exceptions.ContentDecodingError,
+        ReadError,
     ) as exc:
         if attempt <= max_attempts - 1:
             fire_event(RetryExternalCall(attempt=attempt, max=max_attempts))

core/dbt/version.py

@@ -11,7 +11,7 @@ import dbt.exceptions
 import dbt.semver
 
 
-PYPI_VERSION_URL = 'https://pypi.org/pypi/dbt/json'
+PYPI_VERSION_URL = 'https://pypi.org/pypi/dbt-core/json'
 
 
 def get_latest_version():
@@ -96,5 +96,5 @@ def _get_dbt_plugins_info():
         yield plugin_name, mod.version
 
 
-__version__ = '1.0.0rc3'
+__version__ = '1.0.1'
 installed = get_installed_version()

core/scripts/create_adapter_plugins.py

@@ -284,12 +284,12 @@ def parse_args(argv=None):
     parser.add_argument('adapter')
     parser.add_argument('--title-case', '-t', default=None)
     parser.add_argument('--dependency', action='append')
-    parser.add_argument('--dbt-core-version', default='1.0.0rc3')
+    parser.add_argument('--dbt-core-version', default='1.0.1')
     parser.add_argument('--email')
     parser.add_argument('--author')
     parser.add_argument('--url')
     parser.add_argument('--sql', action='store_true')
-    parser.add_argument('--package-version', default='1.0.0rc3')
+    parser.add_argument('--package-version', default='1.0.1')
     parser.add_argument('--project-version', default='1.0')
     parser.add_argument(
         '--no-dependency', action='store_false', dest='set_dependency'

core/setup.py

@@ -25,7 +25,7 @@ with open(os.path.join(this_directory, 'README.md')) as f:
 
 
 package_name = "dbt-core"
-package_version = "1.0.0rc3"
+package_version = "1.0.1"
 description = """With dbt, data analysts and engineers can build analytics \
 the way engineers build applications."""
 

docker/requirements/requirements.txt

@@ -3,17 +3,17 @@ attrs==21.2.0
 Babel==2.9.1
 certifi==2021.10.8
 cffi==1.15.0
-charset-normalizer==2.0.8
+charset-normalizer==2.0.9
 click==8.0.3
 colorama==0.4.4
-dbt-core==1.0.0rc3
+dbt-core==1.0.1rc1
 dbt-extractor==0.4.0
-dbt-postgres==1.0.0rc3
+dbt-postgres==1.0.1rc1
 future==0.18.2
 hologram==0.0.14
 idna==3.3
-importlib-metadata==4.8.2
-isodate==0.6.0
+importlib-metadata==4.9.0
+isodate==0.6.1
 Jinja2==2.11.3
 jsonschema==3.1.1
 leather==0.3.4

plugins/postgres/dbt/adapters/postgres/__version__.py

@@ -1 +1 @@
-version = '1.0.0rc3'
+version = '1.0.1'

plugins/postgres/setup.py

@@ -41,7 +41,7 @@ def _dbt_psycopg2_name():
 
 
 package_name = "dbt-postgres"
-package_version = "1.0.0rc3"
+package_version = "1.0.1"
 description = """The postgres adpter plugin for dbt (data build tool)"""
 
 this_directory = os.path.abspath(os.path.dirname(__file__))

setup.py

@@ -5,7 +5,7 @@ import sys
 
 if 'sdist' not in sys.argv:
     print('')
-    print('As of v1.0.0, `pip install dbt` is no longer supported.')
+    print('As of v1.0.1, `pip install dbt` is no longer supported.')
     print('Instead, please use one of the following.')
     print('')
     print('**To use dbt with your specific database, platform, or query engine:**')
@@ -50,7 +50,7 @@ with open(os.path.join(this_directory, 'README.md')) as f:
 
 
 package_name = "dbt"
-package_version = "1.0.0rc3"
+package_version = "1.0.1"
 description = """With dbt, data analysts and engineers can build analytics \
 the way engineers build applications."""
 

test/integration/006_simple_dependency_test/test_simple_dependency.py

@@ -246,3 +246,48 @@ class TestSimpleDependencyNoProfile(TestSimpleDependency):
         with tempfile.TemporaryDirectory() as tmpdir:
             result = self.run_dbt(["clean", "--profiles-dir", tmpdir])
         return result
+
+class TestSimpleDependencyBadProfile(DBTIntegrationTest):
+
+    @property
+    def schema(self):
+        return "simple_dependency_006"
+
+    @property
+    def models(self):
+        return "models"
+
+    def postgres_profile(self):
+        # Need to set the environment variable here initially because
+        # the unittest setup does a load_config.
+        os.environ['PROFILE_TEST_HOST'] = self.database_host
+        return {
+            'config': {
+                'send_anonymous_usage_stats': False
+            },
+            'test': {
+                'outputs': {
+                    'default2': {
+                        'type': 'postgres',
+                        'threads': 4,
+                        'host': "{{ env_var('PROFILE_TEST_HOST') }}",
+                        'port': 5432,
+                        'user': 'root',
+                        'pass': 'password',
+                        'dbname': 'dbt',
+                        'schema': self.unique_schema()
+                    },
+                },
+                'target': 'default2'
+            }
+        }
+
+    @use_profile('postgres')
+    def test_postgres_deps_bad_profile(self):
+        del os.environ['PROFILE_TEST_HOST']
+        self.run_dbt(["deps"])
+
+    @use_profile('postgres')
+    def test_postgres_clean_bad_profile(self):
+        del os.environ['PROFILE_TEST_HOST']
+        self.run_dbt(["clean"])

test/integration/012_deprecation_tests/test_deprecations.py

@@ -43,7 +43,7 @@ class TestConfigPathDeprecation(BaseTestDeprecations):
         with self.assertRaises(dbt.exceptions.CompilationException) as exc:
             self.run_dbt(['--warn-error', 'debug'])
         exc_str = ' '.join(str(exc.exception).split())  # flatten all whitespace
-        expected = "The `data-paths` config has been deprecated"
+        expected = "The `data-paths` config has been renamed"
         assert expected in exc_str
 
 

test/integration/014_hook_tests/test_run_hooks.py

@@ -1,4 +1,5 @@
 from test.integration.base import DBTIntegrationTest, use_profile
+import os
 
 
 class TestPrePostRunHooks(DBTIntegrationTest):
@@ -22,6 +23,7 @@ class TestPrePostRunHooks(DBTIntegrationTest):
             'run_started_at',
             'invocation_id'
         ]
+        os.environ['TERM_TEST'] = 'TESTING'
 
     @property
     def schema(self):
@@ -41,6 +43,7 @@ class TestPrePostRunHooks(DBTIntegrationTest):
                 "{{ custom_run_hook('start', target, run_started_at, invocation_id) }}",
                 "create table {{ target.schema }}.start_hook_order_test ( id int )",
                 "drop table {{ target.schema }}.start_hook_order_test",
+                "{{ log(env_var('TERM_TEST'), info=True) }}",
             ],
             "on-run-end": [
                 "{{ custom_run_hook('end', target, run_started_at, invocation_id) }}",

test/integration/015_cli_invocation_tests/test_cli_invocation.py

@@ -41,9 +41,17 @@ def temporary_working_directory() -> str:
     out : str
         The temporary working directory.
     """
-    with tempfile.TemporaryDirectory() as tmpdir:
-        with change_working_directory(tmpdir):
-            yield tmpdir
+    # N.B: supressing the OSError is necessary for older (pre 3.10) versions of python 
+    # which do not support the `ignore_cleanup_errors` in tempfile::TemporaryDirectory.
+    # See: https://github.com/python/cpython/pull/24793
+    #
+    # In our case the cleanup is redundent since windows handles clearing 
+    # Appdata/Local/Temp at the os level anyway.
+
+    with contextlib.suppress(OSError):
+        with tempfile.TemporaryDirectory() as tmpdir:
+            with change_working_directory(tmpdir):
+                yield tmpdir
 
 
 def get_custom_profiles_config(database_host, custom_schema):

test/integration/030_statement_test/test_statements.py

@@ -34,15 +34,3 @@ class TestStatements(DBTIntegrationTest):
         self.assertEqual(len(results), 1)
 
         self.assertTablesEqual("statement_actual", "statement_expected")
-
-    @use_profile("presto")
-    def test_presto_statements(self):
-        self.use_default_project({"seed-paths": [self.dir("seed")]})
-
-        results = self.run_dbt(["seed"])
-        self.assertEqual(len(results), 2)
-        results = self.run_dbt()
-        self.assertEqual(len(results), 1)
-
-        self.assertTablesEqual("statement_actual", "statement_expected")
-

test/integration/062_defer_state_test/previous_state/manifest.json

@@ -0,0 +1,6 @@
+{
+    "metadata": {
+        "dbt_schema_version": "https://schemas.getdbt.com/dbt/manifest/v3.json",
+        "dbt_version": "0.21.1"
+    }
+}

test/integration/062_defer_state_test/test_modified_state.py

@@ -6,7 +6,7 @@ import string
 
 import pytest
 
-from dbt.exceptions import CompilationException
+from dbt.exceptions import CompilationException, IncompatibleSchemaException
 
 
 class TestModifiedState(DBTIntegrationTest):
@@ -36,7 +36,7 @@ class TestModifiedState(DBTIntegrationTest):
         for entry in os.listdir(self.test_original_source_path):
             src = os.path.join(self.test_original_source_path, entry)
             tst = os.path.join(self.test_root_dir, entry)
-            if entry in {'models', 'seeds', 'macros'}:
+            if entry in {'models', 'seeds', 'macros', 'previous_state'}:
                 shutil.copytree(src, tst)
             elif os.path.isdir(entry) or entry.endswith('.sql'):
                 os.symlink(src, tst)
@@ -202,3 +202,10 @@ class TestModifiedState(DBTIntegrationTest):
         results, stdout = self.run_dbt_and_capture(['run', '--models', '+state:modified', '--state', './state'])
         assert len(results) == 1
         assert results[0].node.name == 'view_model'
+
+    @use_profile('postgres')
+    def test_postgres_previous_version_manifest(self):
+        # This tests that a different schema version in the file throws an error
+        with self.assertRaises(IncompatibleSchemaException) as exc:
+            results = self.run_dbt(['ls', '-s',  'state:modified',  '--state',  './previous_state'])
+            self.assertEqual(exc.CODE, 10014)

test/integration/068_partial_parsing_tests/test-files/my_test.sql

@@ -1,2 +1,2 @@
 select
-   * from {{ ref('customers') }} where customer_id > 100
+   * from {{ ref('customers') }} where first_name = '{{ macro_something() }}'

test/integration/068_partial_parsing_tests/test-files/test-macro.sql

@@ -0,0 +1,5 @@
+{% macro macro_something() %}
+
+    {% do return('macro_something') %}
+
+{% endmacro %}

test/integration/068_partial_parsing_tests/test-files/test-macro2.sql

@@ -0,0 +1,5 @@
+{% macro macro_something() %}
+
+    {% do return('some_name') %}
+
+{% endmacro %}

test/integration/068_partial_parsing_tests/test_partial_parsing.py

@@ -46,6 +46,7 @@ class BasePPTest(DBTIntegrationTest):
         os.mkdir(os.path.join(self.test_root_dir, 'macros'))
         os.mkdir(os.path.join(self.test_root_dir, 'analyses'))
         os.mkdir(os.path.join(self.test_root_dir, 'snapshots'))
+        os.environ['DBT_PP_TEST'] = 'true'
 
 
 
@@ -332,6 +333,7 @@ class TestSources(BasePPTest):
         results = self.run_dbt(["--partial-parse", "run"])
 
         # Add a data test
+        self.copy_file('test-files/test-macro.sql', 'macros/test-macro.sql')
         self.copy_file('test-files/my_test.sql', 'tests/my_test.sql')
         results = self.run_dbt(["--partial-parse", "test"])
         manifest = get_manifest()
@@ -339,6 +341,11 @@ class TestSources(BasePPTest):
         test_id = 'test.test.my_test'
         self.assertIn(test_id, manifest.nodes)
 
+        # Change macro that data test depends on
+        self.copy_file('test-files/test-macro2.sql', 'macros/test-macro.sql')
+        results = self.run_dbt(["--partial-parse", "test"])
+        manifest = get_manifest()
+
         # Add an analysis
         self.copy_file('test-files/my_analysis.sql', 'analyses/my_analysis.sql')
         results = self.run_dbt(["--partial-parse", "run"])

test/integration/068_partial_parsing_tests/test_pp_docs.py

@@ -37,6 +37,7 @@ class TestDocs(DBTIntegrationTest):
         os.mkdir(os.path.join(self.test_root_dir, 'macros'))
         os.mkdir(os.path.join(self.test_root_dir, 'analyses'))
         os.mkdir(os.path.join(self.test_root_dir, 'snapshots'))
+        os.environ['DBT_PP_TEST'] = 'true'
 
 
     @use_profile('postgres')

test/integration/068_partial_parsing_tests/test_pp_metrics.py

@@ -45,6 +45,7 @@ class BasePPTest(DBTIntegrationTest):
         os.mkdir(os.path.join(self.test_root_dir, 'macros'))
         os.mkdir(os.path.join(self.test_root_dir, 'analyses'))
         os.mkdir(os.path.join(self.test_root_dir, 'snapshots'))
+        os.environ['DBT_PP_TEST'] = 'true'
 
 
 

test/integration/068_partial_parsing_tests/test_pp_vars.py

@@ -41,7 +41,7 @@ class BasePPTest(DBTIntegrationTest):
         os.mkdir(os.path.join(self.test_root_dir, 'tests'))
         os.mkdir(os.path.join(self.test_root_dir, 'macros'))
         os.mkdir(os.path.join(self.test_root_dir, 'seeds'))
-
+        os.environ['DBT_PP_TEST'] = 'true'
 
 
 class EnvVarTest(BasePPTest):
@@ -300,6 +300,64 @@ class ProjectEnvVarTest(BasePPTest):
         # cleanup
         del os.environ['ENV_VAR_NAME']
 
+
+class ProfileSecretEnvVarTest(BasePPTest):
+
+    @property
+    def profile_config(self):
+        # Need to set these here because the base integration test class
+        # calls 'load_config' before the tests are run.
+        # Note: only the specified profile is rendered, so there's no
+        # point it setting env_vars in non-used profiles.
+        os.environ['NOT_SECRET_USER'] = 'root'
+        os.environ['DBT_ENV_SECRET_PASS'] = 'password'
+        return {
+            'config': {
+                'send_anonymous_usage_stats': False
+            },
+            'test': {
+                'outputs': {
+                    'dev': {
+                        'type': 'postgres',
+                        'threads': 1,
+                        'host': self.database_host,
+                        'port': 5432,
+                        'user': "root",
+                        'pass': "password",
+                        'user': "{{ env_var('NOT_SECRET_USER') }}",
+                        'pass': "{{ env_var('DBT_ENV_SECRET_PASS') }}",
+                        'dbname': 'dbt',
+                        'schema': self.unique_schema()
+                    },
+                },
+                'target': 'dev'
+            }
+        }
+
+    @use_profile('postgres')
+    def test_postgres_secret_env_vars(self):
+        # Initial run
+        self.setup_directories()
+        self.copy_file('test-files/model_one.sql', 'models/model_one.sql')
+        results = self.run_dbt(["run"])
+        manifest = get_manifest()
+
+        breakpoint()
+        
+        # find the non-secret in the manifest, we expect it to be there.
+        self.assertEqual(manifest.env_vars['NOT_SECRET_USER'], 'root')
+
+        # attempt to find the secret in the manifest. hopefully it's not there
+        try:
+            manifest.env_vars['x']
+            self.assertTrue(False, 'A secret was saved when it shouldn\'t have been')
+        except KeyError:
+            self.AssertTrue(True)
+
+        # cleanup
+        del os.environ['NOT_SECRET_USER']
+        del os.environ['DBT_ENV_SECRET_PASS']
+
 class ProfileEnvVarTest(BasePPTest):
 
     @property

test/interop/log_parsing/Cargo.lock

@@ -0,0 +1,204 @@
+# This file is automatically @generated by Cargo.
+# It is not intended for manual editing.
+version = 3
+
+[[package]]
+name = "autocfg"
+version = "1.0.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "cdb031dd78e28731d87d56cc8ffef4a8f36ca26c38fe2de700543e627f8a464a"
+
+[[package]]
+name = "chrono"
+version = "0.4.19"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "670ad68c9088c2a963aaa298cb369688cf3f9465ce5e2d4ca10e6e0098a1ce73"
+dependencies = [
+ "libc",
+ "num-integer",
+ "num-traits",
+ "serde",
+ "time",
+ "winapi",
+]
+
+[[package]]
+name = "itoa"
+version = "0.4.8"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "b71991ff56294aa922b450139ee08b3bfc70982c6b2c7562771375cf73542dd4"
+
+[[package]]
+name = "libc"
+version = "0.2.108"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8521a1b57e76b1ec69af7599e75e38e7b7fad6610f037db8c79b127201b5d119"
+
+[[package]]
+name = "log_parsing"
+version = "0.1.0"
+dependencies = [
+ "chrono",
+ "serde",
+ "serde_json",
+ "walkdir",
+]
+
+[[package]]
+name = "num-integer"
+version = "0.1.44"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d2cc698a63b549a70bc047073d2949cce27cd1c7b0a4a862d08a8031bc2801db"
+dependencies = [
+ "autocfg",
+ "num-traits",
+]
+
+[[package]]
+name = "num-traits"
+version = "0.2.14"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "9a64b1ec5cda2586e284722486d802acf1f7dbdc623e2bfc57e65ca1cd099290"
+dependencies = [
+ "autocfg",
+]
+
+[[package]]
+name = "proc-macro2"
+version = "1.0.32"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ba508cc11742c0dc5c1659771673afbab7a0efab23aa17e854cbab0837ed0b43"
+dependencies = [
+ "unicode-xid",
+]
+
+[[package]]
+name = "quote"
+version = "1.0.10"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "38bc8cc6a5f2e3655e0899c1b848643b2562f853f114bfec7be120678e3ace05"
+dependencies = [
+ "proc-macro2",
+]
+
+[[package]]
+name = "ryu"
+version = "1.0.6"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "3c9613b5a66ab9ba26415184cfc41156594925a9cf3a2057e57f31ff145f6568"
+
+[[package]]
+name = "same-file"
+version = "1.0.6"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "93fc1dc3aaa9bfed95e02e6eadabb4baf7e3078b0bd1b4d7b6b0b68378900502"
+dependencies = [
+ "winapi-util",
+]
+
+[[package]]
+name = "serde"
+version = "1.0.130"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "f12d06de37cf59146fbdecab66aa99f9fe4f78722e3607577a5375d66bd0c913"
+dependencies = [
+ "serde_derive",
+]
+
+[[package]]
+name = "serde_derive"
+version = "1.0.130"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d7bc1a1ab1961464eae040d96713baa5a724a8152c1222492465b54322ec508b"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "syn",
+]
+
+[[package]]
+name = "serde_json"
+version = "1.0.72"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "d0ffa0837f2dfa6fb90868c2b5468cad482e175f7dad97e7421951e663f2b527"
+dependencies = [
+ "itoa",
+ "ryu",
+ "serde",
+]
+
+[[package]]
+name = "syn"
+version = "1.0.82"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8daf5dd0bb60cbd4137b1b587d2fc0ae729bc07cf01cd70b36a1ed5ade3b9d59"
+dependencies = [
+ "proc-macro2",
+ "quote",
+ "unicode-xid",
+]
+
+[[package]]
+name = "time"
+version = "0.1.44"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "6db9e6914ab8b1ae1c260a4ae7a49b6c5611b40328a735b21862567685e73255"
+dependencies = [
+ "libc",
+ "wasi",
+ "winapi",
+]
+
+[[package]]
+name = "unicode-xid"
+version = "0.2.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "8ccb82d61f80a663efe1f787a51b16b5a51e3314d6ac365b08639f52387b33f3"
+
+[[package]]
+name = "walkdir"
+version = "2.3.2"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "808cf2735cd4b6866113f648b791c6adc5714537bc222d9347bb203386ffda56"
+dependencies = [
+ "same-file",
+ "winapi",
+ "winapi-util",
+]
+
+[[package]]
+name = "wasi"
+version = "0.10.0+wasi-snapshot-preview1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "1a143597ca7c7793eff794def352d41792a93c481eb1042423ff7ff72ba2c31f"
+
+[[package]]
+name = "winapi"
+version = "0.3.9"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "5c839a674fcd7a98952e593242ea400abe93992746761e38641405d28b00f419"
+dependencies = [
+ "winapi-i686-pc-windows-gnu",
+ "winapi-x86_64-pc-windows-gnu",
+]
+
+[[package]]
+name = "winapi-i686-pc-windows-gnu"
+version = "0.4.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6"
+
+[[package]]
+name = "winapi-util"
+version = "0.1.5"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "70ec6ce85bb158151cae5e5c87f95a8e97d2c0c4b001223f33a334e3ce5de178"
+dependencies = [
+ "winapi",
+]
+
+[[package]]
+name = "winapi-x86_64-pc-windows-gnu"
+version = "0.4.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f"

test/interop/log_parsing/Cargo.toml

@@ -0,0 +1,10 @@
+[package]
+name = "log_parsing"
+version = "0.1.0"
+edition = "2018"
+
+[dependencies]
+serde = { version = "1.0", features = ["derive"] }
+serde_json = { version = "1.0" }
+chrono = { version = "0.4", features = ["serde"] }
+walkdir = "2"

test/interop/log_parsing/src/main.rs

@@ -0,0 +1,260 @@
+
+use chrono::{DateTime, Utc};
+use serde::{Deserialize, Serialize};
+use std::env;
+use std::error::Error;
+use std::fs::File;
+use std::io::{self, BufRead};
+use walkdir::WalkDir;
+
+
+// Applies schema tests to file input
+// if these fail, we either have a problem in dbt that needs to be resolved
+// or we have changed our interface and the log_version should be bumped in dbt,
+// modeled appropriately here, and publish new docs for the new log_version.
+fn main() -> Result<(), Box<dyn Error>> {
+    let log_name = "dbt.log";
+    let path = env::var("LOG_DIR").expect("must pass absolute log path to tests with env var `LOG_DIR=/logs/live/here/`");
+    
+    println!("Looking for files named `{}` in {}", log_name, path);
+    let lines: Vec<String> = get_input(&path, log_name)?;
+    println!("collected {} log lines.", lines.len());
+
+    println!("");
+
+    println!("testing type-level schema compliance by deserializing each line...");
+    let log_lines: Vec<LogLine> = deserialized_input(&lines)
+        .map_err(|e| format!("schema test failure: json doesn't match type definition\n{}", e))?;
+    println!("Done.");
+
+    println!("");
+    println!("because we skip non-json log lines, there are {} collected values to test.", log_lines.len());
+    println!("");
+
+    // make sure when we read a string in then output it back to a string the two strings
+    // contain all the same key-value pairs.
+    println!("testing serialization loop to make sure all key-value pairs are accounted for");
+    test_deserialize_serialize_is_unchanged(&lines);
+    println!("Done.");
+
+    println!("");
+
+    // make sure each log_line contains the values we expect
+    println!("testing that the field values in each log line are expected");
+    for log_line in log_lines {
+        log_line.value_test()
+    }
+    println!("Done.");
+
+    Ok(())
+}
+
+
+// each nested type of LogLine should define its own value_test function
+// that asserts values are within an expected set of values when possible.
+trait ValueTest {
+    fn value_test(&self) -> ();
+}
+
+#[derive(Serialize, Deserialize, Debug, Clone, PartialEq)]
+struct LogLine {
+    log_version: isize,
+    r#type: String,
+    code: String,
+    #[serde(with = "custom_date_format")]
+    ts: DateTime<Utc>,
+    pid: isize,
+    msg: String,
+    level: String,
+    invocation_id: String,
+    thread_name: String,
+    data: serde_json::Value,      // TODO be more specific
+    node_info: serde_json::Value, // TODO be more specific
+}
+
+impl ValueTest for LogLine {
+    fn value_test(&self){
+        assert_eq!(
+            self.log_version, 1,
+            "The log version changed. Be sure this was intentional."
+        );
+
+        assert_eq!(
+            self.r#type,
+            "log_line".to_owned(),
+            "The type value has changed. If this is intentional, bump the log version"
+        );
+
+        assert!(
+            ["debug", "info", "warn", "error"]
+                .iter()
+                .any(|level| **level == self.level),
+            "log level had unexpected value {}",
+            self.level
+        );
+    }
+}
+
+// logs output timestamps like this: "2021-11-30T12:31:04.312814Z"
+// which is so close to the default except for the decimal.
+// this requires handling the date with "%Y-%m-%dT%H:%M:%S%.6f" which requires this
+// boilerplate-looking module.
+mod custom_date_format {
+    use chrono::{NaiveDateTime, DateTime, Utc};
+    use serde::{self, Deserialize, Deserializer, Serializer};
+
+    const FORMAT: &'static str = "%Y-%m-%dT%H:%M:%S%.6fZ";
+
+    pub fn serialize<S>(date: &DateTime<Utc>, serializer: S) -> Result<S::Ok, S::Error>
+    where
+        S: Serializer,
+    {
+        let s = format!("{}", date.format(FORMAT));
+        serializer.serialize_str(&s)
+    }
+
+    pub fn deserialize<'de, D>(deserializer: D) -> Result<DateTime<Utc>, D::Error>
+    where
+        D: Deserializer<'de>,
+    {
+        let s = String::deserialize(deserializer)?;
+        Ok(DateTime::<Utc>::from_utc(NaiveDateTime::parse_from_str(&s, FORMAT).map_err(serde::de::Error::custom)?, Utc))
+    }
+}
+
+// finds all files in any subdirectory of this path with this name. returns the contents
+// of each file line by line as one continuous structure. No distinction between files.
+fn get_input(path: &str, file_name: &str) -> Result<Vec<String>, String> {
+    WalkDir::new(path)
+        .follow_links(true)
+        .into_iter()
+        // filters out all the exceptions encountered on this walk silently
+        .filter_map(|e| e.ok())
+        // walks through each file and returns the contents if the filename matches
+        .filter_map(|e| {
+            let f_name = e.file_name().to_string_lossy();
+            if f_name.ends_with(file_name) {
+                let contents = File::open(e.path())
+                    .map_err(|e| format!("Something went wrong opening the log file {}\n{}", f_name, e))
+                    .and_then(|file| {
+                        io::BufReader::new(file)
+                            .lines()
+                            .map(|l| {
+                                l.map_err(|e| format!("Something went wrong reading lines of the log file {}\n{}", f_name, e))
+                            })
+                            .collect::<Result<Vec<String>, String>>()
+                    });
+                    
+                Some(contents)
+            } else {
+                None
+            }
+        })
+        .collect::<Result<Vec<Vec<String>>, String>>()
+        .map(|vv| vv.concat())
+}
+
+// attemps to deserialize the strings into LogLines. If the string isn't valid
+// json it skips it instead of failing. This is so that any tests that generate
+// non-json logs won't break the schema test.
+fn deserialized_input(log_lines: &[String]) -> serde_json::Result<Vec<LogLine>> {
+    log_lines
+        .into_iter()
+        // if the log line isn't valid json format, toss it
+        .filter(|log_line| serde_json::from_str::<serde_json::Value>(log_line).is_ok())
+        // attempt to deserialize into our LogLine type
+        .map(|log_line| serde_json::from_str::<LogLine>(log_line))
+        .collect()
+}
+
+// turn a String into a LogLine and back into a String returning both Strings so
+// they can be compared
+fn deserialize_serialize_loop(
+    log_lines: &[String],
+) -> serde_json::Result<Vec<(String, String)>> {
+    log_lines
+        .into_iter()
+        .map(|log_line| {
+            serde_json::from_str::<LogLine>(log_line).and_then(|parsed| {
+                serde_json::to_string(&parsed).map(|json| (log_line.clone(), json))
+            })
+        })
+        .collect()
+}
+
+// make sure when we read a string in then output it back to a string the two strings
+// contain all the same key-value pairs.
+fn test_deserialize_serialize_is_unchanged(lines: &[String]) {
+    let objects: Result<Vec<(serde_json::Value, serde_json::Value)>, serde_json::Error> =
+        deserialize_serialize_loop(lines).and_then(|v| {
+            v.into_iter()
+                .map(|(s0, s1)| {
+                    serde_json::from_str::<serde_json::Value>(&s0).and_then(|s0v| {
+                        serde_json::from_str::<serde_json::Value>(&s1).map(|s1v| (s0v, s1v))
+                    })
+                })
+                .collect()
+        });
+
+    match objects {
+        Err(e) => assert!(false, "{}", e),
+        Ok(v) => {
+            for pair in v {
+                match pair {
+                    (
+                        serde_json::Value::Object(original),
+                        serde_json::Value::Object(looped),
+                    ) => {
+                        // looping through each key of each json value gives us meaningful failure messages
+                        // instead of "this big string" != "this other big string"
+                        for (key, value) in original.clone() {
+                            let looped_val = looped.get(&key);
+                            assert_eq!(
+                                looped_val,
+                                Some(&value),
+                                "original key value ({}, {}) expected in re-serialized result",
+                                key,
+                                value
+                            )
+                        }
+                        for (key, value) in looped.clone() {
+                            let original_val = original.get(&key);
+                            assert_eq!(
+                                original_val,
+                                Some(&value),
+                                "looped key value ({}, {}) not found in original result",
+                                key,
+                                value
+                            )
+                        }
+                    }
+                    _ => assert!(false, "not comparing json objects"),
+                }
+            }
+        }
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use crate::*;
+
+    const LOG_LINE: &str = r#"{"code": "Z023", "data": {"stats": {"error": 0, "pass": 3, "skip": 0, "total": 3, "warn": 0}}, "invocation_id": "f1e1557c-4f9d-4053-bb50-572cbbf2ca64", "level": "info", "log_version": 1, "msg": "Done. PASS=3 WARN=0 ERROR=0 SKIP=0 TOTAL=3", "node_info": {}, "pid": 75854, "thread_name": "MainThread", "ts": "2021-12-03T01:32:38.334601Z", "type": "log_line"}"#;
+
+    #[test]
+    fn test_basic_loop() {
+        assert!(deserialize_serialize_loop(&[LOG_LINE.to_owned()]).is_ok())
+    }
+
+    #[test]
+    fn test_values() {
+        assert!(deserialized_input(&[LOG_LINE.to_owned()]).map(|v| {
+            v.into_iter().map(|ll| ll.value_test())
+        }).is_ok())
+    }
+
+    #[test]
+    fn test_values_loop() {
+        test_deserialize_serialize_is_unchanged(&[LOG_LINE.to_owned()]);
+    }
+}

test/unit/test_agate_helper.py

@@ -154,3 +154,28 @@ class TestAgateHelper(unittest.TestCase):
 
         for i, row in enumerate(tbl):
             self.assertEqual(list(row), expected[i])
+
+    def test_nocast_bool_01(self):
+        # True and False values should not be cast to 1 and 0, and vice versa
+        # See: https://github.com/dbt-labs/dbt-core/issues/4511
+
+        column_names = ['a', 'b']
+        result_set = [
+            {'a': True, 'b': 1},
+            {'a': False, 'b': 0},
+        ]
+
+        tbl = agate_helper.table_from_data_flat(data=result_set, column_names=column_names)
+        self.assertEqual(len(tbl), len(result_set))
+
+        assert isinstance(tbl.column_types[0], agate.data_types.Boolean)
+        assert isinstance(tbl.column_types[1], agate.data_types.Number)
+
+        expected = [
+            [True, Decimal(1)],
+            [False, Decimal(0)],
+        ]
+
+        for i, row in enumerate(tbl):
+            self.assertEqual(list(row), expected[i])
+

test/unit/test_core_dbt_utils.py

@@ -1,4 +1,5 @@
 import requests
+import tarfile
 import unittest
 
 from dbt.exceptions import ConnectionException
@@ -22,11 +23,21 @@ class TestCoreDbtUtils(unittest.TestCase):
         connection_exception_retry(lambda: Counter._add_with_limited_exception(), 5)
         self.assertEqual(2, counter) # 2 = original attempt plus 1 retry
 
+    def test_connection_timeout(self):
+        Counter._reset()
+        connection_exception_retry(lambda: Counter._add_with_timeout(), 5)
+        self.assertEqual(2, counter) # 2 = original attempt plus 1 retry
+
     def test_connection_exception_retry_success_none_response(self):
         Counter._reset()
         connection_exception_retry(lambda: Counter._add_with_none_exception(), 5)
         self.assertEqual(2, counter) # 2 = original attempt returned None, plus 1 retry
 
+    def test_connection_exception_retry_success_failed_untar(self):
+        Counter._reset()
+        connection_exception_retry(lambda: Counter._add_with_untar_exception(), 5)
+        self.assertEqual(2, counter) # 2 = original attempt returned ReadError, plus 1 retry
+
 
 counter:int = 0 
 class Counter():
@@ -42,11 +53,21 @@ class Counter():
         counter+=1
         if counter < 2:
             raise requests.exceptions.ConnectionError
+    def _add_with_timeout():
+        global counter
+        counter+=1
+        if counter < 2:
+            raise requests.exceptions.Timeout
     def _add_with_none_exception():
         global counter
         counter+=1
         if counter < 2:
             raise requests.exceptions.ContentDecodingError
+    def _add_with_untar_exception():
+        global counter
+        counter+=1
+        if counter < 2:
+            raise tarfile.ReadError
     def _reset():
         global counter
         counter = 0

test/unit/test_events.py

@@ -1,19 +1,20 @@
-from dbt import events
-from dbt.events.functions import EVENT_HISTORY, fire_event
+
 from dbt.events.test_types import UnitTestInfo
 from argparse import Namespace
 from dbt.events import AdapterLogger
 from dbt.events.functions import event_to_serializable_dict
 from dbt.events.types import *
 from dbt.events.test_types import *
-from dbt.events.base_types import Event, Node
+from dbt.events.base_types import Event
 from dbt.events.stubs import _CachedRelation, BaseRelation, _ReferenceKey, ParsedModelNode
+from importlib import reload
+import dbt.events.functions as event_funcs
+import dbt.flags as flags
 import inspect
 import json
-import datetime
 from unittest import TestCase
 from dbt.contracts.graph.parsed import (
-    ParsedModelNode, NodeConfig, DependsOn, ParsedMacro
+    ParsedModelNode, NodeConfig, DependsOn
 )
 from dbt.contracts.files import FileHash
 
@@ -88,29 +89,29 @@ class TestEventCodes(TestCase):
 
 class TestEventBuffer(TestCase):
 
+    def setUp(self) -> None:
+        flags.EVENT_BUFFER_SIZE = 10
+        reload(event_funcs)
+
     # ensure events are populated to the buffer exactly once
     def test_buffer_populates(self):
-        fire_event(UnitTestInfo(msg="Test Event 1"))
-        fire_event(UnitTestInfo(msg="Test Event 2"))
+        event_funcs.fire_event(UnitTestInfo(msg="Test Event 1"))
+        event_funcs.fire_event(UnitTestInfo(msg="Test Event 2"))
         self.assertTrue(
-            EVENT_HISTORY.count(UnitTestInfo(msg='Test Event 1', code='T006')) == 1
+            event_funcs.EVENT_HISTORY.count(UnitTestInfo(msg='Test Event 1', code='T006')) == 1
         )
 
     # ensure events drop from the front of the buffer when buffer maxsize is reached
-    # TODO commenting out till we can make this not spit out 100k log lines.
-    # def test_buffer_FIFOs(self):
-    #     for n in range(0,100001):
-    #         fire_event(UnitTestInfo(msg=f"Test Event {n}"))
-    #     self.assertTrue(
-    #         EVENT_HISTORY.count(EventBufferFull(code='Z048')) == 1
-    #     )
-    #     self.assertTrue(
-    #         EVENT_HISTORY.count(UnitTestInfo(msg='Test Event 1', code='T006')) == 0
-    #     )
-
-def dump_callable():
-    return dict()
-    
+    def test_buffer_FIFOs(self):
+        for n in range(0,(flags.EVENT_BUFFER_SIZE + 1)):
+            event_funcs.fire_event(UnitTestInfo(msg=f"Test Event {n}"))
+        
+        self.assertTrue(
+            event_funcs.EVENT_HISTORY.count(EventBufferFull(code='Z048')) == 1
+        )
+        self.assertTrue(
+             event_funcs.EVENT_HISTORY.count(UnitTestInfo(msg='Test Event 1', code='T006')) == 0
+         )
 
 def MockNode():
     return ParsedModelNode(
@@ -195,8 +196,8 @@ sample_values = [
     SQLQueryStatus(status="", elapsed=0.1),
     SQLCommit(conn_name=""),
     ColTypeChange(orig_type="", new_type="", table=""),
-    SchemaCreation(relation=BaseRelation()),
-    SchemaDrop(relation=BaseRelation()),
+    SchemaCreation(relation=_ReferenceKey(database="", schema="", identifier="")),
+    SchemaDrop(relation=_ReferenceKey(database="", schema="", identifier="")),
     UncachedRelation(
         dep_key=_ReferenceKey(database="", schema="", identifier=""),
         ref_key=_ReferenceKey(database="", schema="", identifier=""),
@@ -205,7 +206,7 @@ sample_values = [
         dep_key=_ReferenceKey(database="", schema="", identifier=""),
         ref_key=_ReferenceKey(database="", schema="", identifier=""),
     ),
-    AddRelation(relation=_CachedRelation()),
+    AddRelation(relation=_ReferenceKey(database="", schema="", identifier="")),
     DropMissingRelation(relation=_ReferenceKey(database="", schema="", identifier="")),
     DropCascade(
         dropped=_ReferenceKey(database="", schema="", identifier=""),
@@ -221,21 +222,17 @@ sample_values = [
         old_key=_ReferenceKey(database="", schema="", identifier=""),
         new_key=_ReferenceKey(database="", schema="", identifier="")
     ),
-    DumpBeforeAddGraph(dump_callable),
-    DumpAfterAddGraph(dump_callable),
-    DumpBeforeRenameSchema(dump_callable),
-    DumpAfterRenameSchema(dump_callable),
+    DumpBeforeAddGraph(dict()),
+    DumpAfterAddGraph(dict()),
+    DumpBeforeRenameSchema(dict()),
+    DumpAfterRenameSchema(dict()),
     AdapterImportError(ModuleNotFoundError()),
     PluginLoadError(),
     SystemReportReturnCode(returncode=0),
-    SelectorAlertUpto3UnusedNodes(node_names=[]),
-    SelectorAlertAllUnusedNodes(node_names=[]),
     NewConnectionOpening(connection_state=''),
     TimingInfoCollected(),
     MergedFromState(nbr_merged=0, sample=[]),
     MissingProfileTarget(profile_name='', target_name=''),
-    ProfileLoadError(exc=Exception('')),
-    ProfileNotFound(profile_name=''),
     InvalidVarsYAML(),
     GenericTestFileParse(path=''),
     MacroFileParse(path=''),
@@ -275,8 +272,6 @@ sample_values = [
     PartialParsingDeletedExposure(unique_id=''),
     InvalidDisabledSourceInTestNode(msg=''),
     InvalidRefInTestNode(msg=''),
-    MessageHandleGenericException(build_path='', unique_id='', exc=Exception('')),
-    DetailsHandleGenericException(),
     RunningOperationCaughtError(exc=Exception('')),
     RunningOperationUncaughtError(exc=Exception('')),
     DbtProjectError(),
@@ -289,7 +284,7 @@ sample_values = [
     ProfileHelpMessage(),
     CatchableExceptionOnRun(exc=Exception('')),
     InternalExceptionOnRun(build_path='', exc=Exception('')),
-    GenericExceptionOnRun(build_path='', unique_id='', exc=Exception('')),
+    GenericExceptionOnRun(build_path='', unique_id='', exc=''),
     NodeConnectionReleaseError(node_name='', exc=Exception('')),
     CheckCleanPath(path=''),
     ConfirmCleanPath(path=''),
@@ -297,7 +292,7 @@ sample_values = [
     FinishedCleanPaths(),
     OpenCommand(open_cmd='', profiles_dir=''),
     DepsNoPackagesFound(),
-    DepsStartPackageInstall(package=''),
+    DepsStartPackageInstall(package_name=''),
     DepsInstallInfo(version_name=''),
     DepsUpdateAvailable(version_latest=''),
     DepsListSubdirectory(subdirectory=''),
@@ -359,7 +354,7 @@ sample_values = [
     NodeExecuting(unique_id='', report_node_data=MockNode()),
     NodeFinished(unique_id='', report_node_data=MockNode(), run_result=''),
     QueryCancelationUnsupported(type=''),
-    ConcurrencyLine(concurrency_line=''),
+    ConcurrencyLine(num_threads=0, target_name=''),
     StarterProjectPath(dir=''),
     ConfigFolderDirectory(dir=''),
     NoSampleProfileFound(adapter=''),
@@ -395,8 +390,6 @@ sample_values = [
     MainReportArgs(Namespace()),
     RegistryProgressMakingGETRequest(''),
     DepsUTD(),
-    CatchRunException('', Exception('')),
-    HandleInternalException(Exception('')),
     PartialParsingNotEnabled(),
     SQlRunnerException(Exception('')),
     DropRelation(''),
@@ -429,9 +422,40 @@ class TestEventJSONSerialization(TestCase):
 
         # if we have everything we need to test, try to serialize everything
         for event in sample_values:
-            d = event_to_serializable_dict(event, lambda dt: dt.isoformat(), lambda x: x.message())
+            d = event_to_serializable_dict(event, lambda _: event.get_ts_rfc3339(), lambda x: x.message())
             try:
                 json.dumps(d)
             except TypeError as e:
                 raise Exception(f"{event} is not serializable to json. Originating exception: {e}")
                 
+
+class TestConditionallyFiringEvents(TestCase):
+
+    # tests that fire_event_if only creates the event if the condition is met
+    def test_fire_event_if(self):
+
+        # this class exists to count how many times the stub is called
+        @dataclass
+        class DumpStub():
+            counter = 0
+
+            def dump_graph(self):
+                self.counter = self.counter + 1
+                return dict()
+
+        # initialize to start the counter at 0
+        dump_stub = DumpStub()
+
+        # becaue the condition is false, the event should never be created,
+        # and the stub function should never be called
+        event_funcs.fire_event_if(False, lambda: DumpAfterAddGraph(dump=dump_stub.dump_graph()))
+
+        # assert the stub function was never called
+        self.assertEqual(0, dump_stub.counter)
+
+        # becuase the condition is true, the event should be created and 
+        # the stub function will be called
+        event_funcs.fire_event_if(True, lambda: DumpAfterAddGraph(dump=dump_stub.dump_graph()))
+        
+        # assert that the stub function was called
+        self.assertEqual(1, dump_stub.counter)

test/unit/test_system_client.py

@@ -2,6 +2,9 @@ import os
 import shutil
 import stat
 import unittest
+import tarfile
+import io
+from pathlib import Path
 from tempfile import mkdtemp, NamedTemporaryFile
 
 from dbt.exceptions import ExecutableError, WorkingDirectoryError
@@ -185,3 +188,63 @@ class TestFindMatching(unittest.TestCase):
             shutil.rmtree(self.base_dir)
         except:
             pass
+
+
+class TestUntarPackage(unittest.TestCase):
+
+    def setUp(self):
+        self.base_dir = mkdtemp()
+        self.tempdir = mkdtemp(dir=self.base_dir)
+        self.tempdest = mkdtemp(dir=self.base_dir)
+    
+    def tearDown(self):
+        try:
+            shutil.rmtree(self.base_dir)
+        except:
+            pass
+
+    def test_untar_package_success(self):
+        #  set up a valid tarball to test against
+        with NamedTemporaryFile(
+            prefix='my-package.2', suffix='.tar.gz', dir=self.tempdir, delete=False
+        ) as named_tar_file:
+            tar_file_full_path = named_tar_file.name
+            with NamedTemporaryFile(
+                prefix='a', suffix='.txt', dir=self.tempdir
+            ) as file_a:
+                file_a.write(b'some text in the text file')
+                relative_file_a = os.path.basename(file_a.name)
+                with tarfile.open(fileobj=named_tar_file, mode='w:gz') as tar:
+                    tar.addfile(tarfile.TarInfo(relative_file_a), open(file_a.name))
+
+        #  now we test can test that we can untar the file successfully
+        assert tarfile.is_tarfile(tar.name)
+        dbt.clients.system.untar_package(tar_file_full_path, self.tempdest)
+        path = Path(os.path.join(self.tempdest, relative_file_a))
+        assert path.is_file()
+
+    def test_untar_package_failure(self):
+        #  create a text file then rename it as a tar (so it's invalid)
+        with NamedTemporaryFile(
+                prefix='a', suffix='.txt', dir=self.tempdir, delete=False
+            ) as file_a:
+                file_a.write(b'some text in the text file')
+                txt_file_name = file_a.name
+                file_path= os.path.dirname(txt_file_name)
+                tar_file_path = os.path.join(file_path, 'mypackage.2.tar.gz')
+        os.rename(txt_file_name, tar_file_path)
+
+        #  now that we're set up, test that untarring the file fails
+        with self.assertRaises(tarfile.ReadError) as exc:
+            dbt.clients.system.untar_package(tar_file_path, self.tempdest)
+
+    def test_untar_package_empty(self):
+        #  create a tarball with nothing in it
+        with NamedTemporaryFile(
+            prefix='my-empty-package.2', suffix='.tar.gz', dir=self.tempdir
+        ) as named_file:
+
+            #  make sure we throw an error for the empty file
+            with self.assertRaises(tarfile.ReadError) as exc:
+                dbt.clients.system.untar_package(named_file.name, self.tempdest)
+            self.assertEqual("empty file", str(exc.exception))

test/unit/utils.py

@@ -255,7 +255,7 @@ class TestAdapterConversions(TestCase):
             return agate.TimeDelta()
 
         for instance in agate_helper.DEFAULT_TYPE_TESTER._possible_types:
-            if type(instance) is column_type:
+            if isinstance(instance, column_type):  # include child types
                 return instance
 
         raise ValueError(f'no tester for {column_type}')