Dbt run returns ‘header info didn’t have x_token_server’ on expired access token
Opened this issue · 3 comments
nguyenann13 commented
Expected behavior
When running dbt commands, authenticating with OAuth and installed keyring...if the cached access token is expired, it should prompt for authentication again to refresh the token. Allowing the dbt command to run after.
Actual behavior
The dbt command fails with
14:36:51 Database Error in model dim_date (models\marts\common\dim_date.sql)
Error: header info didn't have x_token_server
Steps To Reproduce
- Configure dbt profile to use
method: oauth
- Install keyring with keyrings.cryptfile or keyrings.alt backend
- Run
dbt run
- Window pops up, authenticates successfully and dbt commands run
- Wait till access token expires
- Run
dbt run
again
Log output/Screenshots
PS C:\Projects\dbt\dbt-edl\edl> dbt run --select marts.common
14:24:01 Running with dbt=1.8.5
14:24:03 Registered adapter: trino=1.8.1
14:24:14 Found 31 models, 9 analyses, 1652 sources, 827 macros
14:24:14
14:25:07 Concurrency: 24 threads (target='developer_workdb')
14:25:07
14:25:07 1 of 1 START sql table model ann_workdb.dim_date ............................... [RUN]
14:25:35 1 of 1 OK created sql table model ann_workdb.dim_date .......................... [SUCCESS in 27.44s]
14:25:35
14:25:35 Finished running 1 table model in 0 hours 1 minutes and 20.07 seconds (80.07s).
14:25:35
14:25:35 Completed successfully
14:25:35
14:25:35 Done. PASS=1 WARN=0 ERROR=0 SKIP=0 TOTAL=1
PS C:\Projects\dbt\dbt-edl\edl> dbt run --select marts.common
14:36:23 Running with dbt=1.8.5
14:36:31 Found 31 models, 9 analyses, 1652 sources, 827 macros
14:36:31
14:36:41 Concurrency: 24 threads (target='developer_workdb')
14:36:41
14:36:41 1 of 1 START sql table model ann_workdb.dim_date ............................... [RUN]
14:36:50 1 of 1 ERROR creating sql table model ann_workdb.dim_date ...................... [ERROR in 8.88s]
14:36:50
14:36:50 Finished running 1 table model in 0 hours 0 minutes and 18.88 seconds (18.88s).
14:36:51
14:36:51 Completed with 1 error and 0 warnings:
14:36:51
14:36:51 Database Error in model dim_date (models\marts\common\dim_date.sql)
Error: header info didn't have x_token_server
compiled Code at target\run\enterprise_data_library\models\marts\common\dim_date.sql
14:36:51
14:36:51 Done. PASS=0 WARN=0 ERROR=1 SKIP=0 TOTAL=1
PS C:\Projects\dbt\dbt-edl\edl> dbt debug
14:41:50 Running with dbt=1.8.5
14:41:50 dbt version: 1.8.5
14:41:50 python version: 3.11.5
14:41:50 python path: C:\Projects\dbt\dbt-edl\edl\.venv\Scripts\python.exe
14:41:50 os info: Windows-10-10.0.19045-SP0
14:41:50 Using profiles dir at ./dbt_profile
14:41:50 Using profiles.yml file at ./dbt_profile\profiles.yml
14:41:50 Using dbt_project.yml file at C:\Projects\dbt\dbt-edl\edl\dbt_project.yml
14:41:50 adapter type: trino
14:41:50 adapter version: 1.8.1
14:41:50 Configuration:
14:41:50 profiles.yml file [OK found and valid]
14:41:50 dbt_project.yml file [OK found and valid]
14:41:50 Required dependencies:
14:41:50 - git [OK found]
14:41:50 Connection:
14:41:50 host: starburst.stage.com
14:41:50 port: 443
14:41:50 user: user@mail.com
14:41:50 database: sandbox
14:41:50 cert: None
14:41:50 prepared_statements_enabled: True
14:41:50 Registered adapter: trino=1.8.1
14:41:51 Connection test: [ERROR]
14:41:51 1 check failed:
14:41:51 dbt was unable to connect to the specified database.
The database returned the following error:
>Database Error
Error: header info didn't have x_token_server
Check your database credentials and try again. For more information, visit:
https://docs.getdbt.com/docs/configure-your-profile
Operating System
Microsoft Windows [Version 10.0.19045.4780]
dbt version
1.8.5
Trino Server version
449-e
Python version
3.11.5
Are you willing to submit PR?
- Yes I am willing to submit a PR!
hovaesco commented
Please send trino-python-client debug logs, which trino-python-client version are you using?
nguyenann13 commented
Please send trino-python-client debug logs, which trino-python-client version are you using?
I am using trino python client 0.329.0
============================== 09:41:50.149473 | e9cb1649-d9b4-43d5-9406-7fc81a7ec99f ==============================
�[0m09:41:50.149473 [info ] [MainThread]: Running with dbt=1.8.5
�[0m09:41:50.151806 [debug] [MainThread]: running dbt with arguments {'printer_width': '80', 'indirect_selection': 'eager', 'write_json': 'True', 'log_cache_events': 'False', 'partial_parse': 'True', 'cache_selected_only': 'False', 'profiles_dir': './dbt_profile', 'debug': 'False', 'version_check': 'True', 'log_path': 'C:\\Projects\\dbt\\dbt-edl\\edl\\logs', 'warn_error': 'None', 'fail_fast': 'False', 'use_colors': 'True', 'use_experimental_parser': 'False', 'no_print': 'None', 'quiet': 'False', 'empty': 'None', 'warn_error_options': 'WarnErrorOptions(include=[], exclude=[])', 'introspect': 'True', 'log_format': 'default', 'static_parser': 'True', 'target_path': 'None', 'invocation_command': 'dbt debug', 'send_anonymous_usage_stats': 'True'}
�[0m09:41:50.201872 [info ] [MainThread]: dbt version: 1.8.5
�[0m09:41:50.203451 [info ] [MainThread]: python version: 3.11.5
�[0m09:41:50.204306 [info ] [MainThread]: python path: C:\Projects\dbt\dbt-edl\edl\.venv\Scripts\python.exe
�[0m09:41:50.206569 [info ] [MainThread]: os info: Windows-10-10.0.19045-SP0
�[0m09:41:50.428748 [info ] [MainThread]: Using profiles dir at ./dbt_profile
�[0m09:41:50.431753 [info ] [MainThread]: Using profiles.yml file at ./dbt_profile\profiles.yml
�[0m09:41:50.433240 [info ] [MainThread]: Using dbt_project.yml file at C:\Projects\dbt\dbt-edl\edl\dbt_project.yml
�[0m09:41:50.434864 [info ] [MainThread]: adapter type: trino
�[0m09:41:50.436948 [info ] [MainThread]: adapter version: 1.8.1
�[0m09:41:50.581876 [info ] [MainThread]: Configuration:
�[0m09:41:50.582894 [info ] [MainThread]: profiles.yml file [�[32mOK found and valid�[0m]
�[0m09:41:50.584894 [info ] [MainThread]: dbt_project.yml file [�[32mOK found and valid�[0m]
�[0m09:41:50.586894 [info ] [MainThread]: Required dependencies:
�[0m09:41:50.587894 [debug] [MainThread]: Executing "git --help"
�[0m09:41:50.736629 [debug] [MainThread]: STDOUT: "b"usage: git [-v | --version] [-h | --help] [-C <path>] [-c <name>=<value>]\n [--exec-path[=<path>]] [--html-path] [--man-path] [--info-path]\n [-p | --paginate | -P | --no-pager] [--no-replace-objects] [--bare]\n [--git-dir=<path>] [--work-tree=<path>] [--namespace=<name>]\n [--config-env=<name>=<envvar>] <command> [<args>]\n\nThese are common Git commands used in various situations:\n\nstart a working area (see also: git help tutorial)\n clone Clone a repository into a new directory\n init Create an empty Git repository or reinitialize an existing one\n\nwork on the current change (see also: git help everyday)\n add Add file contents to the index\n mv Move or rename a file, a directory, or a symlink\n restore Restore working tree files\n rm Remove files from the working tree and from the index\n\nexamine the history and state (see also: git help revisions)\n bisect Use binary search to find the commit that introduced a bug\n diff Show changes between commits, commit and working tree, etc\n grep Print lines matching a pattern\n log Show commit logs\n show Show various types of objects\n status Show the working tree status\n\ngrow, mark and tweak your common history\n branch List, create, or delete branches\n commit Record changes to the repository\n merge Join two or more development histories together\n rebase Reapply commits on top of another base tip\n reset Reset current HEAD to the specified state\n switch Switch branches\n tag Create, list, delete or verify a tag object signed with GPG\n\ncollaborate (see also: git help workflows)\n fetch Download objects and refs from another repository\n pull Fetch from and integrate with another repository or a local branch\n push Update remote refs along with associated objects\n\n'git help -a' and 'git help -g' list available subcommands and some\nconcept guides. See 'git help <command>' or 'git help <concept>'\nto read about a specific subcommand or concept.\nSee 'git help git' for an overview of the system.\n""
�[0m09:41:50.739060 [debug] [MainThread]: STDERR: "b''"
�[0m09:41:50.740083 [info ] [MainThread]: - git [�[32mOK found�[0m]
�[0m09:41:50.742083 [info ] [MainThread]: Connection:
�[0m09:41:50.744039 [info ] [MainThread]: host: starburst.stage.com
�[0m09:41:50.746727 [info ] [MainThread]: port: 443
�[0m09:41:50.748452 [info ] [MainThread]: user: ann.nguyen@mail.com
�[0m09:41:50.754767 [info ] [MainThread]: database: sandbox
�[0m09:41:50.758848 [info ] [MainThread]: schema: ann_workdb
�[0m09:41:50.765369 [info ] [MainThread]: cert: None
�[0m09:41:50.767631 [info ] [MainThread]: prepared_statements_enabled: True
�[0m09:41:50.769652 [info ] [MainThread]: Registered adapter: trino=1.8.1
�[0m09:41:50.773706 [debug] [MainThread]: Acquiring new trino connection 'debug'
�[0m09:41:51.063770 [debug] [MainThread]: Using trino connection "debug"
�[0m09:41:51.064772 [debug] [MainThread]: On debug: select 1 as id
�[0m09:41:51.065272 [debug] [MainThread]: Opening a new connection, currently in state init
�[0m09:41:51.762080 [debug] [MainThread]: Trino adapter: Trino error: Error: header info didn't have x_token_server
�[0m09:41:51.764072 [debug] [MainThread]: On debug: Close
�[0m09:41:51.766080 [info ] [MainThread]: Connection test: [�[31mERROR�[0m]
�[0m09:41:51.768287 [info ] [MainThread]: �[31m1 check failed:�[0m
�[0m09:41:51.770993 [info ] [MainThread]: dbt was unable to connect to the specified database.
The database returned the following error:
>Database Error
Error: header info didn't have x_token_server
Check your database credentials and try again. For more information, visit:
https://docs.getdbt.com/docs/configure-your-profile
�[0m09:41:51.775182 [debug] [MainThread]: Command `dbt debug` failed at 09:41:51.774681 after 1.78 seconds
�[0m09:41:51.776186 [debug] [MainThread]: Connection 'debug' was properly closed.
�[0m09:41:51.777788 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001B8FC20CE10>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001B8FC1FA750>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001B8FC241510>]}
�[0m09:41:51.779343 [debug] [MainThread]: Flushing usage events
�[0m09:42:02.961817 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000026F5E2654D0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000026F5E2646D0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000026F5E264790>]}
JonMerlevede commented
As the underlying issue is with trino-python-client, I opened an issue there: trinodb/trino-python-client#484.