Improve `--output="json"` behavior of `azd`

To support their extension, Visual Studio calls azd with --output=json and uses these structured messages to drive behavior internally.

Previously, when running azd infra create --output=json we would spit out an array of deployment operations peridocially and then at the end of the operation we would print he full deployment object from ARM.

This behavior broke in subtle ways when did the refactoring to support multiple IaC providers, and that turned up an ever larger issue - the entire contract was very tied to an ARM deployment. When using Terraform there is no set of ARM Deployment Operations we can provide (since it doesn't use ARM Deployments, instead it just calls the control plane directly) and there's no deployment object at the end that we can return.

This change works to improve this behavior.

Our contract types now include a top level type property that consumers can use to understand the shape of the message. This was added to allow us to emit more messages as the CLI evolves for a given operation. Consumers should ignore objects with types the don't understand.

Calls to console.Message are now written in a structured format when using --output=json. Any ANSI color codes are removed from the output. New lines are kept as is, so a consumer can take any object with the type of consoleMessage and simply JSON decode the message property and then write it to the console (any required trailling newlines will be part of the message string) which will give them the same output that would have been rendered the the console.

When consuming output from the CLI run with --output=json consumers should read JSON objects from stdin until EOF is reached. Objects will be streamed in "real time" as the CLI produces them.

For example, here's the output of azd infra create --output=json with these changes for a small App Service application:

{
  "type": "consoleMessage",
  "message": "\nInfrastructure provisioning plan completed successfully\n"
}
{
  "type": "consoleMessage",
  "message": "Provisioning Azure resources can take some time.\n\nYou can view detailed progress in the Azure Portal:\nhttps://portal.azure.com/#blade/HubsExtension/DeploymentDetailsBlade/overview/id/%2Fsubscriptions%2Ffaa080af-c1d8-40ad-9cce-e1a450ca5b57%2Fproviders%2FMicrosoft.Resources%2Fdeployments%2Fmatell-azd-json\n\n"
}
{
  "type": "consoleMessage",
  "message": "Created Resource group: rg-matell-azd-json\n"
}
{
  "type": "consoleMessage",
  "message": "Created App Service plan: plan-itzzednmw27ng\n"
}
{
  "type": "consoleMessage",
  "message": "Created Web App: app-itzzednmw27ng\n"
}
{
  "type": "consoleMessage",
  "message": "\nAzure resource provisioning completed successfully\n"
}
{
  "type": "consoleMessage",
  "message": "View the resources created under the resource group rg-matell-azd-json in Azure Portal:\nhttps://portal.azure.com/#@/resource/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json/overview\n\n"
}
{
  "type": "envRefreshResult",
  "outputs": {
    "WEBSITE_URL": {
      "type": "string",
      "value": "https://app-itzzednmw27ng.azurewebsites.net/"
    }
  },
  "resources": [
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json"
    },
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json/providers/Microsoft.Web/serverfarms/plan-itzzednmw27ng"
    },
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json/providers/Microsoft.Web/sites/app-itzzednmw27ng"
    },
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json/providers/Microsoft.Web/sites/app-itzzednmw27ng/config/appsettings"
    }
  ]
}

Contributes To: https://github.com/Azure/azure-dev/issues/742

With the type - consoleMessage(how data should be presented/messaged in the console) and type - envRefreshResult(actual operations result data)

Feels like we are mixing the command contracts to have not just the data model/structure but also on how the presentation of the data in the console and/or IDEs. Are we thinking along the same lines for error contracts too? Should we really do that? It might work fine with our internal integrations. But, external and or other integrations the consoleMessage part of the command contract might not be useful and consumers have to ignore always.

Instead, can't we keep it separate so that it becomes an implementation detail of the presentation layer (CLI UX/IDE/UI) to consume the CLI command contracts (just the data part) and present it the way they want to. Similar to how the azure portal consumes API's and presents it the way they want to for consumers.

So that our layering can be like CLI UX layer (UI) -> CLI Command layer (API contracts) -> Azd Providers (Service) -> Actual Azure RP's (DB's).

@rajeshkamal5050 and I chatted a bit about his feedback today in our 1:1.

The crux of the problem here is that some of our operations (like infra create) can take a long time and so simply waiting until the end of the operation to produce a result will lead to a bad user experience because it will appear the tool is hung while it is actually making progress. When run interactively, we use the spinner to show that we are doing work/not hung as well as writing a set of progress messages as the operation goes. The goal here was to do the same thing, but for JSON output. This is sort of a "push model", you run an operation and the CLI streams a set of events (encoded in JSON) that describe what's going on.

