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

A few final logging touch-ups #4388

Merged
merged 8 commits into from
Dec 2, 2021
Merged
Show file tree
Hide file tree
Changes from 7 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
6 changes: 3 additions & 3 deletions core/dbt/deprecations.py
Original file line number Diff line number Diff line change
Expand Up @@ -36,9 +36,9 @@ def show(self, *args, **kwargs) -> None:
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)

Expand All @@ -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}`.
Copy link
Member

Choose a reason for hiding this comment

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

Love the wording updates.

Please update your `dbt_project.yml` configuration to reflect this change.
'''

Expand Down
6 changes: 5 additions & 1 deletion core/dbt/events/functions.py
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@
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, Cache
from dbt.events.types import EventBufferFull, T_Event, MainReportVersion
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
Expand Down Expand Up @@ -203,6 +203,8 @@ def create_file_text_log_line(e: T_Event, msg_fn: Callable[[T_Event], str]) -> s
# 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:
if type(e) == EmptyLine:
return "" # 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)
Expand All @@ -222,6 +224,8 @@ def create_log_line(e: T_Event, msg_fn: Callable[[T_Event], str], file_output=Fa
# 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)
Expand Down
113 changes: 8 additions & 105 deletions core/dbt/events/types.py
Original file line number Diff line number Diff line change
Expand Up @@ -379,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):
Expand Down Expand Up @@ -860,67 +826,7 @@ 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


# 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)

# 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()
)

# 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
Expand Down Expand Up @@ -1564,7 +1470,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))


Expand Down Expand Up @@ -1681,7 +1587,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
Expand Down Expand Up @@ -1732,7 +1638,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)


Expand Down Expand Up @@ -2260,11 +2166,12 @@ def message(self) -> str:

@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
Expand Down Expand Up @@ -2625,8 +2532,6 @@ def message(self) -> str:
AdapterImportError(ModuleNotFoundError())
PluginLoadError()
SystemReportReturnCode(returncode=0)
SelectorAlertUpto3UnusedNodes(node_names=[])
SelectorAlertAllUnusedNodes(node_names=[])
NewConnectionOpening(connection_state='')
TimingInfoCollected()
MergedFromState(nbr_merged=0, sample=[])
Expand Down Expand Up @@ -2672,8 +2577,6 @@ def message(self) -> str:
PartialParsingDeletedExposure(unique_id='')
InvalidDisabledSourceInTestNode(msg='')
InvalidRefInTestNode(msg='')
MessageHandleGenericException(build_path='', unique_id='', exc=Exception(''))
DetailsHandleGenericException()
RunningOperationCaughtError(exc=Exception(''))
RunningOperationUncaughtError(exc=Exception(''))
DbtProjectError()
Expand Down Expand Up @@ -2869,7 +2772,7 @@ def message(self) -> str:
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='')
Expand Down
7 changes: 3 additions & 4 deletions core/dbt/parser/schemas.py
Original file line number Diff line number Diff line change
Expand Up @@ -960,10 +960,9 @@ def parse_patch(
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('://')
Expand Down
3 changes: 2 additions & 1 deletion core/dbt/task/deps.py
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@
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

Expand Down Expand Up @@ -81,6 +81,7 @@ def run(self):
source_type=source_type,
version=version)
if packages_to_upgrade:
fire_event(EmptyLine())
fire_event(DepsNotifyUpdatesAvailable(packages=packages_to_upgrade))

@classmethod
Expand Down
2 changes: 2 additions & 0 deletions core/dbt/task/printer.py
Original file line number Diff line number Diff line change
Expand Up @@ -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))


Expand Down
12 changes: 7 additions & 5 deletions core/dbt/task/runnable.py
Original file line number Diff line number Diff line change
Expand Up @@ -56,6 +56,7 @@
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'
Expand Down Expand Up @@ -377,10 +378,8 @@ def execute_nodes(self):
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())

Expand Down Expand Up @@ -461,8 +460,11 @@ def run(self):
)

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(),
Expand Down
4 changes: 3 additions & 1 deletion core/dbt/task/serve.py
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@
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

Expand All @@ -22,6 +22,8 @@ def run(self):

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
Expand Down
4 changes: 1 addition & 3 deletions core/dbt/ui.py
Original file line number Diff line number Diff line change
Expand Up @@ -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}'
Original file line number Diff line number Diff line change
Expand Up @@ -43,7 +43,7 @@ def test_postgres_data_path_fail(self):
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


Expand Down
8 changes: 1 addition & 7 deletions test/unit/test_events.py
Original file line number Diff line number Diff line change
Expand Up @@ -224,8 +224,6 @@ def MockNode():
AdapterImportError(ModuleNotFoundError()),
PluginLoadError(),
SystemReportReturnCode(returncode=0),
SelectorAlertUpto3UnusedNodes(node_names=[]),
SelectorAlertAllUnusedNodes(node_names=[]),
NewConnectionOpening(connection_state=''),
TimingInfoCollected(),
MergedFromState(nbr_merged=0, sample=[]),
Expand Down Expand Up @@ -271,8 +269,6 @@ def MockNode():
PartialParsingDeletedExposure(unique_id=''),
InvalidDisabledSourceInTestNode(msg=''),
InvalidRefInTestNode(msg=''),
MessageHandleGenericException(build_path='', unique_id='', exc=Exception('')),
DetailsHandleGenericException(),
RunningOperationCaughtError(exc=Exception('')),
RunningOperationUncaughtError(exc=Exception('')),
DbtProjectError(),
Expand Down Expand Up @@ -355,7 +351,7 @@ def MockNode():
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=''),
Expand Down Expand Up @@ -391,8 +387,6 @@ def MockNode():
MainReportArgs(Namespace()),
RegistryProgressMakingGETRequest(''),
DepsUTD(),
CatchRunException('', Exception('')),
HandleInternalException(Exception('')),
PartialParsingNotEnabled(),
SQlRunnerException(Exception('')),
DropRelation(''),
Expand Down