azure-workload-identity: Sidecar doesn't work properly for Microsoft ODBC Driver for SQL Server

Describe the bug I have a container that connect to a Azure Database using a User Managed Identity. It previously worked when using AAD Pod identity. I have tried enabling the sidecar (as I think the driver uses ADAL) and I can see in the logs that it make some calls but it somehow doesn’t work when it gets back to the container.

Steps To Reproduce

1: Create an appropriate image with ODBC driver and python:

FROM python:3.9.15-buster

RUN curl https://packages.microsoft.com/keys/microsoft.asc | apt-key add - \
&& curl https://packages.microsoft.com/config/debian/10/prod.list > /etc/apt/sources.list.d/mssql-release.list
RUN apt-get update && \
ACCEPT_EULA=Y apt-get install -y \
        msodbcsql17 \
        unixodbc-dev \
        mssql-tools 


ENV PATH="/opt/mssql-tools/bin:${PATH}"

RUN pip install sqlalchemy pyodbc
COPY script.py /script.py

where the script.py is:

from sqlalchemy import create_engine
import urllib
import os

server= os.getenv("SERVER")
uid = os.getenv("UID")
raw_params = (
"DRIVER={ODBC Driver 17 for SQL Server};"
f"SERVER={server};"
"Encrypt=yes;"
"TrustServerCertificate=no;"
"Connection Timeout=30;"
f"UID={uid};"
"Authentication=ActiveDirectoryMsi"
)
params = urllib.parse.quote_plus(raw_params)
connection_string = f"mssql+pyodbc:///?odbc_connect={params}"
engine = create_engine(connection_string)
engine.execute("select 1")

2: deploy to cluster with following yaml:

apiVersion: v1
kind: Pod
metadata:
  name: awli-test
  annotations:
    azure.workload.identity/inject-proxy-sidecar: "true"
spec:
  serviceAccountName: my-workload-identity
  containers:
  - args:
    - /bin/bash
    - -c
    - --
    - while true; do sleep 30; done;
    env:
      - name: SERVER
        value: URL_FOR_AZURE_SQL_SERVER
      - name: UID
        value: CLIENT_ID_FOR_USER_MANAGED_IDENITITY
    image: test-image:latest
    imagePullPolicy: IfNotPresent
    name: main
    resources:
      limits:
        cpu: "2"
        memory: 10G
      requests:
        cpu: 500m
        memory: 5G

Where URL_FOR_AZURE_SQL_SERVER, CLIENT_ID_FOR_USER_MANAGED_IDENITITY and test-image:latest are changed accordingly.

3: See logs before running script by running

~ kubectl logs  awli-test -c azwi-proxy
I1017 10:02:24.612091       1 proxy.go:96] proxy "msg"="starting the proxy server"  "port"=8000 "userAgent"="azure-workload-identity/proxy/v0.13.0 (linux/amd64) 46c5137/2022-08-31-23:38"
I1017 10:02:24.653617       1 proxy.go:167] proxy "msg"="received readyz request"  "method"="GET" "uri"="/readyz"

1. Exec into container, run script and wait for failure:

