Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Replace TraceWriter with an Interface to improve code testability #293

Closed
cmatskas opened this issue May 16, 2017 · 55 comments

Comments

Projects
None yet
@cmatskas
Copy link
Collaborator

commented May 16, 2017

At the moment Functions in C# take a TraceWriter as a method parameter. This means that testing locally becomes a challenge as it's very hard to mock this. Ideally the method parameter should be an interface like ILogger that allows to easily mock this during testing

@fabiocav

This comment has been minimized.

Copy link
Member

commented May 16, 2017

Done :)

As of our last release, you can use an Microsoft.Extensions.Logging.ILogger instead of a TraceWriter and an ILogger instance will be provided.

@brettsam can share more details.

@fabiocav fabiocav closed this May 16, 2017

@cmatskas

This comment has been minimized.

Copy link
Collaborator Author

commented May 16, 2017

Booya! There's been no information around this so apologies for raising...I'm not part of the inner circle :(
Thanks for the quick response!

@DivineOps

This comment has been minimized.

Copy link

commented Jun 3, 2017

Hi @fabiocav,
If I switch to ILogger, I am having an issue with local logs displaying in AzureFunctions.CLI.
When I publish the function, the function logs are displayed, along with the function pulse. But when running locally only the function pulse is displayed (although no errors are thrown).
Is this a configuration issue?
Can you share a working code sample?

Also, it is worth noting that we are talking about Microsoft.Extensions.Logging.ILogger, because there is more than one library that defines ILogger

@brettsam

This comment has been minimized.

Copy link
Member

commented Jun 5, 2017

The missing logs in the CLI is an issue being tracked here: Azure/azure-functions-core-tools#130 -- we're looking into it.

And yes, it's the Microsoft.Extensions.Logging.ILogger.

@DivineOps

This comment has been minimized.

Copy link

commented Jun 5, 2017

Thanks Brett!

@fabiocav

This comment has been minimized.

Copy link
Member

commented Jun 5, 2017

Thanks for pointing out the ambiguity, @DivineOps. I've updated the original comment to make it clear I was referring to the Microsoft.Extensions.Logging.ILogger interface.

@DivineOps

This comment has been minimized.

Copy link

commented Jun 7, 2017

Ironically, I am finding it easier to mock TraceWriter than ILogger, since ILogger only exposes a single non-static Log method which requires a long list of parameters :)

@dersia

This comment has been minimized.

Copy link

commented Jun 9, 2017

Hi there I just realized, that there seems to be an issue with the new ILogger. If I select the ILogger, everything works as expected and there is no issue at all, but if I consume a nuget-package which has dependency on Microsoft.Extensions.Logging.Abstractions it stops working. I actually get a failure upon loading the function:

Microsoft.Azure.WebJobs.Host: Cannot bind parameter 'log' to type ILogger. Make sure the parameter Type is supported by the binding. If you're using binding extensions (e.g. ServiceBus, Timers, etc.) make sure you've called the registration method for the extension(s) in your startup code (e.g. config.UseServiceBus(), config.UseTimers(), etc.)

@brettsam

This comment has been minimized.

Copy link
Member

commented Jun 9, 2017

@dersia -- I've opened a new issue for this: #334 -- can you hop over to that issue and let me know what package you added that broke this?

@tafs7

This comment has been minimized.

Copy link

commented Jun 13, 2017

@fabiocav Is this new ILogger interface documented anywhere on https://docs.microsoft.com ?

Is there any reference code or samples of how to leverage this both from a script function (e.g. csx) and from a pre-compiled function?

I assume we need to add a nuget package reference to the pre-compiled class library (Install-Package Microsoft.Extensions.Logging.Abstractions -Version 1.1.2), correct? I notice there's a pre-release pkg version 2.0, what is the difference? Which is supported by Azure Functions?

@cmatskas

This comment has been minimized.

Copy link
Collaborator Author

commented Jun 13, 2017

Seconded! A demo/sample code would awesome to help with adoption. Thanks

@brettsam

This comment has been minimized.

Copy link
Member

commented Jun 13, 2017

