Indefinite Snowflake auth loop when using browser authentication

[eugene-nikolaev]

Describe the bug

We encounter indefinite auth loop while running dbt with browser auth enabled

Steps To Reproduce

Install dbt 0.17.2 and run anything on Snowflake

Expected behavior

Expected two auth requests in case of MFA and dbt proceeding to transform.
(non-MFA logins fail into the loop too)

Screenshots and log output

(dbt-transformations) <wiped out>@<wiped out> dbt-transformations % dbt run --models <wiped out>
Running with dbt=0.17.2
Found 129 models, 135 tests, 3 snapshots, 0 analyses, 140 macros, 0 operations, 1 seed file, 53 sources

Initiating login request with your identity provider. A browser window should have opened for you to complete the login. If you can't see it, check existing browser windows, or your OS settings. Press CTRL+C to abort and try again...
Initiating login request with your identity provider. A browser window should have opened for you to complete the login. If you can't see it, check existing browser windows, or your OS settings. Press CTRL+C to abort and try again...
Initiating login request with your identity provider. A browser window should have opened for you to complete the login. If you can't see it, check existing browser windows, or your OS settings. Press CTRL+C to abort and try again...
Initiating login request with your identity provider. A browser window should have opened for you to complete the login. If you can't see it, check existing browser windows, or your OS settings. Press CTRL+C to abort and try again...
Initiating login request with your identity provider. A browser window should have opened for you to complete the login. If you can't see it, check existing browser windows, or your OS settings. Press CTRL+C to abort and try again...
^C^C^Cctrl-c

System information

Which database are you using dbt with?

• postgres
• redshift
• bigquery
• snowflake
• other (specify: ____________)

The output of dbt --version:

installed version: 0.17.2
   latest version: 0.17.2

Up to date!

Plugins:
  - bigquery: 0.17.2
  - snowflake: 0.17.2
  - redshift: 0.17.2
  - postgres: 0.17.2

The operating system you're using:
MacOS 10.15.5 (19F101)

The output of python --version:
Python 3.7.7

Additional context

reverting dbt to 0.17.1 fixed the issue

[jtcohen6]

Hey @eugene-nikolaev, thanks for opening this issue.

Which MFA mechanism are you using for your Snowflake account? dbt connects to Snowflake via its python connector, which uses Duo Push by default. That's how I've done dbt CLI + Snowflake + MFA in the past.

It's helpful to know that reverting to v0.17.1 fixes the issue. We made two relevant changes in v0.17.2:

• add environment variables for logging #2635: added an env var (DBT_SNOWFLAKE_CONNECTOR_DEBUG_LOGGING) to turn on debug-level logging from Snowflake's python connector
• Fix: close connections after use #2650: close open Snowflake connections after using them

I'm guessing that the latter is at issue, and the former may help us troubleshoot what's going on.

[eugene-nikolaev]

@jtcohen6 thanks for reply.
Yes it is Duo Mobile for MFA.
However it isn't related to MFA in any way because other developer has the same without MFA.

[beckjake]

It's definitely going to be the latter. Fixing this is going to be a bit involved, unfortunately.

Instead of closing everything we'll have to go back to the old way of not calling close when the connection is open. Then we'll have to do something clever to make sure close gets called so we don't deadlock with the keepalive thread again. I'm not sure what that means happens to MFA if a model hits a connection-closing error on 0.17.1. Do we make you re-auth?

[jtcohen6]

@eugene-nikolaev Got it, I think your best bet for now is to use v0.17.1

@beckjake Let's pull this into v0.18.0, if possible

[eugene-nikolaev]

@jtcohen6, @beckjake, got it, thanks! Will wait.

[beckjake]

I think instead of reverting that change (which is still on the table, though I would rather avoid it) we may be able to fix this by implementing #2613. It appears to me that on Linux, the token cache is global to the executing user (in ~/.cache/snowflake/ by default). I think that would solve these issues pretty nicely, though of course you'd have to enable the token cache on the server. I'm not super clear on the mac/windows flow, it looks like it uses the os' "keyring" mechanism, whatever that is.

Is that a reasonable approach?

[tonyqiu2020]

@beckjake We still have the same issue after upgrading to 0.18. The latest working version is 0.17.1

[beckjake]

@tonyqiu2020 are you on windows/mac? Does pip install keyring fix it, by any chance?
And regardless of OS, you've set alter account set allow_id_token = true;, right?

[thillerdal]

@beckjake we have this issue as well (appeared when upgrading from 0.17.2 to 0.18.0). We're running okta, snowflake and a variety of pc and mac configs.

We first changed alter account set allow_id_token = true, but that did not help. pip install keyring, however, seems to fix the issue!

[tonyqiu2020]

pip install keyring fixed the issue.

[Plamen8780]

I followed the steps above but I still have this issue.

I'm using dbt 0.18.0 on Mac.
Installed keyring with pip install keyring
Executed alter account set allow_id_token = true on Snowflake

When I execute dbt run it just starts an infinite loop of authentications in Duo Mobile and I have to kill it.
Do I have to configure something in keyring?

[jtcohen6]

Hey @Plamen8780, I'm thinking that may be a different issue? The issue here is an infinite loop of externalbrowser authentication, whether the user has MFA turned on or not.