~ kubectl exec --stdin --tty awli-test -- /bin/bash
~ python script.py
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 3361, in _wrap_pool_connect
    return fn()
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 320, in connect
    return _ConnectionFairy._checkout(self)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 884, in _checkout
    fairy = _ConnectionRecord.checkout(pool)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 486, in checkout
    rec = pool._do_get()
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/impl.py", line 146, in _do_get
    self._dec_overflow()
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
    compat.raise_(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/util/compat.py", line 208, in raise_
    raise exception
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/impl.py", line 143, in _do_get
    return self._create_connection()
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 266, in _create_connection
    return _ConnectionRecord(self)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 381, in __init__
    self.__connect()
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 678, in __connect
    pool.logger.debug("Error on connect(): %s", e)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
    compat.raise_(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/util/compat.py", line 208, in raise_
    raise exception
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 673, in __connect
    self.dbapi_connection = connection = pool._invoke_creator(self)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/create.py", line 578, in connect
    return dialect.connect(*cargs, **cparams)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 598, in connect
    return self.dbapi.connect(*cargs, **cparams)
pyodbc.OperationalError: ('HYT00', '[HYT00] [unixODBC][Microsoft][ODBC Driver 17 for SQL Server]Login timeout expired (0) (SQLDriverConnect)')

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "//script.py", line 19, in <module>
    engine.execute("select 1")
  File "<string>", line 2, in execute
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/util/deprecations.py", line 402, in warned
    return fn(*args, **kwargs)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 3256, in execute
    connection = self.connect(close_with_result=True)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 3315, in connect
    return self._connection_cls(self, close_with_result=close_with_result)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 96, in __init__
    else engine.raw_connection()
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 3394, in raw_connection
    return self._wrap_pool_connect(self.pool.connect, _connection)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 3364, in _wrap_pool_connect
    Connection._handle_dbapi_exception_noconnection(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2198, in _handle_dbapi_exception_noconnection
    util.raise_(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/util/compat.py", line 208, in raise_
    raise exception
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 3361, in _wrap_pool_connect
    return fn()
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 320, in connect
    return _ConnectionFairy._checkout(self)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 884, in _checkout
    fairy = _ConnectionRecord.checkout(pool)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 486, in checkout
    rec = pool._do_get()
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/impl.py", line 146, in _do_get
    self._dec_overflow()
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
    compat.raise_(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/util/compat.py", line 208, in raise_
    raise exception
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/impl.py", line 143, in _do_get
    return self._create_connection()
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 266, in _create_connection
    return _ConnectionRecord(self)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 381, in __init__
    self.__connect()
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 678, in __connect
    pool.logger.debug("Error on connect(): %s", e)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
    compat.raise_(
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/util/compat.py", line 208, in raise_
    raise exception
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 673, in __connect
    self.dbapi_connection = connection = pool._invoke_creator(self)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/create.py", line 578, in connect
    return dialect.connect(*cargs, **cparams)
  File "/usr/local/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 598, in connect
    return self.dbapi.connect(*cargs, **cparams)
sqlalchemy.exc.OperationalError: (pyodbc.OperationalError) ('HYT00', '[HYT00] [unixODBC][Microsoft][ODBC Driver 17 for SQL Server]Login timeout expired (0) (SQLDriverConnect)')

1. Observe that in the logs from the azwi-proxy that calls where made to get a token. (I have changed the CLIENT_ID to something random)

kubectl logs -n prefect awli-test -c azwi-proxy
I1017 10:02:24.612091       1 proxy.go:96] proxy "msg"="starting the proxy server"  "port"=8000 "userAgent"="azure-workload-identity/proxy/v0.13.0 (linux/amd64) 46c5137/2022-08-31-23:38"
I1017 10:02:24.653617       1 proxy.go:167] proxy "msg"="received readyz request"  "method"="GET" "uri"="/readyz"
I1017 10:03:14.931967       1 proxy.go:101] proxy "msg"="received token request"  "method"="GET" "uri"="/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fdatabase.windows.net%2F&object_id=h869042n-6f42-5jg5-5g2f-48956645645f2"
I1017 10:03:15.432570       1 proxy.go:101] proxy "msg"="received token request"  "method"="GET" "uri"="/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fdatabase.windows.net%2F&object_id=h869042n-6f42-5jg5-5g2f-48956645645f"
I1017 10:03:16.433120       1 proxy.go:101] proxy "msg"="received token request"  "method"="GET" "uri"="/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fdatabase.windows.net%2F&object_id=h869042n-6f42-5jg5-5g2f-48956645645f"
I1017 10:03:18.433681       1 proxy.go:101] proxy "msg"="received token request"  "method"="GET" "uri"="/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fdatabase.windows.net%2F&object_id=h869042n-6f42-5jg5-5g2f-48956645645f"
I1017 10:03:33.455898       1 proxy.go:101] proxy "msg"="received token request"  "method"="GET" "uri"="/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fdatabase.windows.net%2F&object_id=h869042n-6f42-5jg5-5g2f-48956645645f"
I1017 10:03:33.956334       1 proxy.go:101] proxy "msg"="received token request"  "method"="GET" "uri"="/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fdatabase.windows.net%2F&object_id=h869042n-6f42-5jg5-5g2f-48956645645f"
I1017 10:03:34.956857       1 proxy.go:101] proxy "msg"="received token request"  "method"="GET" "uri"="/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fdatabase.windows.net%2F&object_id=h869042n-6f42-5jg5-5g2f-48956645645f"
I1017 10:03:36.957431       1 proxy.go:101] proxy "msg"="received token request"  "method"="GET" "uri"="/metadata/identity/oauth2/token?api-version=2018-02-01&resource=https%3A%2F%2Fdatabase.windows.net%2F&object_id=h869042n-6f42-5jg5-5g2f-48956645645f"

Expected behavior That the SQL query would have worked like it did for AAD Pod Identity

Logs See above

Environment

kubectl version
Client Version: version.Info{Major:"1", Minor:"22", GitVersion:"v1.22.4", GitCommit:"b695d79d4f967c403a96986f1750a35eb75e75f1", GitTreeState:"clean", BuildDate:"2021-11-17T15:48:33Z", GoVersion:"go1.16.10", Compiler:"gc", Platform:"windows/amd64"}
Server Version: version.Info{Major:"1", Minor:"22", GitVersion:"v1.22.15", GitCommit:"1d79bc3bcccfba7466c44cc2055d6e7442e140ea", GitTreeState:"clean", BuildDate:"2022-09-21T21:45:46Z", GoVersion:"go1.16.15", Compiler:"gc", Platform:"linux/amd64"}

• Kubernetes version (use kubectl version):
• Cloud provider or hardware configuration:
• OS (e.g: cat /etc/os-release):
• Kernel (e.g. uname -a):
• Install tools:
• Network plugin and version (if this is a network-related bug):
• Others:

Additional context