I've just put together an ILogger wiki topic here: https://github.com/Azure/azure-webjobs-sdk-script/wiki/ILogger. I'll add more to it over time, but that should give some information on background and usage. Feel free to weigh in here with more questions and I'll fill them in on the wiki page.

@tafs7

This comment has been minimized.

Copy link

commented Jun 13, 2017

@brettsam quick questions - can the ILogger interface be used from local/debug (CLI)?

@justinyoo

This comment has been minimized.

Copy link

commented Jun 15, 2017

@tafs7 Unfortunately, not yet. But Azure Functions Core Tools beta.101 will include the update.

https://github.com/Azure/azure-functions-cli/milestone/8

@nhwilly

This comment has been minimized.

Copy link

commented Jun 22, 2017

How can I bind to an ILogger<T>? I am trying to reuse code from my MVC package and in that system, the Microsoft.Extensions.Logging requires a type parameter.

@nhwilly

This comment has been minimized.

Copy link

commented Jun 23, 2017

Sorry, let me ask that more clearly.

I am sharing business logic methods (in a DLL) between my MVC app and my Azure functions. MVC DI takes care of injecting an ILogger<T> when needed, but Azure Functions gives me an ILogger.

I know this is a completely noobish question, but I can't seem to create an ILogger<T> properly in Azure Functions so I can pass it along to my business logic method.

I tried creating a LoggerFactory in AF and then adding a provider to it, but that always fails with a method missing error.

I've just refactored the entire project to use Azure Functions this way and I'm stuck. Any direction would be greatly appreciated.

@brettsam

This comment has been minimized.

Copy link
Member

commented Jun 23, 2017

Good question. I haven't looked much at ILogger<T>. An ILogger<T> looks like it is an ILogger that stores the name of T as the category name. For Functions we don't use a Type to generate our category (the type names get pretty unwieldy), so we use the category "Functions" for all of our Loggers that we pass to customer functions. I can try to think through what this would mean to pass a function an ILogger<SomeType>. Maybe we could make it work if there's enough demand for it.

Since ILogger<T> : ILogger (with no additional properties or methods), is it possible to change your business logic to use ILoggers? Even if MVC DI injects an ILogger<T>, I think your business logic should be able to operate on an ILogger.

https://github.com/aspnet/Logging/blob/dev/src/Microsoft.Extensions.Logging.Abstractions/ILoggerOfT.cs

@nhwilly

This comment has been minimized.

Copy link

commented Jun 23, 2017

@brettsam Thanks for responding. That was the first thing I tried. But the dependency injection in MVC doesn't like trying to resolve an ILogger or I don't know what I'm doing. Probably the latter.

I'm pretty sure I'm not the only one with libraries trying to be shared between MVC projects and AF. It would be great if stuff just lined up.

As I understand it, there's no access to DI in AF, so I have to create a new ILogger<T> if I want to use my existing code unmolested.

That said, sharing code between the projects is the only thing that makes any sense, so I'm pretty committed to modifying all things necessary to make that happen. Just point and I'm there...

@brettsam

This comment has been minimized.

Copy link
Member

commented Jun 23, 2017

This was the example I remembered seeing: https://docs.microsoft.com/en-us/aspnet/core/fundamentals/logging#how-to-create-logs.

Assuming that I'm looking at it correctly, the DI is passing an ILogger<T>, yet it is stored in the class as an ILogger. Then any business logic should be able to work off of ILogger. So you don't need to change your DI setup, but the business logic could change everything from ILogger<T> to ILogger. I think that would work since ILogger<T> doesn't add anything to the ILogger interface.

If we tried to support ILogger<T> as a function parameter, I'm not entirely sure what T you'd use since you don't actually have a Type when you're writing functions (in the portal at least). I think what we'd do instead is add support for using an ILoggerFactory as a function parameter, which would allow you to call CreateLogger<T> yourself if you wanted. But that'll require some new code (and time :-)). I was hoping the plan above would work so you can get moving forward ASAP without the need for us to unblock you.

BTW -- we're looking at DI access for functions. I have a prototype that needs a little work still. The idea would be you could add your own providers to ILoggerFactory (and other services). Then, all Loggers would be constructed from that LoggerFactory. We're tracking that here: Azure/azure-functions-host#1579.

@nhwilly

This comment has been minimized.

