search

Azure / login

Connect to Azure
MIT License
318 stars 297 forks source link

azure/login@v2 action in workflow just runs and never completes on pre login using private networking with GitHub-hosted runner #439

Closed stan-spotts closed 7 months ago

stan-spotts commented 7 months ago

Following directions at Configuring private networking for GitHub-hosted runners in your organization, I manually kicked off a workflow to push a set of services in node.js to an image in an azure container registry. It won't get past a "pre login" step (that it adds itself). Raw logs say the job is about to start. It appears the configuration is okay, as NIC's from GitHub appear in my resource group.

The workflow up to this point is simply this:

on: 
    workflow_dispatch:
    #[push]
name: Linux_Container_Workflow

jobs:
    build-and-deploy:
        runs-on: LinuxRunner

        steps:
        - name: Log Runner Group
          run: |
            echo "Runner group used: ${{ matrix.runner-group }}"

It just spins at this point :

Run azure/login@v2
  with:
    creds: ***
    enable-AzPSSession: false
    environment: azurecloud
    allow-no-subscriptions: false
    audience: api://AzureADTokenExchange
    auth-type: SERVICE_PRINCIPAL
Clearing azure cli accounts from the local cache.
/usr/bin/az account clear
MoChilia commented 7 months ago

Hi @stan-spotts, could you share the logging information for the pre login step with debug logging enabled?

stan-spotts commented 7 months ago

I set up the action debug logging and I'm watching it run now. It gave me this, and is spinning on the "Pre Login via Azure CLI" step but isn't showing any details yet for the step - and it's been about 4 minutes.

##[debug]Starting: Set up job
Current runner version: '[2](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8868576194/job/24348299327#step:1:2).316.0'
Runner name: 'LinuxRunner_8cd4ae69529e'
Runner group name: 'githubazurerunners'
Machine name: 'runner'
Operating System
Runner Image
GITHUB_TOKEN Permissions
Secret source: Actions
##[debug]Primary repository: CGFNSOrg/IntegrationAPI
Prepare workflow directory
##[debug]Creating pipeline directory: '/home/runner/work/IntegrationAPI'
##[debug]Creating workspace directory: '/home/runner/work/IntegrationAPI/IntegrationAPI'
##[debug]Update context data
##[debug]Evaluating job-level environment variables
##[debug]Evaluating job container
##[debug]Evaluating job service containers
##[debug]Evaluating job defaults
Prepare all required actions
Getting action download info
Download action repository 'actions/checkout@main' (SHA:8459bc0c7e[3](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8868576194/job/24348299327#step:1:3)759cdf591f513d9f141a95fef0a8f)
##[debug]Download 'https://api.github.com/repos/actions/checkout/tarball/8[4](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8868576194/job/24348299327#step:1:4)59bc0c7e3759cdf591f513d9f141a95fef0a8f' to '/home/runner/work/_actions/_temp_a30e[5](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8868576194/job/24348299327#step:1:5)462-14bb-412c-bba2-b4d4[6](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8868576194/job/24348299327#step:1:6)6c4fa30/6c7f1333-6eca-4b21-b491-c7b0604e7edc.tar.gz'
##[debug]Unwrap 'actions-checkout-8459bc0' to '/home/runner/work/_actions/actions/checkout/main'
##[debug]Archive '/home/runner/work/_actions/_temp_a30e5462-14bb-412c-bba2-b4d466c4fa30/6c7f1333-6eca-4b21-b491-c7b0604e7edc.tar.gz' has been unzipped into '/home/runner/work/_actions/actions/checkout/main'.
Download action repository 'azure/login@v2' (SHA:6b2456866fc08b011acb422a92a4aa20e2c4de32)
##[debug]Download 'https://api.github.com/repos/Azure/login/tarball/6b2456866fc08b011acb422a92a4aa20e2c4de32' to '/home/runner/work/_actions/_temp_af23753b-b5d8-4f8f-8962-8721faa8c64b/475cb27c-98bb-4f05-9296-ed93dd33d46f.tar.gz'
##[debug]Unwrap 'Azure-login-6b24568' to '/home/runner/work/_actions/azure/login/v2'
##[debug]Archive '/home/runner/work/_actions/_temp_af23753b-b5d8-4f8f-8962-8721faa8c64b/475cb27c-98bb-4f05-9296-ed93dd33d46f.tar.gz' has been unzipped into '/home/runner/work/_actions/azure/login/v2'.
Download action repository 'docker/login-action@v3' (SHA:e92390c5fb421da1463c202d546fed0ec5c39f20)
##[debug]Download 'https://api.github.com/repos/docker/login-action/tarball/e92390c5fb421da1463c202d546fed0ec5c39f20' to '/home/runner/work/_actions/_temp_d39c5b66-5237-49b1-b8fd-1896ea05ccc6/f1f62631-6e8a-45ee-a42e-54cf003dfc53.tar.gz'
##[debug]Unwrap 'docker-login-action-e92390c' to '/home/runner/work/_actions/docker/login-action/v3'
##[debug]Archive '/home/runner/work/_actions/_temp_d39c5b66-5237-49b1-b8fd-1896ea05ccc6/f1f62631-6e8a-45ee-a42e-54cf003dfc53.tar.gz' has been unzipped into '/home/runner/work/_actions/docker/login-action/v3'.
Download action repository 'azure/aci-deploy@v1' (SHA:28cafb864979bc5b44cd1f3fd45522727eb5a3db)
##[debug]Download 'https://api.github.com/repos/Azure/aci-deploy/tarball/28cafb864979bc5b44cd1f3fd45522727eb5a3db' to '/home/runner/work/_actions/_temp_a7e233a2-d253-4df7-a974-61a876a5c562/a06c5212-c0c0-4a81-aa77-[10](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8868576194/job/24348299327#step:1:11)a486452b3b.tar.gz'
##[debug]Unwrap 'Azure-aci-deploy-28cafb8' to '/home/runner/work/_actions/azure/aci-deploy/v1'
##[debug]Archive '/home/runner/work/_actions/_temp_a7e233a2-d253-4df7-a974-61a876a5c562/a06c5[21](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8868576194/job/24348299327#step:1:24)2-c0c0-4a81-aa77-10a486452b3b.tar.gz' has been unzipped into '/home/runner/work/_actions/azure/aci-deploy/v1'.
##[debug]action.yml for action: '/home/runner/work/_actions/actions/checkout/main/action.yml'.
##[debug]action.yml for action: '/home/runner/work/_actions/azure/login/v2/action.yml'.
##[debug]action.yml for action: '/home/runner/work/_actions/docker/login-action/v3/action.yml'.
##[debug]action.yml for action: '/home/runner/work/_actions/azure/aci-deploy/v1/action.yml'.
##[debug]Set step '__run' display name to: 'Log Runner Group'
##[debug]Set step '__actions_checkout' display name to: 'Checkout GitHub Action'
##[debug]Set step '__azure_login' display name to: 'Login via Azure CLI'
##[debug]Set step '__azure_login' display name to: 'Login via Azure CLI'
##[debug]Set step '__docker_login-action' display name to: 'Build and push image'
##[debug]Set step '__run_2' display name to: 'Run docker build . -t $*** secrets.REGISTRY_LOGIN_SERVER ***/integrationAPI:$*** github.sha ***'
##[debug]Set step '__azure_aci-deploy' display name to: 'Deploy to Azure Container Instances'
Complete job name: build-and-deploy
##[debug]Collect running processes for tracking orphan processes.
##[debug]Finishing: Set up job

image

I cancelled the workflow after it sat here for 4+ minutes, and this followed:

##[debug]Evaluating condition for step: 'Pre Login via Azure CLI'
##[debug]Evaluating: always()
##[debug]Evaluating always:
##[debug]=> true
##[debug]Result: true
##[debug]Starting: Pre Login via Azure CLI
##[debug]Register post job cleanup for action: azure/login@v[2](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8868576194/job/24348299327#step:2:2)
##[debug]Loading inputs
##[debug]Evaluating: secrets.AZURE_CREDENTIALS
##[debug]Evaluating Index:
##[debug]..Evaluating secrets:
##[debug]..=> Object
##[debug]..Evaluating String:
##[debug]..=> 'AZURE_CREDENTIALS'
##[debug]=> '*** 
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]***'
##[debug]Result: '*** 
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]***'
##[debug]Loading env
Run azure/login@v2
  with:
    creds: ***
    enable-AzPSSession: false
    environment: azurecloud
    allow-no-subscriptions: false
    audience: api://AzureADTokenExchange
    auth-type: SERVICE_PRINCIPAL