The other model we could have approached in a pull/poll model, where when the operation starts azd gives some sort of token or something that a consumer can use to poll the current status. This looks similar to how ARM works, where a deployment gives you a deployment ID and then you can ask the control plane for the current status of the operation as well as use that deployment ID to pull information about the sub-operations that are happing.

That model is interesting and may be where we want to end up longer term. In that world, azd starts to feel much more like a language server than a CLI, but that may be the right long-term story for editor integration. It could also make some of the stuff we'd like to do longer term like prompting for data a little easier.

But for now, we agreed to stick with what we have here. This gets us to a place where consumers can show the same output the CLI would have shown (modulo color) without having to do any complex work on their own. For example, previously when we were emitting just the set of operations, VS had to take that array and, on each update, figure out what had changed to report resource creation. This is work the CLI was already doing as well, so it's nice that VS can get out of that game.

After a great discussion with @philliphoff and @weikanglim yesterday, I made some changes to the PR. We decided that we should write the progress messages to a different stream than the output. This allows us to not have to envelope the "return value" of the command, which provides better UX and gives a consistent story to consumers: When calling azd with --output=json a single JSON object will be written to stdout.

If a consumer wants to monitor progress they can read JSON objects from stderr. These objects are in an envelope, so consumers should ignore event types they don't understand. Right now the only type we have is "consoleMessage", but we may add more later:

Here's text from the follow up commit:

Based on discussions with Wei and Phillip, we've decided to make some changes to how we report progress when --output=json is set.

In the previous commit, we would write progress information as well as the final result of the command to stdout. This meant that we needed to have a type parameter on all the JSON data we emittied so that consumers could understand how to decode things. Furthermore, we decided to wrap these progress messages in an envelope so that the metadata and data were seperated and we wouldn't run into collisions where we a property from the data we wanted to emit clashed with a property name for some metadata we needed to provide to consumers. This strategy was workable, but it lead to sort of bad UX on the command line, as the result of every command now looked like:

{
  "type": "someEventType",
  "data": // a JSON value that represents the actual data
}

Which meant consumers would always need to access the data property to get the information they were interested in.

Furthermore, this cost was going to be paid by all commands (not just ones that emit progress) so that our output was regular and also to give us the flexability to return more status information over time.

After discussion, we decided to instead adopt the following model:

When a command is run with --output=json the result of the command, in JSON form is printed to stdout. Since only a single value will ever be permitted, there is no need to have an envelope since the consumer knows, a priori the shape of the result given the command they are executing.

During an operation, when --output=json is specified, the CLI may also emit a stream of events to stderr which contain information about the operation that is in progress. These events are wrapped in an envelope (which includes both a type property, telling consumers the shape of the data and a timestamp as to when the event was emitted. Consumers may ignore the stderr stream completely or they may choose to read JSON objects, one at a time, from the stream and decode them if they understand the type of the event. Over time, the CLI may start to emit more events over this output stream, so consumers SHOULD ignore events with type's they don't understand.

We also discussed how we will want to report errors from commands when --output=json is true. We decided that in the case of a fatal error, we'll write a structured error object to stdout (instead of the normal result of the command, which we don't have). Consumers will need to look at the exit code of azd. When zero, they can interpret the object written to stdout in the usual way, but when non zero, they should instead assume the object represents an error and they can decode it in that manner. Wei is working on the shape of the error in that case.

Now, when running azd infra create --output=json, we have output like the following (note that the stderr and stdout streams are "intermingled" here, as you would see in cmd.exe if you hadn't redirected streams, but the messages are going to different places:

{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:09:07.3380684-07:00",
  "data": {
    "message": "\nInfrastructure provisioning plan completed successfully\n"
  }
}
{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:09:13.4784512-07:00",
  "data": {
    "message": "Provisioning Azure resources can take some time.\n\nYou can view detailed progress in the Azure Portal:\nhttps://portal.azure.com/#blade/HubsExtension/DeploymentDetailsBlade/overview/id/%2Fsubscriptions%2Ffaa080af-c1d8-40ad-9cce-e1a450ca5b57%2Fproviders%2FMicrosoft.Resources%2Fdeployments%2Fmatell-azd-json\n\n"
  }
}
{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:09:16.6614146-07:00",
  "data": {
    "message": "Created Resource group: rg-matell-azd-json\n"
  }
}
{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:09:32.0064925-07:00",
  "data": {
    "message": "Created App Service plan: plan-itzzednmw27ng\n"
  }
}
{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:09:49.4528654-07:00",
  "data": {
    "message": "Created Web App: app-itzzednmw27ng\n"
  }
}
{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:10:20.4436239-07:00",
  "data": {
    "message": "\nAzure resource provisioning completed successfully\n"
  }
}
{
  "outputs": {
    "WEBSITE_URL": {
      "type": "string",
      "value": "https://app-itzzednmw27ng.azurewebsites.net/"
    }
  },
  "resources": [
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json"
    },
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json/providers/Microsoft.Web/serverfarms/plan-itzzednmw27ng"
    },
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json/providers/Microsoft.Web/sites/app-itzzednmw27ng"
    },
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json/providers/Microsoft.Web/sites/app-itzzednmw27ng/config/appsettings"
    }
  ]
}