Copy link

commented Jun 23, 2017

Exactly. In the sample code from here shown below shows it in the method signature with <T> and the local field is just ILogger. That's how I set up my library.

But if I try to call that same method from my AF where there is no DI, I can't pass in ILogger<T> since I don't have it, and it doesn't like ILogger at all.

If I change the signature of my method to just take an ILogger, the DI breaks.

I know I'm missing something obvious, but I can't figure out what.

public class TodoController : Controller
{
private readonly ITodoRepository _todoRepository;
private readonly ILogger _logger;

public TodoController(ITodoRepository todoRepository,
    ILogger<TodoController> logger)
{
    _todoRepository = todoRepository;
    _logger = logger;
}
@brettsam

This comment has been minimized.

Copy link
Member

commented Jun 23, 2017

Would you mind sharing the code for how you're trying to do this in Functions? If you don't want to post it publicly, you can send it to my email (listed in my Github profile). I want to see what we can do to get this working.

@nhwilly

This comment has been minimized.

Copy link

commented Jun 23, 2017

@nhwilly

This comment has been minimized.

Copy link

commented Jun 23, 2017

Ok, it's in your email. Thanks again.

@brettsam

This comment has been minimized.

Copy link
Member

commented Jun 23, 2017

That gives me a clearer picture, thanks. In my head I was envisioning the business logic all encapsulated in your own class -- let's call it MyBusinessLogicHelper. So I was imagining you register that with the DI, and then your classes constructed by MVC were constructed like:

public class MyRepository(MyBusinessLogicHelper helper, ILogger<T> logger)
{
    // Helper only operated on ILogger, which would be okay. 
    // And MyBusinessLogicHelper was the thing you would re-use in functions, rather than the repository itself.
}

Short of refactoring that, one option you could use right now is to write a wrapper class that implements ILogger<T>, and just pass it our ILogger. Then you could pass that to your repository instead of ours.

Something like:

private class LoggerWrapper<T> : ILogger<T>
{
    private ILogger _inner;
    public LoggerWrapper(ILogger inner)
    {
        _inner = inner;
    }

    public IDisposable BeginScope<TState>(TState state)
    {
        return _inner.BeginScope(state);
    }

    public bool IsEnabled(LogLevel logLevel)
    {
        return _inner.IsEnabled(logLevel);
    }

    public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
    {
        return _inner.Log(logLevel, eventId, state, exception, formatter);
    }
}

And you could use it like:

var loggerOfT = new LoggerWrapper<Account>(logger);

It's not ideal, but could get you moving forward while we come up with a nicer solution.

@nhwilly

This comment has been minimized.

Copy link

commented Jun 23, 2017

Wow, great. I'll try to implement it right now.

Actually I have a generic Service<T> base class that is extended for the various types in the system and it indeed does hide the repository. My API and MVC controllers just use the services to perform the same functions. Controllers do almost nothing at this point.

I elected not to use the Service<T> classes in AF as they are heavier than just the repository and the AF functionality is pretty simple. I didn't want to make the functions too code heavy. Looking at it again, I might go back to that approach.

Even if I did use the Service class approach, the DI would still try to inject an ILogger<T> into the Service<T> so I would be back to the same problem again, just one level up.

As for being ideal, heh, anything that gets me past this is just fine.

Can't thank you enough.

@nhwilly

This comment has been minimized.

Copy link

commented Jun 23, 2017

Well, I got this...
Microsoft.Azure.WebJobs.Host: Cannot bind parameter 'logger' to type ILogger. Make sure the parameter Type is supported by the binding. If you're using binding extensions (e.g. ServiceBus, Timers, etc.) make sure you've called the registration method for the extension(s) in your startup code (e.g. config.UseServiceBus(), config.UseTimers(), etc.).

I even pulled everything out of the AF method. If I put ILogger in the signature, it throws that error. Could this be tied to a specific version of Microsoft.Extensions.Logging.Abstractions? I'm using 1.1.2

Also, in the same code, I pulled the return out of the Log<TState>... method as it is a void.

@nhwilly

This comment has been minimized.

Copy link

commented Jun 24, 2017

Update: Well I can see how this would work but I'm caught in some kind of version wormhole.

I can't get my MVC project to work unless I include Microsoft.Extensions.Logging v1.1.2 which apparently comes with Microsoft.Extensions.Logging.Abstractions as part of the deal (although I can't find it referenced anywhere in the NuGet dependencies).