##[debug]Azure CLI path: /usr/bin/az
Clearing azure cli accounts from the local cache.
/usr/bin/az account clear
##[debug]Re-evaluate condition on job cancellation for step: 'Pre Login via Azure CLI'.

But it's still running after 10 minutes. It seems to take a while to cancel, sometimes I cancel several times before it "takes."

Runner logging was also enabled, log is here: 1_Set up job.txt

MoChilia commented 7 months ago

@stan-spotts, could you temporarily try using azure/login@1.5.1 to see if azure/login without pre step works for you?

stan-spotts commented 7 months ago

Interesting. It got further, faster, but still didn't get to the Build and push image step that's after the azure/login step. It's been spinning after this for a few minutes now:

##[debug]Evaluating condition for step: 'Login via Azure CLI'
##[debug]Evaluating: success()
##[debug]Evaluating success:
##[debug]=> true
##[debug]Result: true
##[debug]Starting: Login via Azure CLI
##[debug]Loading inputs
##[debug]Evaluating: secrets.AZURE_CREDENTIALS
##[debug]Evaluating Index:
##[debug]..Evaluating secrets:
##[debug]..=> Object
##[debug]..Evaluating String:
##[debug]..=> 'AZURE_CREDENTIALS'
##[debug]=> '*** 
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]***'
##[debug]Result: '*** 
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]***'
##[debug]Loading env
Run azure/login@v1.5.1
  with:
    creds: ***
    enable-AzPSSession: false
    environment: azurecloud
    allow-no-subscriptions: false
    audience: api://AzureADTokenExchange
    auth-type: SERVICE_PRINCIPAL