How many threads are you running dbt with against Snowflake? Last time I did this, I recall needing to authenticate in Duo Mobile once for each thread at the start of a run.

[Plamen8780]

@jtcohen6 , you are right it is slightly different - I'm using password authentication and I have MFA turned on but it still results in an infinite Duo authentication loop.
I'm using just one thread. I also tried clicking "Yes" in Duo at least 20 times before giving up.

I forgot to mention that I don't have this issue when running dbt debug. There I authenticate once and the execution finishes successfully.

In the meantime I've turned off MFA and everything works fine. But it will be nice to have the option to use dbt with MFA turned on.

[jtcohen6]

@Plamen8780 Got it. Could you try watching the dbt logs (e.g. tail -f logs/dbt.log) when you dbt run? I'd be curious to know if you're getting one Duo Push per metadata query that dbt is running, or if it is indeed an infinite loop not tied to any specific set of queries.

[Plamen8780]

@jtcohen6 , this is how the log looks like before I installed keyring:

2020-09-17 14:12:47.346320 (MainThread): Acquiring new snowflake connection "model.tide.latest_codes".
2020-09-17 14:12:47.346482 (MainThread): Opening a new connection, currently in state init
2020-09-17 14:12:47.379310 (MainThread): Acquiring new snowflake connection "model.tide.latest_code_usages".
2020-09-17 14:12:47.379451 (MainThread): Opening a new connection, currently in state init
2020-09-17 14:12:47.393309 (MainThread): Acquiring new snowflake connection "model.tide.latest_company_formations_users".
2020-09-17 14:12:47.393444 (MainThread): Opening a new connection, currently in state init
2020-09-17 14:12:47.406594 (MainThread): Acquiring new snowflake connection "model.tide.latest_company_formations_businesses".
2020-09-17 14:12:47.406734 (MainThread): Opening a new connection, currently in state init
2020-09-17 14:12:47.420416 (MainThread): Acquiring new snowflake connection "model.tide.latest_company_formations_applications".
2020-09-17 14:12:47.420574 (MainThread): Opening a new connection, currently in state init
2020-09-17 14:12:47.435721 (MainThread): Acquiring new snowflake connection "model.tide.latest_virtual_address_usage".
2020-09-17 14:12:47.435854 (MainThread): Opening a new connection, currently in state init
...

And this is after keyring:

2020-09-17 17:46:50.545057 (MainThread): Acquiring new snowflake connection "model.tide.latest_codes".
2020-09-17 17:46:50.571224 (MainThread): Acquiring new snowflake connection "model.tide.latest_code_usages".
2020-09-17 17:46:50.585056 (MainThread): Acquiring new snowflake connection "model.tide.latest_company_formations_users".
2020-09-17 17:46:50.598730 (MainThread): Acquiring new snowflake connection "model.tide.latest_company_formations_businesses".
2020-09-17 17:46:50.612737 (MainThread): Acquiring new snowflake connection "model.tide.latest_company_formations_applications".
2020-09-17 17:46:50.627212 (MainThread): Acquiring new snowflake connection "model.tide.latest_virtual_address_usage".
...

So it seems like it tries to acquire connection for each model. But not sure why keyring doesn't work here.

[jtcohen6]

@Plamen8780 When are you seeing the Duo pushes? Is it before/after every single one of those Acquiring new snowflake connection? Or a completely unrelated phenomenon?

[feluelle]

The issues is not fixed @jtcohen6. We are still facing it and probably will use a different auth method then. :/

cc @pecigonzalo

[jtcohen6]

@feluelle Are you using the latest versions of dbt-snowflake and snowflake-connector-python, with keyring installed?

[feluelle]

Yes, I am using the latest version of all three. But it might be still related to the connector and has nothing to do with dbt. See snowflakedb/snowflake-connector-python#349 WDYT Jeremy? :)

[JudyCamps]

I am experiencing this issue in dbt 1.1.0 with Snowflake and OKTA on a macbook.
The terminal window says
Initiating login request with your identity provider. A browser window should have opened for you to complete the login. If you can't see it, check existing browser windows, or your OS settings. Press CTRL+C to abort and try again...
It keeps opening browser windows that say "Your identity was confirmed and propagated to Snowflake dbt. You can close this window now and go back where you started from."

So it seems OKTA is returning the token but dbt core is not accepting it. I have keyring installed.

[joaopmoniz]

I have the same as @JudyCamps, very similar environment.
I am using Mac, dbt core 1.1.1 and snowflake plugin 1.1.0. I already have the keyring installed, and we've set the alter account set allow_id_token = true on Snowflake with the externalbrowser config on the profile. Same problem as above.

[HorvathDanielMarton]

I experience the same problem as well on Rosetta terminal. Installed dbt-snowflake via Homebrew.

Core:
  - installed: 1.3.0
  - latest:    1.3.0 - Up to date!

Plugins:
  - snowflake: 1.3.0 - Up to date!

python3 --version
Python 3.9.6

[ubblechristophe]

Hi there!
I experience the same problem, any updates on that matter?

[leahwicz]

We have an open issue specifically for this in the Snowflake repo here with some solutions on how people unblocked themselves

dbt-labs/dbt-snowflake#208