If I just leave my function project with the defaults, it complains that my business DLL is referencing v1.1.2 while the function is referencing v1.1.1 and so it won't compile.

If I attempt to upgrade my function project to Microsoft.Extensions.Logging v1.1.2, it compiles, but then I get the error message above about not being able to bind to ILogger.

So I downgraded just the business DLL that I'm sharing to 1.1.1, leaving everything else at 1.1.2 and it's compiling and seems to be running.

Naturally, I ripped out everything that wasn't tied down just to eliminate the errors, so the logs are going into the ether somewhere. I'll try to gently reintroduce a proper destination for the logging.

Maybe ApplicationInsights if I could just figure where those logs go... :)

Thanks again, and I'll keep you posted on how this works out.

@brettsam

This comment has been minimized.

Copy link
Member

commented Jun 26, 2017

We have a version conflict with the latest logging assemblies. We're tracking that elsewhere -- Azure/azure-functions-host#1570. We will get the proper assembly redirects in place so that this doesn't happen.

@nhwilly

This comment has been minimized.

Copy link

commented Jun 26, 2017

Wow, OK, great to know. Thanks!

@prabhakarreddy1234

This comment has been minimized.

Copy link

commented Oct 5, 2017

I think it's still broken. any ETA on this? I cannot upgrade Microsoft.Extensions.Logging.Abstractions to 1.1.2 . Still working on 1.1.1 .

@RizwanSharp

This comment has been minimized.

Copy link

commented Oct 13, 2017

Swapping TraceWritter with ILogger works fine in .Net Standard function project but not in project targeting 4.6.1. It says it cannot bind to 'log' parameter.

Function SDK version is 1.0.5. Isn't supported in both .Net Standard and regular .Net Framework?

@i-movo

This comment has been minimized.

Copy link

commented Oct 31, 2017

The Azure portal doesn't seem to display logs being generated using ILogger.

Under functions apps> FunctionName > Monitor there is a Logs window which does not work with ILogger, works fine with TraceWriter.

@wilkovanderveen

This comment has been minimized.

Copy link

commented Jan 19, 2018

Any progress on this one? I am using .NET 4.6.1 Functions and am trying to use the ILogger from a function using the .NET standard (2.0.0) version of Microsoft.Extensions.Logging. and it still does not seem to find a logger implementation according to the message I am getting:

Microsoft.Azure.WebJobs.Host: Error indexing method 'SendOrderPlanningConfirmation.Run'. Microsoft.Azure.WebJobs.Host: Cannot bind parameter 'logger' to type ILogger. Make sure the parameter Type is supported by the binding. If you're using binding extensions (e.g. ServiceBus, Timers, etc.) make sure you've called the registration method for the extension(s) in your startup code (e.g. config.UseServiceBus(), config.UseTimers(), etc.).

This seems the same issue as others are having.

@KZeronimo

This comment has been minimized.

Copy link

commented Jan 19, 2018

@wilkovanderveen - we are experiencing the exact same issue - Microsoft folks how do we utilize ILogger within an Azure Function targeting .NET 4.6.1

@brettsam

This comment has been minimized.

Copy link
Member

commented Jan 19, 2018

Does it work when you use version 1.1.1 of Microsoft.Extensions.Logging?

@KZeronimo

This comment has been minimized.

Copy link

commented Jan 19, 2018

It does run successfully (running locally) - trying to confirm now that my own custom log traces using log.Log(LogLevel.Trace, 0, state, null, Formatter) are ending up in Application Insights

Is the reason why the version 2.0.0 of Microsoft.Extension.Logging is failing is because it depends on .NET Standard 2.0? I was hopeful that had been fixed

@brettsam

This comment has been minimized.

Copy link
Member

commented Jan 19, 2018

The problem is that the Functions host takes some of these dependencies itself (in this case, it depends on 1.1.1). So no matter what you reference while building, you'll run against the Functions versions. Your compiled code is looking for v2.0.0, but when it runs, the host loads v1.1.1. And we don't have 'backwards' binding redirects that would take a 2.0.0 reference and redirect it to 1.1.1.