##[debug]Reading creds in JSON...
::add-mask::***
::add-mask::***
Running Azure CLI Login.
##[debug]Azure CLI path: /usr/bin/az
##[debug]Azure CLI version used:
##[debug]azure-cli                         [2](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8872666720/job/24357341853#step:4:2).59.0
##[debug]
##[debug]core                              2.59.0
##[debug]telemetry                          1.1.0
##[debug]
##[debug]Extensions:
##[debug]azure-devops                       1.0.0
##[debug]
##[debug]Dependencies:
##[debug]msal                              1.27.0
##[debug]azure-mgmt-resource             2[3](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8872666720/job/24357341853#step:4:3).1.0b2
##[debug]
##[debug]Python location '/opt/az/bin/python3'
##[debug]Extensions directory '/opt/az/azcliextensions'
##[debug]
##[debug]Python (Linux) 3.11.8 (main, Mar 27 202[4](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8872666720/job/24357341853#step:4:4), 04:03:04) [GCC 11.4.0]
##[debug]
##[debug]Legal docs and information: aka.ms/AzureCliLegal
##[debug]
##[debug]
##[debug]Your CLI is up-to-date.
##[debug]

I waited about 4 minutes and cancelled, after which I saw this:

##[debug]
##[debug]Re-evaluate condition on job cancellation for step: 'Login via Azure CLI'.
##[debug]AZURE_HTTP_USER_AGENT='GITHUBACTIONS/AzureLogin@v1_CGFNSOrg/IntegrationAPI'
##[debug]AZUREPS_HOST_ENVIRONMENT='GITHUBACTIONS/AzureLogin@v1_CGFNSOrg/IntegrationAPI'
Error: The operation was canceled.
##[debug]System.OperationCanceledException: The operation was canceled.
##[debug]   at System.Threading.CancellationToken.ThrowOperationCanceledException()
##[debug]   at GitHub.Runner.Sdk.ProcessInvoker.ExecuteAsync(String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, Channel`1 redirectStandardIn, Boolean inheritConsoleHandler, Boolean keepStandardInOpen, Boolean highPriorityProcess, CancellationToken cancellationToken)
##[debug]   at GitHub.Runner.Common.ProcessInvokerWrapper.ExecuteAsync(String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, Channel`1 redirectStandardIn, Boolean inheritConsoleHandler, Boolean keepStandardInOpen, Boolean highPriorityProcess, CancellationToken cancellationToken)
##[debug]   at GitHub.Runner.Worker.Handlers.DefaultStepHost.ExecuteAsync(IExecutionContext context, String workingDirectory, String fileName, String arguments, IDictionary`2 environment, Boolean requireExitCodeZero, Encoding outputEncoding, Boolean killProcessOnCancel, Boolean inheritConsoleHandler, String standardInInput, CancellationToken cancellationToken)
##[debug]   at GitHub.Runner.Worker.Handlers.NodeScriptActionHandler.RunAsync(ActionRunStage stage)
##[debug]   at GitHub.Runner.Worker.ActionRunner.RunAsync()
##[debug]   at GitHub.Runner.Worker.StepsRunner.RunStepAsync(IStep step, CancellationToken jobCancellationToken)
##[debug]Finishing: Login via Azure CLI

The entire workflow is this:

on: 
    workflow_dispatch:
    #[push]
name: Linux_Container_Workflow

jobs:
    build-and-deploy:
        runs-on: LinuxRunner

        steps:
        - name: Log Runner Group
          run: |
            echo "Runner group used: ${{ matrix.runner-group }}"

        # checkout the repo
        - name: 'Checkout GitHub Action'
          uses: actions/checkout@main

        - name: 'Login via Azure CLI'
          uses: azure/login@v1.5.1
          with:
            creds: ${{ secrets.AZURE_CREDENTIALS }}

        - name: 'Build and push image'
          uses: docker/login-action@v3
          with:
            registry: ${{ secrets.REGISTRY_LOGIN_SERVER }}
            username: ${{ secrets.REGISTRY_USERNAME }}
            password: ${{ secrets.REGISTRY_PASSWORD }}

        - run: |
            docker build . -t ${{ secrets.REGISTRY_LOGIN_SERVER }}/integrationAPI:${{ github.sha }}
            docker push ${{ secrets.REGISTRY_LOGIN_SERVER }}/integrationAPI:${{ github.sha }}

        - name: 'Deploy to Azure Container Instances'
          uses: 'azure/aci-deploy@v1'
          with:
            resource-group: ${{ secrets.RESOURCE_GROUP }}
            dns-name-label: ${{ secrets.RESOURCE_GROUP }}${{ github.run_number }}
            image: ${{ secrets.REGISTRY_LOGIN_SERVER }}/integrationAPI:${{ github.sha }}
            registry-login-server: ${{ secrets.REGISTRY_LOGIN_SERVER }}
            registry-username: ${{ secrets.REGISTRY_USERNAME }}
            registry-password: ${{ secrets.REGISTRY_PASSWORD }}
            name: integrationAPI
            location: 'east us'

I suppose with the private network setup, you don't see the runner group the same way, as the log runner group action didn't work either.

