Add `Write-AzFuncLog` cmdlet to the helper module to allow writing Azure Function user logs in an explicit way.

[daxian-dbw]

This is a feedback from the tech review within PowerShell team.

Currently PowerShell built-in Write-* cmdlets are redirected to the Azure Function log in the following mapping:

Write-* cmdlet (the target stream)	Log level
Write-Verbose     (verbose stream)	Trace
Write-Progress    (progress stream)	Trace
Write-Debug       (debug stream)	Debug
Write-Information (information stream)	Information
Write-Host        (information stream)	Information
Write-Warning     (warning stream)	Warning
Write-Error       (error stream)	Error
Write-Output      (output stream)	Information

The log level Critical doesn't have a corresponding mapping, and for Verbose, Progress, Host, and Output, it's not obvious for users to tell what log levels they are mapped to.
So the feedback is to provide another cmdlet to allow writing Azure Function user logs in an explicit way.

The proposal is Write-AzFuncLog, with the following syntax:

Write-AzFuncLog [-Message] <string> [-Level] <string> [<CommonParameters>]

As for the implementation, probably it should just call Write-Information -Tag internally with the log level as the tag.

[TylerLeonhardt]

As for the implementation, probably it should just call Write-Information -Tag internally with the log level as the tag

So for this cmdlet, we will not honor the Azure Functions log streams?

[daxian-dbw]

So for this cmdlet, we will not honor the Azure Functions log streams?

Today, we already handle information stream differently depending on the tag -- if the tag is __output__, then we prepend OUTPUT: to the message. Otherwise, we prepend INFORMATION:.
We can do similar things for Write-AzFuncLog, for example, Write-AzFuncLog blah -Level critical maps to Write-Information blah -Tag __critical__.

Downside of this implementation is that, user can write Write-Information -Tag __critical__ directly in script ... which would be annoying. But I think that's OK if they want to confuse themselves 😆

[TylerLeonhardt]

Well the downside to it as well is that, if they do:

Write-AzFuncLog blah -Level trace

It will show up in the logs as:

TRACE: blah

Regardless of the trace level you set in the host.json.

So if you set your host.json to exclude trace/Verbose level logs and just have information and error logs, these logs will still show up since you're always writing to the information stream.

[daxian-dbw]

No, you missed my points. We will have to change the even handler for the information stream. When the tag is __trace__, we don't write the message to the information level log, but to the trace level log. Same to other tags like __warning__ and etc.

[TylerLeonhardt]

Is there a reason for Write-Information -Tag __trace__ when we can do Write-Verbose under the hood?

[TylerLeonhardt]

as in...

Write-AzFuncLog blah -Level Trace
# just calls
Write-Verbose blah -Verbose

[daxian-dbw]

Ideally, that would be better. But we don't have an existing cmdlet mapping to Critical, so we still need to do something as I mention above.
Also, for Write-Verbose, we add Verbose: prefix to the message in the stream handler, which we don't want if the user is using Write-AzFuncLog -Level Trace. Same to the other existing cmdlets.

[TylerLeonhardt]

I see. That makes sense. I agree It would be nice to cover all of the Azure Functions log levels.

I guess my biggest question is... Do we know customers want this? Or will the normal write-* cmdlets suffice?

I remember @dfinke and a couple others mentioning that they want an environment variable to test for so that they can share code between an Azure Function and just running a script with pwsh.exe.

In that case, a Write-AzFuncLog wouldn't be too useful.

Our programming model today is very close (exception: Push-OutputBinding) to regular pwsh.exe.

We should discuss if we want to diverge from that, or keep to that.

I know you're not suggesting to remove Write-* but I remember @joeyaiello mentioning we should only be additive when requested 😊

[daxian-dbw]

Do we know customers want this? Or will the normal write-* cmdlets suffice?

This was brought up by Jim in the review dry run. There are two concerns:

1. User cannot write critical level log.
2. User has to do extra configuration to see verbose/debug messages written from the script, because, IIRC, the information and above levels are enabled by default.

For 1, I agree that critical level should be supported for completeness.
For 2, a proposal was: make all built-in write-* cmdlets write messages to the information level log, and using prefix like VERBOSE:, PROGRESS: to differentiate them, so all of them will be visible by default just like in pwsh. I think this option also makes sense, but not super sure we should change to that.

Sure, we should discuss with @joeyaiello before implementation.

[TylerLeonhardt]

Another one of those "Functions is different than PowerShell" issues 😄

[TylerLeonhardt]

For number 1 on your list, I think it would be better to fill that gap a different way with a Write-Critical cmdlet that does what the others do. That way it's consistent with what's already in PowerShell. I don't think it's really... critical... personally though. Hence the request for feedback.

Also for number 2... I think it's a shift in mindset from someone writing a script interactively vs creating an application and deploying it. We've been hitting this "PowerShell ecosystem doesn't fit perfectly in the application model" pain in a few places like the "module dependency" issue for example. This is another pain point.

Do you bombard someone with logs that can't really be filtered like any other Function App? Or do we tell our customers that they should follow the docs on configuring logging?

Hard to tell what the best way forward is... but I think feedback can help us answer it.

[daxian-dbw]

I don't think it's really... critical... personally though. Hence the request for feedback.

I think the critical concept in logging is determined by the business logic of a Function implementation. Maybe it's not an error in script running, but the state of something makes a critical log necessary.

For number 2, the way I'm thinking is that, when I'm using Write-Verbose -Verbose in my script, I don't necessarily mean to have my verbose message written to the trace level log. Instead, most of time, I just want to see them displayed to me truly as verbose messages. That's why I think that proposal also makes sense to me. But, for Write-Error, Write-Information, Write-Debug and Write-Warning, their names match the log level so well that it would be confusing if they don't really write to the corresponding logs. Hence, like I said, I'm not super sure about it.

Do you bombard someone with logs that can't really be filtered like any other Function App?

Haven't heard a user complaint yet, but we don't have much usage today anyways.

[joeyaiello]

Per our discussion, we should talk to the Functions team about how critical is used in another languages.

/cc @asavaritayal @fabiocav

[JustinGrote]

At the very least, just allow the option to expose the TelemetryClient as a powershell variable, then we can call it directly to write whatever custom logs we want, in addition to the existing "native" powershell stream interface by way of the iLogger

If telemetryclient is available then I can write critical there, and the community can write powershell functions for Write-Critical, or whatever, that leverage that interface, in addition to the wide variety of stuff I might want to do like track an Event in application insights, etc.

EDIT: For reference, the javascript worker exposes it as applicationInsights.defaultClient, so there is precedence for this sort of thing.
https://docs.microsoft.com/en-us/azure/azure-monitor/app/api-custom-events-metrics#get-a-telemetryclient-instance