It's not just an issue with this assembly; there's a lengthy, ongoing discussion about this here: Azure/azure-functions-host#992

@KZeronimo

This comment has been minimized.

Copy link

commented Jan 19, 2018

Thank you for the link to the issue - I've been trying to track whether binding redirect support is available yet in az functions or not

Is there a simple way to determine what the Functions host takes dependencies on itself so we can have a chance of detecting when this mismatch scenario will occur and additionally know what version of dependency we need to compile against?

For v1 of functions the redirects in the web.config seems like a good place to start

@KZeronimo

This comment has been minimized.

Copy link

commented Jan 19, 2018

@brettsam - we can break this off into a new issue - where do you suggest

How do we wire in Application Insights Logging Provider for ILogger - trying to avoid using Telemetry Client directly and we can't seem to get this to work

This snippet runs and we can see logs in Application Insights for function execution start and function executed successfully but we have no idea where log.Log(LogLevel.Trace, 0, state, null, Formatter) is being written

Here is the expanded snipped

 public static class AzureFunctionsLogging
    {
        [FunctionName("Logging")]
        public static void Run([TimerTrigger("0 */1 * * * *")]TimerInfo myTimer, ILogger log)
        {
            var state = new Dictionary<string, object> {
                    {"CorrelationId", 1} ,
                    {"Message", "This is a custom log message"}
                };

            log.Log(LogLevel.Trace, 0, state, null, Formatter);
        }

        internal static string Formatter<T>(T state, Exception ex)
        {
            if (ex != null)
            {
                return ex.ToString();
            }

            var stateDictionary = state as Dictionary<string, object>;
            if (stateDictionary != null && stateDictionary.TryGetValue("Message", out object message))
            {
                return message.ToString();
            }
            return string.Empty;
        }

    }
@brettsam

This comment has been minimized.

Copy link
Member

commented Jan 19, 2018

@KZeronimo -- I've created an issue for you here: Azure/azure-functions-host#2335

@Kaegun

This comment has been minimized.

Copy link

commented Jan 29, 2018

I'm successfully running the code using the ILogger interface on my Functions (.NET 4.7), but no traces are emitted to the Function host's console window during testing. Inspecting the ILogger it seems there's a file logger implemented on it. Where would this logger be writing to?

@cmeiklejohn

This comment has been minimized.

Copy link

commented Jun 25, 2018

It's unclear from the thread -- was there ever a resolution to getting this working with .NET 4.6.1? I only saw that @Kaegun has it working with .NET 4.7.

I'm also running into the same issue:

Microsoft.Azure.WebJobs.Host: Error indexing method '$METHOD_NAME'. Microsoft.Azure.WebJobs.Host: Cannot bind parameter 'log' to type ILogger. Make sure the parameter Type is supported by the binding. If you're using binding extensions (e.g. ServiceBus, Timers, etc.) make sure you've called the registration method for the extension(s) in your startup code (e.g. config.UseServiceBus(), config.UseTimers(), etc.).
@csmarvz

This comment has been minimized.

Copy link

commented Jul 4, 2018

@cmeiklejohn - Tried today with .net 4.6.1, the AF is indeed logging both locally and published on azure.

Maybe the snippet below will help you:

using System.Net.Http;
using System.Threading.Tasks;
using Microsoft.Azure.WebJobs;
using Microsoft.Azure.WebJobs.Extensions.Http;
using Microsoft.Extensions.Logging;

namespace LoanApplicationsFunctions
{
    public static class MakeApplication
    {
        [FunctionName("MakeApplication")]
        public static async Task<LoanApplication> Run(
            [HttpTrigger(AuthorizationLevel.Function, "get", "post", Route = null)]
            HttpRequestMessage req,
            ILogger log)
        {
            log.Log(LogLevel.Information,
                0,
                new {Message = "C# HTTP trigger MakeApplication function processed a request." },
                null,
                (state, exception) => { return state.Message; });
        }
    }
}
@brettsam

This comment has been minimized.

Copy link
Member

commented Jul 5, 2018