##[debug]Evaluating condition for step: 'Log Runner Group'
##[debug]Evaluating: success()
##[debug]Evaluating success:
##[debug]=> true
##[debug]Result: true
##[debug]Starting: Log Runner Group
##[debug]Loading inputs
##[debug]Evaluating: format('echo "Runner group used: ***0***"
##[debug]', matrix.runner-group)
##[debug]Evaluating format:
##[debug]..Evaluating String:
##[debug]..=> 'echo "Runner group used: ***0***"
##[debug]'
##[debug]..Evaluating Index:
##[debug]....Evaluating matrix:
##[debug]....=> null
##[debug]..=> null
##[debug]=> 'echo "Runner group used: "
##[debug]'
##[debug]Result: 'echo "Runner group used: "
##[debug]'
##[debug]Loading env
Run echo "Runner group used: "
  echo "Runner group used: "
  shell: /usr/bin/bash -e ***0***
##[debug]/usr/bin/bash -e /home/runner/work/_temp/ab1[2](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8872666720/job/24357341853#step:2:2)e305-fffc-4d2c-aba2-e084d45e4e41.sh
Runner group used: 
##[debug]Finishing: Log Runner Group
MoChilia commented 7 months ago

@stan-spotts, it appears that az account clear went wrong without any error information being logged. Could you please run the following step and share the log with me?

- name: Test az account clear
  run: |
    az account clear --debug
stan-spotts commented 7 months ago

Okay, I put that immediately prior to the azure/login step. It ran quickly to this login clear step, did some processing, and is now hanging with final debug statement "urlib3.connectionpool: Starting new HTTPS connection (1): login.microsoftonline.com:443"

##[debug]Evaluating condition for step: 'Test az account clear'
##[debug]Evaluating: success()
##[debug]Evaluating success:
##[debug]=> true
##[debug]Result: true
##[debug]Starting: Test az account clear
##[debug]Loading inputs
##[debug]Loading env
Run az account clear --debug
  az account clear --debug
  shell: /usr/bin/bash -e ***0***
