Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Feature/logbook structured rpc logging (#1703, #1704) #1715

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 9 additions & 0 deletions core/dbt/adapters/factory.py
Original file line number Diff line number Diff line change
Expand Up @@ -84,3 +84,12 @@ def reset_adapters():
for adapter in _ADAPTERS.values():
adapter.cleanup_connections()
_ADAPTERS.clear()


def cleanup_connections():
"""Only clean up the adapter connections list without resetting the actual
adapters.
"""
with _ADAPTER_LOCK:
for adapter in _ADAPTERS.values():
adapter.cleanup_connections()
22 changes: 17 additions & 5 deletions core/dbt/adapters/sql/connections.py
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,10 @@ def cancel_open(self):
if connection is this_connection:
continue

self.cancel(connection)
# if the connection failed, the handle will be None so we have
# nothing to cancel.
if connection.handle is not None:
self.cancel(connection)
names.append(connection.name)
return names

Expand All @@ -50,16 +53,25 @@ def add_query(self, sql, auto_begin=True, bindings=None,

with self.exception_handler(sql):
if abridge_sql_log:
logger.debug('On %s: %s....', connection.name, sql[0:512])
log_sql = '{}...'.format(sql[:512])
else:
logger.debug('On %s: %s', connection.name, sql)
log_sql = sql

logger.debug(
'On {connection_name}: {sql}',
connection_name=connection.name,
sql=log_sql,
)
pre = time.time()

cursor = connection.handle.cursor()
cursor.execute(sql, bindings)

logger.debug("SQL status: %s in %0.2f seconds",
self.get_status(cursor), (time.time() - pre))
logger.debug(
"SQL status: {status} in {elapsed:0.2f} seconds",
status=self.get_status(cursor),
elapsed=(time.time() - pre)
)

return connection, cursor

Expand Down
6 changes: 3 additions & 3 deletions core/dbt/adapters/sql/impl.py
Original file line number Diff line number Diff line change
Expand Up @@ -99,7 +99,7 @@ def expand_column_types(self, goal, current):
target_column.can_expand_to(reference_column):
col_string_size = reference_column.string_size()
new_type = self.Column.string_type(col_string_size)
logger.debug("Changing col type from %s to %s in table %s",
logger.debug("Changing col type from {} to {} in table {}",
target_column.data_type, new_type, current)

self.alter_column_type(current, column_name, new_type)
Expand Down Expand Up @@ -157,7 +157,7 @@ def get_columns_in_relation(self, relation):
)

def create_schema(self, database, schema):
logger.debug('Creating schema "%s"."%s".', database, schema)
logger.debug('Creating schema "{}"."{}".', database, schema)
kwargs = {
'database_name': self.quote_as_configured(database, 'database'),
'schema_name': self.quote_as_configured(schema, 'schema'),
Expand All @@ -166,7 +166,7 @@ def create_schema(self, database, schema):
self.commit_if_has_connection()

def drop_schema(self, database, schema):
logger.debug('Dropping schema "%s"."%s".', database, schema)
logger.debug('Dropping schema "{}"."{}".', database, schema)
kwargs = {
'database_name': self.quote_as_configured(database, 'database'),
'schema_name': self.quote_as_configured(schema, 'schema'),
Expand Down
10 changes: 5 additions & 5 deletions core/dbt/clients/git.py
Original file line number Diff line number Diff line change
Expand Up @@ -81,21 +81,21 @@ def clone_and_checkout(repo, cwd, dirname=None, remove_git_dir=False,
start_sha = None
if exists:
directory = exists.group(1)
logger.debug('Updating existing dependency %s.', directory)
logger.debug('Updating existing dependency {}.', directory)
else:
matches = re.match("Cloning into '(.+)'", err.decode('utf-8'))
directory = matches.group(1)
logger.debug('Pulling new dependency %s.', directory)
logger.debug('Pulling new dependency {}.', directory)
full_path = os.path.join(cwd, directory)
start_sha = get_current_sha(full_path)
checkout(full_path, repo, branch)
end_sha = get_current_sha(full_path)
if exists:
if start_sha == end_sha:
logger.debug(' Already at %s, nothing to do.', start_sha[:7])
logger.debug(' Already at {}, nothing to do.', start_sha[:7])
else:
logger.debug(' Updated checkout from %s to %s.',
logger.debug(' Updated checkout from {} to {}.',
start_sha[:7], end_sha[:7])
else:
logger.debug(' Checked out at %s.', end_sha[:7])
logger.debug(' Checked out at {}.', end_sha[:7])
return directory
2 changes: 1 addition & 1 deletion core/dbt/compilation.py
Original file line number Diff line number Diff line change
Expand Up @@ -50,7 +50,7 @@ def print_compile_stats(stats):
stat_line = ", ".join(
[dbt.utils.pluralize(ct, names.get(t)) for t, ct in results.items()])

logger.notice("Found {}".format(stat_line))
logger.info("Found {}".format(stat_line))


def _add_prepended_cte(prepended_ctes, new_cte):
Expand Down
Loading