@cmeiklejohn -- Sorry, I missed your question. The issue is likely related to the version of Microsoft.Extensions.Logging.Abstractions that you're referencing. If you reference 1.1.1.0, does it work?

@CalvinDale

This comment has been minimized.

Copy link

commented Jul 7, 2018

I'm encountering this issue while attempting to reference a class library that uses EntityFrameworkCore 2.1.1 which is dependent upon Microsoft.Extensions.Logging (>= 2.1.1) which is dependent upon Microsoft.Extensions.Logging.Abstractions (>= 2.1.1) which is of course greater than 1.1.1.0. And so it throws.

@aderderian

This comment has been minimized.

Copy link

commented Aug 9, 2018

Seeing the lack of Functions ILogger logging to portal stream logs as well as having difficulty being able to inject ILogger into my service layers. Any updates would be awesome.

@brettsam

This comment has been minimized.

Copy link
Member

commented Aug 9, 2018

@CalvinDale -- are you using Functions v1?

@aderderian -- Is that also with Functions v1? you should be seeing ILogger going to the portal streaming logs. Can you share your host.json configuration and show how you're using ILogger in a sample function?

@aderderian

This comment has been minimized.

Copy link

commented Aug 9, 2018

Hey @brettsam thanks for responding. I am on V2 beta. Latest and greatest of it with .NET Core 2.1. I switched from Tracewriter log to ILogger and notice the output was only going to Application Insights. I have nothing in my host.json file at the moment, so that may be the issue.

Secondly, I have a service method signature like this 👍
public ContestService(string dbName, IDocumentClient documentClient, ILogger logger)

In the WebApp I can easily inject this ILogger, but in Azure Functions I am stuck with ILogger only. How can I make this work with my service layer? Thanks!

@brettsam

This comment has been minimized.

Copy link
Member

commented Aug 9, 2018

I just gave it a try on v2 with a really simple function on 2.0.11946.0:

using System.Net;

public static Task<HttpResponseMessage> Run(HttpRequestMessage req, ILogger log)
{
    log.LogInformation("C# HTTP trigger function processed a request.");
    return Task.FromResult(new HttpResponseMessage());
}

And I see the log coming to the streaming logs: 2018-08-09T15:12:54.555 [Information] C# HTTP trigger function processed a request.

We use the Microsoft.Extensions.Logging.ILogger -- are you using the same type in your service layer? If it's the same type, you should just be able to pass it directly in.

@aderderian

This comment has been minimized.

Copy link

commented Aug 9, 2018

OK I will double check. Which area of portal are you viewing them in?

It's not an ILogger in my service layer, it's ILogger type.

@CalvinDale

This comment has been minimized.

Copy link

commented Aug 14, 2018

@brettsam I think it was v2; but I'm not entirely certain. I think I tried them both. I subsequently deleted the project because I found another way to perform the computation.

@aderderian

This comment has been minimized.

Copy link

commented Sep 12, 2018

This seems to be working now. I am not sure if something changed, but looks good in Azure Portal now.

@aderderian

This comment has been minimized.

Copy link

commented Sep 18, 2018

Annnnd now it's not working again. It's pretty hard to get a consistent experience here.

@brettsam

This comment has been minimized.

Copy link
Member

commented Sep 18, 2018

@aderderian -- Can you give me a repro of how you're viewing these? The streaming logs are being written to files on-disk, and then displayed in the portal (you can view them in Kudu under . That only happens when you're actively using the portal (we set a flag that times out after 15 minutes). After that, they're no longer written. So, they should be written as long as you're actively in the portal.

Can you:

  • Check the file system in Kudu? See if the logs you expect are there. They'd be under D:\home\LogFiles\Application\Functions\function
  • While you're in the portal and not seeing the logs, check the debug_sentinel file under D:\home\LogFiles\Application\Functions\Host. Was it last updated recently?
@aderderian

This comment has been minimized.

Copy link

commented Sep 18, 2018

Hey @brettsam thanks for the quick response! Sooo it looks like they're now working again. But the reason they were not working prior was due to a bad value in my application settings. In that event nothing was being written there, but it was going to app insights...which led me to the solution.

Any reason why it would not show in log stream in that scenario?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.