##[debug]/usr/bin/bash -e /home/runner/work/_temp/fedd807[2](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:2)-1830-4921-a7af-b6ca748f4ed5.sh
DEBUG: cli.knack.cli: Command arguments: ['account', 'clear', '--debug']
DEBUG: cli.knack.cli: __init__ debug log:
Cannot enable color.
DEBUG: cli.knack.cli: Event: Cli.PreExecute []
DEBUG: cli.knack.cli: Event: CommandParser.OnGlobalArgumentsCreate [<function CLILogging.on_global_arguments at 0x7f[3](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:3)65c2f0040>, <function OutputProducer.on_global_arguments at 0x7f365c2a2160>, <function CLIQuery.on_global_arguments at 0x7f365c2dbc[4](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:4)0>]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreCommandTableCreate []
DEBUG: cli.azure.cli.core: Command index version or cloud profile is invalid or doesn't match the current command.
DEBUG: cli.azure.cli.core: Command index has been invalidated.
DEBUG: cli.azure.cli.core: No module found from index for '['account', 'clear', '--debug']'
DEBUG: cli.azure.cli.core: Loading all modules and extensions
DEBUG: cli.azure.cli.core: Discovered command modules: ['acr', 'acs', 'advisor', 'ams', 'apim', 'appconfig', 'appservice', 'aro', 'backup', 'batch', 'batchai', 'billing', 'botservice', 'cdn', 'cloud', 'cognitiveservices', 'config', 'configure', 'consumption', 'container', 'containerapp', 'cosmosdb', 'databoxedge', 'dla', 'dls', 'dms', 'eventgrid', 'eventhubs', 'extension', 'feedback', 'find', 'hdinsight', 'identity', 'interactive', 'iot', 'keyvault', 'kusto', 'lab', 'managedservices', 'maps', 'marketplaceordering', 'monitor', 'mysql', 'netappfiles', 'network', 'policyinsights', 'privatedns', 'profile', 'rdbms', 'redis', 'relay', 'resource', 'role', 'search', 'security', 'servicebus', 'serviceconnector', 'servicefabric', 'signalr', 'sql', 'sqlvm', 'storage', 'synapse', 'util', 'vm']
DEBUG: cli.azure.cli.core: Loading command modules:
DEBUG: cli.azure.cli.core: Name                  Load Time    Groups  Commands
DEBUG: cli.azure.cli.core: acr                       1.021        36       149
DEBUG: cli.azure.cli.core: acs                       0.410        14        76
DEBUG: cli.azure.cli.core: advisor                   0.018         3         6
DEBUG: cli.azure.cli.core: ams                       0.019        22       100
DEBUG: cli.azure.cli.core: apim                      0.04[5](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:5)        14        69
DEBUG: cli.azure.cli.core: appconfig                 0.015         9        47
DEBUG: cli.azure.cli.core: appservice                0.802        79       270
DEBUG: cli.azure.cli.core: aro                       0.123         1        10
DEBUG: cli.azure.cli.core: backup                    0.015        1[6](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:6)        60
DEBUG: cli.azure.cli.core: batch                     0.1[7](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:7)4        34       102
DEBUG: cli.azure.cli.core: batchai                   0.020        10        30
DEBUG: cli.azure.cli.core: billing                   0.067        19        53
DEBUG: cli.azure.cli.core: botservice                0.032        12        42
DEBUG: cli.azure.cli.core: cdn                       0.[8](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:8)28        11        48
DEBUG: cli.azure.cli.core: cloud                     0.008         1         7
DEBUG: cli.azure.cli.core: cognitiveservices         0.008        10        33
DEBUG: cli.azure.cli.core: config                    0.008         2         7
DEBUG: cli.azure.cli.core: configure                 0.006         2         5
DEBUG: cli.azure.cli.core: consumption               0.118         8         [9](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:9)
DEBUG: cli.azure.cli.core: container                 0.084         1        11
DEBUG: cli.azure.cli.core: containerapp              1.021        36       115
DEBUG: cli.azure.cli.core: cosmosdb                  0.061        58       199
DEBUG: cli.azure.cli.core: databoxedge               0.054         5        28
DEBUG: cli.azure.cli.core: dla                       0.013        23        62
DEBUG: cli.azure.cli.core: dls                       0.013         7        41
DEBUG: cli.azure.cli.core: dms                       0.015         3        22
DEBUG: cli.azure.cli.core: eventgrid                 0.051        25        96
DEBUG: cli.azure.cli.core: eventhubs                 0.184        12        19
DEBUG: cli.azure.cli.core: extension                 0.007         1         7
DEBUG: cli.azure.cli.core: feedback                  0.001         1         2
DEBUG: cli.azure.cli.core: find                      0.012         1         1
DEBUG: cli.azure.cli.core: hdinsight                 0.040         8        39
DEBUG: cli.azure.cli.core: identity                  0.008         2        11
DEBUG: cli.azure.cli.core: interactive               0.006         1         1
DEBUG: cli.azure.cli.core: iot                       1.173        19        82
DEBUG: cli.azure.cli.core: keyvault                  0.037        20       113
DEBUG: cli.azure.cli.core: kusto                     0.007         3        14
DEBUG: cli.azure.cli.core: lab                       0.023        11        34
DEBUG: cli.azure.cli.core: managedservices           0.008         3         8
DEBUG: cli.azure.cli.core: maps                      0.007         5        13
DEBUG: cli.azure.cli.core: marketplaceordering       0.018         1         2
DEBUG: cli.azure.cli.core: monitor                   4.589        17        60
DEBUG: cli.azure.cli.core: mysql                     0.780        15        51
DEBUG: cli.azure.cli.core: netappfiles               0.207         8        16
DEBUG: cli.azure.cli.core: network                   1.012       [10](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:10)3       338
DEBUG: cli.azure.cli.core: policyinsights            0.063         9        17
DEBUG: cli.azure.cli.core: privatedns                0.230        14        60
DEBUG: cli.azure.cli.core: profile                   0.007         2         8
DEBUG: cli.azure.cli.core: rdbms                     0.216        49       202
DEBUG: cli.azure.cli.core: redis                     0.012         7        38
DEBUG: cli.azure.cli.core: relay                     0.098         7         8
DEBUG: cli.azure.cli.core: resource                  0.136        51       228
DEBUG: cli.azure.cli.core: role                      0.0[11](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:11)        17        61
DEBUG: cli.azure.cli.core: search                    0.085         7        19
DEBUG: cli.azure.cli.core: security                  0.106        49       105
DEBUG: cli.azure.cli.core: servicebus                0.051        13        15
DEBUG: cli.azure.cli.core: serviceconnector          0.149        16       244
DEBUG: cli.azure.cli.core: servicefabric             0.199        27        76
DEBUG: cli.azure.cli.core: signalr                   0.011         9        34
DEBUG: cli.azure.cli.core: sql                       0.049        56       215
DEBUG: cli.azure.cli.core: sqlvm                     0.332         4        20
DEBUG: cli.azure.cli.core: storage                   0.196        59       273
DEBUG: cli.azure.cli.core: synapse                   0.048        54       246
DEBUG: cli.azure.cli.core: util                      0.026         3         7
DEBUG: cli.azure.cli.core: vm                        0.509        58       233
DEBUG: cli.azure.cli.core: Total (65)               15.700      [12](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:13)03      4617
DEBUG: cli.azure.cli.core: Loading extensions:
DEBUG: cli.azure.cli.core: Name                  Load Time    Groups  Commands  Directory
DEBUG: cli.azure.cli.core: azure-devops              0.384        60       192  /opt/az/azcliextensions/azure-devops
DEBUG: cli.azure.cli.core: Total (1)                 0.384        60       192  
DEBUG: cli.azure.cli.core: Loaded 1250 groups, 4809 commands.
DEBUG: cli.azure.cli.core: Updated command index in 0.003 seconds.
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreCommandTableTruncate [<function AzCliLogging.init_command_file_logging at 0x7f365b435c60>]
DEBUG: cli.azure.cli.core.azlogging: metadata file logging enabled - writing logs to '/home/runner/.azure/commands/2024-04-29.12-[17](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:18)-25.account_clear.4362.log'.
INFO: az_command_data_logger: command args: account clear --debug
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreArgumentLoad [<function register_global_subscription_argument.<locals>.add_subscription_parameter at 0x7f365ad227a0>]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPostArgumentLoad []
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPostCommandTableCreate [<function register_ids_argument.<locals>.add_ids_arguments at 0x7f365ad22840>, <function register_cache_arguments.<locals>.add_cache_arguments at 0x7f365ad22980>]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnCommandTableLoaded []
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPreParseArgs [<function _documentdb_deprecate at 0x7f365975cc[20](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:21)>]
DEBUG: cli.knack.cli: Event: CommandInvoker.OnPostParseArgs [<function OutputProducer.handle_output_argument at 0x7f365c2a2200>, <function CLIQuery.handle_query_parameter at 0x7f365c2dbce0>, <function register_ids_argument.<locals>.parse_ids_arguments at 0x7f365ad[22](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8878369587/job/24373870327#step:4:23)8e0>, <function DevCommandsLoader.post_parse_args at 0x7f3655474360>]
DEBUG: cli.azure.cli.core.auth.persistence: build_persistence: location='/home/runner/.azure/msal_token_cache.json', encrypt=False
DEBUG: cli.azure.cli.core.auth.binary_cache: load: /home/runner/.azure/msal_http_cache.bin
DEBUG: cli.azure.cli.core.auth.binary_cache: /home/runner/.azure/msal_http_cache.bin not found. Using a fresh one.
DEBUG: urllib3.util.retry: Converted retries value: 1 -> Retry(total=1, connect=None, read=None, redirect=None, status=None)
DEBUG: urllib3.connectionpool: Starting new HTTPS connection (1): login.microsoftonline.com:443

I cancelled after 6 minutes.

MoChilia commented 7 months ago

@stan-spotts, could you check the internet access and firewall rules on your runner? Is it allowed to access login.microsoftonline.com? You may diagnose DNS and check the access by running

nslookup login.microsoftonline.com
stan-spotts commented 7 months ago

Added a step for that, got this:

##[debug]Evaluating condition for step: 'Check access'
##[debug]Evaluating: success()
##[debug]Evaluating success:
##[debug]=> true
##[debug]Result: true
##[debug]Starting: Check access
##[debug]Loading inputs
##[debug]Loading env
Run nslookup login.microsoftonline.com
##[debug]/usr/bin/bash -e /home/runner/work/_temp/7f394886-7a90-486[2](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8888603521/job/24405675187#step:2:2)-a06d-fd2142981328.sh
Server:     127.0.0.5[3](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8888603521/job/24405675187#step:2:3)
Address:    127.0.0.53#53

Non-authoritative answer:
login.microsoftonline.com   canonical name = login.mso.msidentity.com.
login.mso.msidentity.com    canonical name = ak.privatelink.msidentity.com.
ak.privatelink.msidentity.com   canonical name = www.tm.ak.prd.aadg.akadns.net.
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 20.190.190.19[4](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8888603521/job/24405675187#step:2:4)
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 40.126.62.132
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 20.190.190.19[5](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8888603521/job/24405675187#step:2:5)
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 20.190.190.129
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 20.190.190.193
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 40.12[6](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8888603521/job/24405675187#step:2:6).62.131
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 20.190.190.196
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 20.190.190.130
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 2603:1036:3000:f[8](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8888603521/job/24405675187#step:2:8)::1
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 2603:1036:3000:e8::4
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 2603:1036:3000:e8::3
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 2603:1036:3000:f0::2
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 2603:1036:3000:f8::2
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 2603:1036:3000:e8::1
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 2603:1036:3000:f0::1
Name:   www.tm.ak.prd.aadg.akadns.net
Address: 2603:1036:3000:f8::3

##[debug]Finishing: Check access
MoChilia commented 7 months ago

How about reverting to azure/login@v1.5.0 to check if running az login directly resolves the issue?

stan-spotts commented 7 months ago

Nope, took out the az account clear step and revered to azure/login@v1.5.0 and got this:

##[debug]Evaluating condition for step: 'Login via Azure CLI'
##[debug]Evaluating: success()
##[debug]Evaluating success:
##[debug]=> true
##[debug]Result: true
##[debug]Starting: Login via Azure CLI
##[debug]Loading inputs
##[debug]Evaluating: secrets.AZURE_CREDENTIALS
##[debug]Evaluating Index:
##[debug]..Evaluating secrets:
##[debug]..=> Object
##[debug]..Evaluating String:
##[debug]..=> 'AZURE_CREDENTIALS'
##[debug]=> '*** 
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]***'
##[debug]Result: '*** 
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]  ***
##[debug]***'
##[debug]Loading env
Run azure/login@v1.5.0
##[debug]Reading creds in JSON...
::add-mask::***
::add-mask::***
(node:[2](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8889696625/job/24408483519#step:3:2)253) [DEP0128] DeprecationWarning: Invalid 'main' field in '/home/runner/work/_actions/azure/login/v1.5.0/node_modules/actions-secret-parser/package.json' of 'lib/index.js'. Please either fix that or report it to the module author
(Use `node --trace-deprecation ...` to show where the warning was created)
Running Azure CLI Login.
##[debug]Azure CLI path: /usr/bin/az
##[debug]Azure CLI version used:
##[debug]azure-cli                         2.59.0
##[debug]
##[debug]core                              2.59.0
##[debug]telemetry                          1.1.0
##[debug]
##[debug]Extensions:
##[debug]azure-devops                       1.0.0
##[debug]
##[debug]Dependencies:
##[debug]msal                              1.27.0
##[debug]azure-mgmt-resource             2[3](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8889696625/job/24408483519#step:3:3).1.0b2
##[debug]
##[debug]Python location '/opt/az/bin/python3'
##[debug]Extensions directory '/opt/az/azcliextensions'
##[debug]
##[debug]Python (Linux) 3.11.8 (main, Mar 27 202[4](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8889696625/job/24408483519#step:3:4), 04:03:04) [GCC 11.4.0]
##[debug]
##[debug]Legal docs and information: aka.ms/AzureCliLegal
##[debug]
##[debug]
##[debug]Your CLI is up-to-date.
##[debug]
/usr/bin/az cloud set -n azurecloud
Done setting cloud: "azurecloud"
Note: Azure/login action also supports OIDC login mechanism. Refer https://github.com/azure/login#configure-a-service-principal-with-a-federated-credential-to-use-oidc-based-authentication for more details.
Attempting Azure CLI login by using service principal with secret...
stan-spotts commented 7 months ago

Also just tried with OIDC login:

on: 
    workflow_dispatch:
    #[push]
name: Linux_Container_Workflow

permissions:
  id-token: write
  contents: read

jobs:
    build-and-deploy:
        runs-on: LinuxRunner

        steps:
        # checkout the repo
        - name: 'Checkout GitHub Action'
          uses: actions/checkout@main

        #- name: Test az account clear
        #  run: |
        #    az account clear --debug

        - name: 'Login via Azure CLI'
          uses: azure/login@v1.5.0
          with:
            client-id: ${{ secrets.REGISTRY_USERNAME }}
            tenant-id: ${{ secrets.AZURE_TENANT_ID }}
            subscription-id: ${{ secrets.AZURE_SUBSCRIPTION_ID }}
            # creds: ${{ secrets.AZURE_CREDENTIALS }}

        - name: Azure CLI script
          uses: azure/cli@v2
          with:
            azcliversion: latest
            inlineScript: |
              az account show
 # more stuff follows

Got this:

##[debug]Evaluating condition for step: 'Login via Azure CLI'
##[debug]Evaluating: success()
##[debug]Evaluating success:
##[debug]=> true
##[debug]Result: true
##[debug]Starting: Login via Azure CLI
##[debug]Loading inputs
##[debug]Evaluating: secrets.REGISTRY_USERNAME
##[debug]Evaluating Index:
##[debug]..Evaluating secrets:
##[debug]..=> Object
##[debug]..Evaluating String:
##[debug]..=> 'REGISTRY_USERNAME'
##[debug]=> '***
##[debug]
##[debug]'
##[debug]Result: '***
##[debug]
##[debug]'
##[debug]Evaluating: secrets.TENANT_ID
##[debug]Evaluating Index:
##[debug]..Evaluating secrets:
##[debug]..=> Object
##[debug]..Evaluating String:
##[debug]..=> 'TENANT_ID'
##[debug]=> '***'
##[debug]Result: '***'
##[debug]Evaluating: secrets.SUBSCRIPTION_ID
##[debug]Evaluating Index:
##[debug]..Evaluating secrets:
##[debug]..=> Object
##[debug]..Evaluating String:
##[debug]..=> 'SUBSCRIPTION_ID'
##[debug]=> '***'
##[debug]Result: '***'
##[debug]Loading env
Run azure/login@v1.5.0
  with:
    client-id: ***

    tenant-id: ***
    subscription-id: ***
    enable-AzPSSession: false
    environment: azurecloud
    allow-no-subscriptions: false
    audience: api://AzureADTokenExchange
    auth-type: SERVICE_PRINCIPAL
::add-mask::***
(node:1868) [DEP01[2](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8889945970/job/24409122805#step:3:2)8] DeprecationWarning: Invalid 'main' field in '/home/runner/work/_actions/azure/login/v1.5.0/node_modules/actions-secret-parser/package.json' of 'lib/index.js'. Please either fix that or report it to the module author
(Use `node --trace-deprecation ...` to show where the warning was created)
Running Azure CLI Login.
##[debug]Azure CLI path: /usr/bin/az
##[debug]Azure CLI version used:
##[debug]azure-cli                         2.59.0
##[debug]
##[debug]core                              2.59.0
##[debug]telemetry                          1.1.0
##[debug]
##[debug]Extensions:
##[debug]azure-devops                       1.0.0
##[debug]
##[debug]Dependencies:
##[debug]msal                              1.27.0
##[debug]azure-mgmt-resource             2[3](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8889945970/job/24409122805#step:3:3).1.0b2
##[debug]
##[debug]Python location '/opt/az/bin/python3'
##[debug]Extensions directory '/opt/az/azcliextensions'
##[debug]
##[debug]Python (Linux) 3.11.8 (main, Mar 27 202[4](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8889945970/job/24409122805#step:3:4), 04:03:04) [GCC 11.4.0]
##[debug]
##[debug]Legal docs and information: aka.ms/AzureCliLegal
##[debug]
##[debug]
##[debug]Your CLI is up-to-date.
##[debug]
/usr/bin/az cloud set -n azurecloud
Done setting cloud: "azurecloud"
##[debug]ID token url is https://pipelinesghubeus9.actions.githubusercontent.com/jhZtRrMh7dzQopqE7LHlg1Lle7qeb0XR8C8odWn38kjb4DTMHg/00000000-0000-0000-0000-000000000000/_apis/distributedtask/hubs/Actions/plans/f7168743-4384-42f6-8e9c-d0fd0eb44b36/jobs/ef[5](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8889945970/job/24409122805#step:3:5)3817e-be1e-5b9f-8d47-e[6](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8889945970/job/24409122805#step:3:6)3fd9dfbe04/idtoken?api-version=2.0&audience=api%3A%2F%2FAzureADTokenExchange
::add-mask::***
::add-mask::***
Federated token details:
 issuer - https://token.actions.githubusercontent.com
 subject claim - repo:CGFNSOrg/IntegrationAPI:ref:refs/heads/main
Attempting Azure CLI login by using OIDC...

Then it just spun.

MoChilia commented 7 months ago

Okay, it should be a connection issue on your private network that's blocking access to login.microsoftonline.com. Please check your firewall and network settings.

stan-spotts commented 7 months ago

There are no firewall settings at all. The VNET doesn't even have a private endpoint yet. There is one NSG on the subnet that's set up for this per the information in the link I referenced - https://docs.github.com/en/organizations/managing-organization-settings/configuring-private-networking-for-github-hosted-runners-in-your-organization.

I even added an outbound Any/* -> Any/Http rule. But it still didn't work.

Yet when I removed this NSG it got past the azure/login error. This is not a solution as there's no security. Maybe the destinationAddressPrefixes on either the AllowOutBoundActions or the AllowOutBoundGitHub rule the link defines needs to be wider open?

So I understood that this setup adds a NIC to my subnet from GitHub, but now I'm wondering how it's used. Is it just so the GitHub hosted runner can reach in to access resources with a private IP address on my VNET? Or does it also send all traffic through this NIC when it does such things as the azure/login action?

Just to add insult to injury, as it did complete the azure/login step, it was able to get to the docker/login step. And that failed with this:

Run docker/login-action@v3
  with:
    registry: ***
    username: ***

    password: ***

    ecr: auto
    logout: true
  env:
    AZURE_HTTP_USER_AGENT: 
    AZUREPS_HOST_ENVIRONMENT: 

Logging into ***...
##[debug]Exec.getExecOutput: docker login --password-stdin --username *** ***
Error: Error response from daemon: Get "https://***/v2/": denied: client with IP '13.68.227.2[48](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8890869677/job/24411681241#step:5:48)' is not allowed access. Refer https://aka.ms/acr/firewall to grant access.
##[debug]Node Action run completed with exit code 1

Does the docker/login-action action not understand this setup? I guess I'll have to post something on that repo too :(.

This entire process is like root canal. :(

stan-spotts commented 7 months ago

Update: I created three new outgoing rules:

AllowAzureCloudOutbound - Any/ -> Service Tag/AzureCloud HTTPS Allow 100 AllowAzureADOutbound - Any/ -> Service Tag/AzureActiveDirectory HTTPS Allow 110 AllowAzureFrontDoorOutbound - Any/* -> Service Tag/AzureFrontDoor.Frontend HTTPS Allow 100

So after all this, you had the right idea in that it was a firewall/NSG issue. The documentation did not supply these rules, so login couldn't work but does now. It appears this solved the docker/action-login issue as well.

Now the only odd part is that I'm seeing this on the step where I'm using a cli command to show the account I'm running under:

Run azure/cli@v2
  with:
    azcliversion: latest
    inlineScript: az account show

Warning: Unable to fetch all az cli versions, please report it as an issue on https://github.com/Azure/CLI/issues. Output: , Error: Error: The process 'curl' failed with exit code 28
Starting script execution via docker image mcr.microsoft.com/azure-cli:latest
Error: Error: Unable to find image 'mcr.microsoft.com/azure-cli:latest' locally
docker: Error response from daemon: Get "https://mcr.microsoft.com/v2/": net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers).
See 'docker run --help'.

cleaning up container...
Warning: Error response from daemon: No such container: MICROSOFT_AZURE_CLI_17[14](https://github.com/CGFNSOrg/IntegrationAPI/actions/runs/8898404600/job/24435473268#step:5:15)494816433_CONTAINER

Error: Unable to find image 'mcr.microsoft.com/azure-cli:latest' locally
docker: Error response from daemon: Get "https://mcr.microsoft.com/v2/": net/http: request canceled while waiting for connection (Client.Timeout exceeded while awaiting headers).
See 'docker run --help'.

##[debug]Node Action run completed with exit code 1
##[debug]Finishing: Azure CLI script

But this is probably out of scope for this bug report.