Dbt run returns ‘header info didn’t have x_token_server’ on expired access token

[nguyenann13]

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

1. Configure dbt profile to use method: oauth
2. Install keyring with keyrings.cryptfile or keyrings.alt backend
3. Run dbt run
4. Window pops up, authenticates successfully and dbt commands run
5. Wait till access token expires
6. 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: [email protected]
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]

Please send trino-python-client debug logs, which trino-python-client version are you using?

[nguyenann13]

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: [email protected]
�[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]

As the underlying issue is with trino-python-client, I opened an issue there: trinodb/trino-python-client#484.