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

[CT-582] stdout colouring broken on dbt-core on Windows #5191

Closed
1 task done
marksabincarnivaluk opened this issue Apr 29, 2022 · 6 comments · Fixed by #5327
Closed
1 task done

[CT-582] stdout colouring broken on dbt-core on Windows #5191

marksabincarnivaluk opened this issue Apr 29, 2022 · 6 comments · Fixed by #5327
Labels
bug Something isn't working logging regression
Milestone

Comments

@marksabincarnivaluk
Copy link

Is there an existing issue for this?

  • I have searched the existing issues

Current Behavior

Red/green colouring is no longer visible in dbt v1.1 on Windows.
Instead we see unexpected characters such as [←[32mPASS←[0m in 0.82s]

Possibly caused by #4792

(dbt-env) C:\work\dbt-cuk>dbt test -m dim_booking
07:13:33 Running with dbt=1.1.0
07:13:35 Found 280 models, 593 tests, 1 snapshot, 0 analyses, 403 macros, 2 operations, 5 seed files, 388 sources, 0 exposures, 0 metrics
07:13:35
07:13:39 Concurrency: 4 threads (target='dev')
07:13:39
07:13:39 1 of 12 START test not_null_dim_booking_booking_id ............................. [RUN]
07:13:39 2 of 12 START test not_null_dim_booking_booking_ref ............................ [RUN]
07:13:39 3 of 12 START test not_null_dim_booking_booking_status_code .................... [RUN]
07:13:39 4 of 12 START test not_null_dim_booking_brand_code ............................. [RUN]
07:13:40 4 of 12 PASS not_null_dim_booking_brand_code ................................... [←[32mPASS←[0m in 1.28s]
07:13:40 5 of 12 START test not_null_dim_booking_cruise_code ............................ [RUN]
07:13:40 2 of 12 PASS not_null_dim_booking_booking_ref .................................. [←[32mPASS←[0m in 1.40s]
07:13:40 6 of 12 START test not_null_dim_booking_holiday_end_date ....................... [RUN]
07:13:40 3 of 12 PASS not_null_dim_booking_booking_status_code .......................... [←[32mPASS←[0m in 1.43s]
07:13:40 7 of 12 START test not_null_dim_booking_holiday_start_date ..................... [RUN]
07:13:41 1 of 12 PASS not_null_dim_booking_booking_id ................................... [←[32mPASS←[0m in 2.08s]
07:13:41 8 of 12 START test not_null_dim_booking_is_commercial_booking .................. [RUN]
07:13:41 5 of 12 PASS not_null_dim_booking_cruise_code .................................. [←[32mPASS←[0m in 0.89s]
07:13:41 9 of 12 START test not_null_dim_booking_logical_cruise_buskey .................. [RUN]
07:13:41 7 of 12 PASS not_null_dim_booking_holiday_start_date ........................... [←[32mPASS←[0m in 0.82s]
07:13:41 10 of 12 START test not_null_dim_booking_ship_code ............................. [RUN]
07:13:42 6 of 12 PASS not_null_dim_booking_holiday_end_date ............................. [←[32mPASS←[0m in 1.41s]
07:13:42 11 of 12 START test unique_dim_booking_booking_id .............................. [RUN]
07:13:42 8 of 12 PASS not_null_dim_booking_is_commercial_booking ........................ [←[32mPASS←[0m in 1.06s]
07:13:42 12 of 12 START test unique_dim_booking_booking_ref ............................. [RUN]
07:13:42 9 of 12 PASS not_null_dim_booking_logical_cruise_buskey ........................ [←[32mPASS←[0m in 1.01s]
07:13:43 11 of 12 PASS unique_dim_booking_booking_id .................................... [←[32mPASS←[0m in 0.89s]
07:13:43 12 of 12 PASS unique_dim_booking_booking_ref ................................... [←[32mPASS←[0m in 0.86s]
07:13:43 10 of 12 PASS not_null_dim_booking_ship_code ................................... [←[32mPASS←[0m in 1.89s]
07:13:43
07:13:43 Running 2 on-run-end hooks
07:13:43 1 of 2 START hook: cuk_project.on-run-end.0 .................................... [RUN]
07:13:45 1 of 2 OK hook: cuk_project.on-run-end.0 ....................................... [←[32mSUCCESS 1←[0m in 2.14s]
07:13:45 2 of 2 START hook: cuk_project.on-run-end.1 .................................... [RUN]
07:13:45 2 of 2 OK hook: cuk_project.on-run-end.1 ....................................... [←[32mSUCCESS 1←[0m in 0.12s]
07:13:45
07:13:46
07:13:46 Finished running 12 tests, 2 hooks in 10.20s.
07:13:46
07:13:46 ←[32mCompleted successfully←[0m
07:13:46
07:13:46 Done. PASS=12 WARN=0 ERROR=0 SKIP=0 TOTAL=12
07:13:51 Error sending message, disabling tracking

Expected Behavior

dbt v1.05 shows PASS/SUCCESS is green and FAIL in red.

07:24:28 Running with dbt=1.0.5
07:24:29 Unable to do partial parsing because of a dbt version mismatch. Saved manifest version: 1.1.0. Current version: 1.0.5.
07:24:38 Found 280 models, 593 tests, 1 snapshot, 0 analyses, 401 macros, 2 operations, 5 seed files, 388 sources, 0 exposures, 0 metrics
07:24:38
07:24:41 Concurrency: 4 threads (target='dev')
07:24:41
07:24:41 1 of 12 START test not_null_dim_booking_booking_id.............................. [RUN]
07:24:41 2 of 12 START test not_null_dim_booking_booking_ref............................. [RUN]
07:24:41 3 of 12 START test not_null_dim_booking_booking_status_code..................... [RUN]
07:24:41 4 of 12 START test not_null_dim_booking_brand_code.............................. [RUN]
07:24:42 1 of 12 PASS not_null_dim_booking_booking_id.................................... [PASS in 0.95s]
07:24:42 5 of 12 START test not_null_dim_booking_cruise_code............................. [RUN]
07:24:42 4 of 12 PASS not_null_dim_booking_brand_code.................................... [PASS in 1.06s]
07:24:42 6 of 12 START test not_null_dim_booking_holiday_end_date........................ [RUN]
07:24:42 3 of 12 PASS not_null_dim_booking_booking_status_code........................... [PASS in 1.10s]
07:24:42 7 of 12 START test not_null_dim_booking_holiday_start_date...................... [RUN]
07:24:42 2 of 12 PASS not_null_dim_booking_booking_ref................................... [PASS in 1.15s]
07:24:42 8 of 12 START test not_null_dim_booking_is_commercial_booking................... [RUN]
07:24:43 6 of 12 PASS not_null_dim_booking_holiday_end_date.............................. [PASS in 0.85s]
07:24:43 9 of 12 START test not_null_dim_booking_logical_cruise_buskey................... [RUN]
07:24:43 5 of 12 PASS not_null_dim_booking_cruise_code................................... [PASS in 1.18s]
07:24:43 10 of 12 START test not_null_dim_booking_ship_code.............................. [RUN]
07:24:43 7 of 12 PASS not_null_dim_booking_holiday_start_date............................ [PASS in 1.05s]
07:24:43 11 of 12 START test unique_dim_booking_booking_id............................... [RUN]
07:24:43 8 of 12 PASS not_null_dim_booking_is_commercial_booking......................... [PASS in 1.00s]
07:24:43 12 of 12 START test unique_dim_booking_booking_ref.............................. [RUN]
07:24:44 11 of 12 PASS unique_dim_booking_booking_id..................................... [PASS in 0.80s]
07:24:44 9 of 12 PASS not_null_dim_booking_logical_cruise_buskey......................... [PASS in 1.13s]
07:24:44 10 of 12 PASS not_null_dim_booking_ship_code.................................... [PASS in 0.95s]
07:24:44 12 of 12 PASS unique_dim_booking_booking_ref.................................... [PASS in 1.13s]
07:24:44
07:24:44 Running 2 on-run-end hooks
07:24:44 1 of 2 START hook: cuk_project.on-run-end.0..................................... [RUN]
07:24:47 1 of 2 OK hook: cuk_project.on-run-end.0........................................ [SUCCESS 1 in 2.53s]
07:24:47 2 of 2 START hook: cuk_project.on-run-end.1..................................... [RUN]
07:24:47 2 of 2 OK hook: cuk_project.on-run-end.1........................................ [SUCCESS 1 in 0.10s]
07:24:47
07:24:47
07:24:47 Finished running 12 tests, 2 hooks in 9.13s.
07:24:47
07:24:47 Completed successfully
07:24:47
07:24:47 Done. PASS=12 WARN=0 ERROR=0 SKIP=0 TOTAL=12
07:24:53 Error sending message, disabling tracking

Steps To Reproduce

On Windows, install dbt v1.1.0.
Run a command such as dbt test in the console.
Inspect output.

Relevant log output

No response

Environment

- OS:Windows
- Python:3.8.2
- dbt:v1.1.0

What database are you using dbt with?

snowflake

Additional Context

No response

@marksabincarnivaluk marksabincarnivaluk added bug Something isn't working triage labels Apr 29, 2022
@github-actions github-actions bot changed the title stdout colouring broken on dbt-core on Windows [CT-582] stdout colouring broken on dbt-core on Windows Apr 29, 2022
@jtcohen6
Copy link
Contributor

Possibly related to: #4443

@iknox-fa
Copy link
Contributor

Hi @marksabincarnivaluk, thanks for the bug ticket. Based on the output I'm seeing the correct color tags are there but they're being shown as raw text for some reason ([←[32m should be the correct windows color code for green).

Can you test your windows console by running this echo?
echo �[32mThis is green�[0m

@marksabincarnivaluk
Copy link
Author

marksabincarnivaluk commented Apr 30, 2022 via email

@marksabincarnivaluk
Copy link
Author

marksabincarnivaluk commented May 2, 2022

Hi,

I've found that these key sequences do result in colours at the command prompt:

echo Ctrl+[ [32m This is green Ctrl+[ [0m

or

echo alt 027 [32m This is green alt 027 [0m

Both Ctrl+[ and alt 027 produce the escape character.

Also in python, this works:

`import os
os.system("color") # Alternative - os.system("")

TCOLOR = "\033[31;3m"
ENDC = "\033[m"
print (TCOLOR + "This is red" + ENDC)`

I see you are using colorama.

The following code, based on dbt's logger.py, does give the colours as expected.
The PR #4792 altered logger.py so it no longer calls
colorama.init(wrap=True)

Although colorama.init(wrap=False) is subsequently called, it seems that it must be called first with wrap=True to make it work on Windows.

`import colorama
from colorama import Fore, Back, Style
import sys

# Remove the next 2 lines to break it
colorama_wrap = True
colorama.init(wrap=colorama_wrap)

if sys.platform == "win32" and not os.getenv("TERM"):
colorama_wrap = False
colorama_stdout = colorama.AnsiToWin32(sys.stdout).stream

colorama.init(wrap=False)

print(Fore.RED + 'some red text')
print(Back.GREEN + 'and with a green background')
print(Style.DIM + 'and in dim text')
print(Style.RESET_ALL)
print('back to normal now')`

@iknox-fa iknox-fa removed the triage label May 3, 2022
@iknox-fa
Copy link
Contributor

iknox-fa commented May 3, 2022

I've been able to confirm this is a bug in 1.1.0 on a windows machine. We'll get this prioritized ASAP @marksabincarnivaluk

@jtcohen6
Copy link
Contributor

jtcohen6 commented May 3, 2022

Wow, this is some weird code! Seems like a direct result of #4792:

Unless this statement has a side-effect or is being used externally, it appears to be deadcode

Sounds like we're talking about just such a side-effect?

@jtcohen6 jtcohen6 added this to the v1.1.1 milestone May 9, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working logging regression
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants