search

pulumi / pulumi-azure-native

Azure Native Provider
Apache License 2.0
128 stars 34 forks source link

pulumi up fails with could not determine az version: unmarshaling the result of Azure CLI #2048

Closed espenairmine closed 2 years ago

espenairmine commented 2 years ago

What happened?

Trying pulumi, followed the cookbook : https://www.pulumi.com/docs/get-started/azure/

pulumi installs fine, az cli works like a charm. pulumi up/preview fails with:

Diagnostics: azure-native:resources:ResourceGroup (test-pulumi): error: could not determine az version: unmarshaling the result of Azure CLI: json: invalid character 'A' looking for beginning of value: Azure-cli Azure-cli-core A...

---------------------------

pulumi up

Previewing update (dev)

View Live: https://app.pulumi.com/<REDACTED>/dev/previews/e2c79bfc-6797-4918-ada0-769f85257073

     Type                                     Name         Plan       Info
 +   pulumi:pulumi:Stack                      <REDACTED>     create
     └─ azure-native:resources:ResourceGroup  test-pulumi             1 error

Diagnostics:
  azure-native:resources:ResourceGroup (test-pulumi):
    error: could not determine az version: unmarshaling the result of Azure CLI: json: invalid character 'A' looking for beginning of value: Azure-cli    Azure-cli-core    A...

----------------------------

Log file created at: 2022/10/25 10:07:09
Running on machine: hjemme64
Binary: Built with gc go1.19.2 for windows/amd64
Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu threadid file:line] msg
I1025 10:07:09.241342   25356 backend.go:484] found username for access token
I1025 10:07:09.452886   25356 backend.go:484] found username for access token
I1025 10:07:09.701499   25356 ignore.go:44] Explicitly ignoring and discarding error: no git repository found from <REDACTED>
I1025 10:07:12.663731   25356 deployment_executor.go:472] deploymentExecutor.retirePendingDeletes(...): no pending deletions
I1025 10:07:12.663731   25356 deployment_executor.go:253] deploymentExecutor.Execute(...): waiting for incoming events
I1025 10:07:12.663731   25356 step_executor.go:389] StepExecutor worker(-2): worker coming online
I1025 10:07:12.663731   25356 step_executor.go:389] StepExecutor worker(-2): worker waiting for incoming chains
I1025 10:07:12.970045   25356 eventsink.go:59] registering resource: ty=pulumi:pulumi:Stack, name=<REDACTED>, custom=False, remote=False
I1025 10:07:13.223645   25356 eventsink.go:59] registering resource: ty=azure-native:resources:ResourceGroup, name=test-pulumi, custom=True, remote=False
I1025 10:07:13.277206   25356 eventsink.go:59] registering resource: ty=azure-native:storage:StorageAccount, name=sa, custom=True, remote=False
I1025 10:07:13.277712   25356 eventsink.go:59] Waiting for outstanding RPCs to complete
I1025 10:07:13.278362   25356 eventsink.go:59] RPCs successfully completed
I1025 10:07:13.279157   25356 eventsink.go:59] Waiting for 187 outstanding tasks to complete
I1025 10:07:13.279803   25356 eventsink.go:59] beginning rpc register resource
I1025 10:07:13.282659   25356 eventsink.go:59] beginning rpc register resource
I1025 10:07:13.284678   25356 eventsink.go:59] beginning rpc register resource
I1025 10:07:13.284678   25356 eventsink.go:59] beginning rpc register resource outputs
I1025 10:07:13.285683   25356 eventsink.go:59] resource registration prepared: ty=pulumi:pulumi:Stack, name=dcp2-dev
I1025 10:07:13.300130   25356 source_eval.go:1110] ResourceMonitor.RegisterResource received: t=pulumi:pulumi:Stack, name=dcp2-dev, custom=false, #props=0, parent=, protect=false, provider=, deps=[], deleteBeforeReplace=<nil>, ignoreChanges=[], aliases=[], customTimeouts={0 0 0}, providers=map[], replaceOnChanges=[], retainOnDelete=false
I1025 10:07:13.300130   25356 source_eval.go:167] EvalSourceIterator produced a registration: t=pulumi:pulumi:Stack,name=dcp2-dev,#props=0
I1025 10:07:13.300130   25356 deployment_executor.go:257] deploymentExecutor.Execute(...): incoming event (nil? false, <nil>)
I1025 10:07:13.300130   25356 deployment_executor.go:444] deploymentExecutor.handleSingleEvent(...): received RegisterResourceEvent
I1025 10:07:13.300130   25356 step_executor.go:389] StepExecutor worker(-2): worker received chain for execution
I1025 10:07:13.300130   25356 step_executor.go:389] StepExecutor worker(-2): worker waiting for incoming chains
I1025 10:07:13.300130   25356 step_executor.go:389] StepExecutor worker(0): launching oneshot worker
I1025 10:07:13.300635   25356 step_executor.go:389] StepExecutor worker(0): applying step create on urn:pulumi:dev::dcp2::pulumi:pulumi:Stack::dcp2-dev (preview true)
I1025 10:07:13.300635   25356 step_executor.go:389] StepExecutor worker(0): step create on urn:pulumi:dev::<REDACTED>::pulumi:pulumi:Stack::<REDACTED> retired
I1025 10:07:13.300635   25356 source_eval.go:1236] ResourceMonitor.RegisterResource operation finished: t=pulumi:pulumi:Stack, urn=urn:pulumi:dev::<REDACTED>::pulumi:pulumi:Stack::<REDACTED>, #outs=0
I1025 10:07:13.301168   25356 eventsink.go:59] resource registration successful: ty=pulumi:pulumi:Stack, urn=urn:pulumi:dev::<REDACTED>::pulumi:pulumi:Stack::<REDACTED>
I1025 10:07:13.303627   25356 eventsink.go:59] resource registration prepared: ty=azure-native:resources:ResourceGroup, name=test-pulumi
I1025 10:07:13.304131   25356 source_eval.go:346] handling default provider request for package azure-native-1.83.0
I1025 10:07:13.304131   25356 source_eval.go:294] newRegisterDefaultProviderEvent(azure-native-1.83.0): using version 1.83.0 from request
I1025 10:07:13.304131   25356 source_eval.go:313] newRegisterDefaultProviderEvent(azure-native-1.83.0): no pluginDownloadURL specified, falling back to default pluginDownloadURL
I1025 10:07:13.304131   25356 source_eval.go:321] newRegisterDefaultProviderEvent(azure-native-1.83.0): default pluginDownloadURL miss, sending empty string to engine
I1025 10:07:13.304131   25356 source_eval.go:379] waiting for default provider for package azure-native-1.83.0
I1025 10:07:13.304131   25356 source_eval.go:167] EvalSourceIterator produced a registration: t=pulumi:providers:azure-native,name=default_1_83_0,#props=2
I1025 10:07:13.304131   25356 deployment_executor.go:257] deploymentExecutor.Execute(...): incoming event (nil? false, <nil>)
I1025 10:07:13.304131   25356 deployment_executor.go:444] deploymentExecutor.handleSingleEvent(...): received RegisterResourceEvent
I1025 10:07:13.643169   25356 step_executor.go:389] StepExecutor worker(-2): worker received chain for execution
I1025 10:07:13.643169   25356 step_executor.go:389] StepExecutor worker(-2): worker waiting for incoming chains
I1025 10:07:13.643169   25356 step_executor.go:389] StepExecutor worker(1): launching oneshot worker
I1025 10:07:13.643688   25356 step_executor.go:389] StepExecutor worker(1): applying step create on urn:pulumi:dev::dcp2::pulumi:providers:azure-native::default_1_83_0 (preview true)
I1025 10:07:13.643688   25356 step_executor.go:389] StepExecutor worker(1): step create on urn:pulumi:dev::dcp2::pulumi:providers:azure-native::default_1_83_0 retired
I1025 10:07:13.643688   25356 source_eval.go:388] registered default provider for package azure-native-1.83.0: urn:pulumi:dev::dcp2::pulumi:providers:azure-native::default_1_83_0
I1025 10:07:13.643688   25356 source_eval.go:1110] ResourceMonitor.RegisterResource received: t=azure-native:resources:ResourceGroup, name=test-pulumi, custom=true, #props=0, parent=urn:pulumi:dev::dcp2::pulumi:pulumi:Stack::dcp2-dev, protect=false, provider=urn:pulumi:dev::dcp2::pulumi:providers:azure-native::default_1_83_0::04da6b54-80e4-46f7-96ec-b56ff0331ba9, deps=[], deleteBeforeReplace=<nil>, ignoreChanges=[], aliases=[{urn:pulumi:dev::dcp2::azure-native:resources/v20151101:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20160201:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20160701:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20160901:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20170510:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20180201:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20180501:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20190301:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20190501:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20190510:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20190701:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20190801:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20191001:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20200601:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20200801:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20201001:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20210101:ResourceGroup::test-pulumi     } {urn:pulumi:dev::dcp2::azure-native:resources/v20210401:ResourceGroup::test-pulumi     }], customTimeouts={0 0 0}, providers=map[], replaceOnChanges=[], retainOnDelete=false
I1025 10:07:13.643688   25356 source_eval.go:167] EvalSourceIterator produced a registration: t=azure-native:resources:ResourceGroup,name=test-pulumi,#props=0
I1025 10:07:13.643688   25356 deployment_executor.go:257] deploymentExecutor.Execute(...): incoming event (nil? false, <nil>)
I1025 10:07:13.643688   25356 deployment_executor.go:444] deploymentExecutor.handleSingleEvent(...): received RegisterResourceEvent
I1025 10:07:14.586856   25356 deployment_executor.go:284] deploymentExecutor.Execute(...): error handling event: could not determine az version: unmarshaling the result of Azure CLI: json: invalid character 'A' looking for beginning of value: Azure-cli    Azure-cli-core    A...
I1025 10:07:14.586856   25356 eventsink.go:86] eventSink::Error(<{%reset%}>could not determine az version: unmarshaling the result of Azure CLI: json: invalid character 'A' looking for beginning of value: Azure-cli    Azure-cli-core    A...<{%reset%}>)
I1025 10:07:14.586856   25356 step_executor.go:389] StepExecutor worker(-1): StepExecutor.waitForCompletion(): waiting for worker threads to exit
I1025 10:07:14.586856   25356 step_executor.go:389] StepExecutor worker(-2): worker exiting due to cancellation
I1025 10:07:14.586856   25356 step_executor.go:389] StepExecutor worker(-1): StepExecutor.waitForCompletion(): worker threads all exited
I1025 10:07:14.586856   25356 deployment_executor.go:301] deploymentExecutor.Execute(...): step executor has completed
I1025 10:07:14.586856   25356 deployment_executor.go:159] deploymentExecutor.Execute(...): exiting provider canceller
I1025 10:07:14.599018   25356 ignore.go:44] Explicitly ignoring and discarding error: rpc error: code = Canceled desc = grpc: the client connection is closing
I1025 10:07:14.620600   25356 source_eval.go:187] EvalSourceIterator ended with an error: error reading from server: read tcp 127.0.0.1:56601->127.0.0.1:56599: use of closed network connection
I1025 10:07:14.620600   25356 deployment_executor.go:238] deploymentExecutor.Execute(...): incoming events goroutine exiting
I1025 10:07:14.620600   25356 host.go:512] Error closing 'python' language plugin during shutdown; ignoring: 2 errors occurred:
    * TerminateProcess: Access is denied.
    * TerminateProcess: Access is denied.
-----------------------------------

pulumi about

CLI
Version      3.43.1
Go Version   go1.19.2
Go Compiler  gc

Plugins
NAME          VERSION
azure-native  1.83.0
python        unknown

Host
OS       Microsoft Windows 11 Pro
Version  10.0.22623 Build 22623
Arch     x86_64

This project is written in python: executable='C:\Users\<REDACTED>\source\repos\<REDACTED>\pulumi\venv\Scripts\python.exe' version='3.9.6
'
URL            https://app.pulumi.com/<REDACTED>
User           <REDACTED>
Organizations  <REDACTED>

Dependencies:
NAME                 VERSION
pip                  22.3.0
pulumi-azure-native  1.83.0
setuptools           65.5.0
wheel                0.37.1

Pulumi locates its logs in C:\Users\<REDACTED>\AppData\Local\Temp by default

--------------------------------------
az version
Azure-cli    Azure-cli-core    Azure-cli-telemetry
-----------  ----------------  ---------------------
2.41.0       2.41.0            1.0.8

Steps to reproduce

Follow Azure python cookbok on windows (11)

Expected Behavior

pulumi up creates preview and stack can be deployed

Actual Behavior

pulumi up fails with error code (hard to diagnose as az cli is working as expected)

Output of pulumi about

CLI
Version      3.43.1
Go Version   go1.19.2
Go Compiler  gc

Plugins
NAME          VERSION
azure-native  1.83.0
python        unknown

Host
OS       Microsoft Windows 11 Pro
Version  10.0.22623 Build 22623
Arch     x86_64

This project is written in python: executable='C:\Users\<REDACTED>\source\repos\<REDACTED>\pulumi\venv\Scripts\python.exe' version='3.9.6
'
URL            https://app.pulumi.com/<REDACTED>
User           <REDACTED>
Organizations  <REDACTED>

Dependencies:
NAME                 VERSION
pip                  22.3.0
pulumi-azure-native  1.83.0
setuptools           65.5.0
wheel                0.37.1

Pulumi locates its logs in C:\Users\<REDACTED>\AppData\Local\Temp by default

Additional context

No response

Contributing

Vote on this issue by adding a 👍 reaction. To contribute a fix for this issue, leave a comment (and link to your pull request, if you've opened one already).

danielrbradley commented 2 years ago

This appears to be the same issue as #2046

Will close as a duplicate and track via the other issue, but will bump the priority as it appears to be a non-isolated issue.