Here you can see an example of the redirection working:

C:\dd\azure\azure-dev\cli\azd\test\functional\testdata\samples\webapp>azd provision --output=json 2>messages.txt
{
  "outputs": {
    "WEBSITE_URL": {
      "type": "string",
      "value": "https://app-itzzednmw27ng.azurewebsites.net/"
    }
  },
  "resources": [
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json"
    },
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json/providers/Microsoft.Web/serverfarms/plan-itzzednmw27ng"
    },
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json/providers/Microsoft.Web/sites/app-itzzednmw27ng"
    },
    {
      "id": "/subscriptions/faa080af-c1d8-40ad-9cce-e1a450ca5b57/resourceGroups/rg-matell-azd-json/providers/Microsoft.Web/sites/app-itzzednmw27ng/config/appsettings"
    }
  ]
}

C:\dd\azure\azure-dev\cli\azd\test\functional\testdata\samples\webapp>type messages.txt
{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:09:07.3380684-07:00",
  "data": {
    "message": "\nInfrastructure provisioning plan completed successfully\n"
  }
}
{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:09:13.4784512-07:00",
  "data": {
    "message": "Provisioning Azure resources can take some time.\n\nYou can view detailed progress in the Azure Portal:\nhttps://portal.azure.com/#blade/HubsExtension/DeploymentDetailsBlade/overview/id/%2Fsubscriptions%2Ffaa080af-c1d8-40ad-9cce-e1a450ca5b57%2Fproviders%2FMicrosoft.Resources%2Fdeployments%2Fmatell-azd-json\n\n"
  }
}
{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:09:16.6614146-07:00",
  "data": {
    "message": "Created Resource group: rg-matell-azd-json\n"
  }
}
{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:09:32.0064925-07:00",
  "data": {
    "message": "Created App Service plan: plan-itzzednmw27ng\n"
  }
}
{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:09:49.4528654-07:00",
  "data": {
    "message": "Created Web App: app-itzzednmw27ng\n"
  }
}
{
  "type": "consoleMessage",
  "timestamp": "2022-10-21T10:10:20.4436239-07:00",
  "data": {
    "message": "\nAzure resource provisioning completed successfully\n"
  }
}

C:\dd\azure\azure-dev\cli\azd\test\functional\testdata\samples\webapp>

Azure Dev CLI Install Instructions

Install scripts

MacOS/Linux

May elevate using sudo on some platforms and configurations

bash:

curl -fsSL https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925/uninstall-azd.sh | bash;
curl -fsSL https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925/install-azd.sh | bash -s -- --base-url https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925 --version '' --verbose

pwsh:

Invoke-RestMethod 'https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925/uninstall-azd.ps1' -OutFile uninstall-azd.ps1; ./uninstall-azd.ps1
Invoke-RestMethod 'https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925/install-azd.ps1' -OutFile install-azd.ps1; ./install-azd.ps1 -BaseUrl 'https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925' -Version '' -Verbose

Windows

powershell -c "Set-ExecutionPolicy Bypass Process; irm 'https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925/uninstall-azd.ps1' > uninstall-azd.ps1; ./uninstall-azd.ps1;"
powershell -c "Set-ExecutionPolicy Bypass Process; irm 'https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925/install-azd.ps1' > install-azd.ps1; ./install-azd.ps1 -BaseUrl 'https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925' -Version '' -Verbose;"

Standalone Binary

• Linux - https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925/azd-linux-amd64.tar.gz
• MacOS - https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925/azd-darwin-amd64.zip
• Windows - https://azuresdkreleasepreview.blob.core.windows.net/azd/standalone/pr/925/azd-windows-amd64.zip

Container

docker run -it azdevcliextacr.azurecr.io/azure-dev:pr-925