Skip to content

Cleanup of public overloads for ILoggerFactory #674

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

Merged
merged 8 commits into from
Feb 13, 2020
Merged

Cleanup of public overloads for ILoggerFactory #674

merged 8 commits into from
Feb 13, 2020

Conversation

bart-degreed
Copy link
Contributor

Ensured consistent passing along of ILoggerFactory parameter downwards to base classes and dependencies. I ended up making them all non-optional, because it is easy to forget passing it (compiler does not warn).
Callers can still pass null as a value, but that should be very rare, since ASP.NET Core includes built-in logging that is automatically registered.

In the process, I added some missing namespaces in examples (types were in global namespace).

BaseJsonApiController<T> and BaseJsonApiController<T, TId>:

  • Made types abstract with protected constructors, fixed related tests
  • Ensure all overloads have ILoggerFactory parameter and its value is passed downwards
  • Have overloads call each other, so that fields assignment occurs only once

JsonApiCmdController<T> and JsonApiCmdController<T, TId>, JsonApiQueryController<T> and JsonApiQueryController<T, TId>:

  • Ensure all overloads have ILoggerFactory parameter and its value is passed downwards
  • Changed IResourceService<> parameter into IResourceQueryService<> / IResourceCmdService (still allows to pass IResourceService<>, because it implements both)
  • Aligned parameter names with base class

JsonApiController<T> and JsonApiController<T, TId>:

  • Bugfix where loggerFactory was assigned the value null while passing it downwards!
  • Ensure all overloads have ILoggerFactory parameter and its value is passed downwards

DefaultResourceRepository<TResource> and DefaultResourceRepository<TResource, TId>:

  • Removed unneeded constructor overload

DefaultExceptionFilter:

  • Added null conditional operator, because at logging time the logger is assumed to be possibly null.

All unit tests succeed with these changes.

Ensured consistent passing along of `ILoggerFactory` parameter downwards to base classes and dependencies. I ended up making them all non-optional, because it is easy to forget passing it (compiler does not warn).
Callers can still pass `null` as a value, but that should be very rare, since ASP.NET Core includes built-in logging that is automatically registered.

In the process, I added some missing namespaces in examples (types were in global namespace).

`BaseJsonApiController<T>` and `BaseJsonApiController<T, TId>`:
- Made types abstract with protected constructors, fixed related tests
- Ensure all overloads have `ILoggerFactory` parameter and its value is passed downwards
- Have overloads call each other, so that fields assignment occurs only once

`JsonApiCmdController<T>` and `JsonApiCmdController<T, TId>`, `JsonApiQueryController<T>` and `JsonApiQueryController<T, TId>`:
- Ensure all overloads have `ILoggerFactory` parameter and its value is passed downwards
- Changed `IResourceService<>` parameter into `IResourceQueryService<>` / `IResourceCmdService` (still allows to pass `IResourceService<>`, because it implements both)
- Aligned parameter names with base class

`JsonApiController<T>` and `JsonApiController<T, TId>`:
- Bugfix where loggerFactory was assigned the value `null` while passing it downwards!
- Ensure all overloads have `ILoggerFactory` parameter and its value is passed downwards

`DefaultResourceRepository<TResource>` and `DefaultResourceRepository<TResource, TId>`:
- Removed unneeded constructor overload

`DefaultExceptionFilter`:
- Added null conditional operator, because at logging time the logger is assumed to be possibly `null`.

All unit tests succeed with these changes.
Copy link
Member

@maurei maurei left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the work on this. I have made a bunch of small comments/compliments targeting specific lines of code. Apart from that I have two general comments about ILoggerFactory

  1. Optional parameter. First of all good job on adding ILoggerFactory in the controller classes in the cases where it was missing and as such making it more consistent. I do think we should consider sticking to it being an optional dependency because of the following reasons
    • backward compatibility: previously this parameter was optional (or missing) and placed last. If users were already injecting it, they will have to reorder their dependencies, and if they weren't injecting it they probably didn't need to but will now still be required to add it to their dependencies.
    • For those who don't need logging it only adds noise to the constructor of their controller by having to null it out.
  2. Usage of ILogger<T> I think we should consider injecting the generic ILogger<T> instead of ILoggerFactory because of the following reasons
    • In principle it is a violation of SRP to inject a factory, see this post. Nevertheless it happens in multiple places so this is not the strongest argument, but in the examples of the official docs they're using the generic ILogger<T> too anyway.
    • If we expect an ILoggerFactory in our internal classes on which we then call CreateLogger<T>, the result is identical as just resolving ILogger<T> from the DI container, so we might as well do that. Additionally, however, developers can still inject ILoggerFactory in their inheriting classes and call CreateLogger<T>( ... ) and pass along any custom category, which isn't possible right now because we're doing that call in the base class (see 2nd example in this link)

I'm aware that the second reason is actually introducing a violation of backward compatibility, which is used as an point of concern in the first reason. Nevertheless in the latter backward compatiblity would be compromised (only for developers that did not rely on the default null value) in return for some increased functionality (the dev can pass along a custom category) and alignment with best practises, whereas currently it would be violated without an apparent motive.

@maurei maurei self-requested a review February 12, 2020 00:01
@maurei maurei self-requested a review February 12, 2020 00:21
@bart-degreed
Copy link
Contributor Author

bart-degreed commented Feb 12, 2020

Thanks for your review. Let me respond to your primary concerns.

  1. Optional parameter.
    backward compatibility...

I agree we should make logging optional. It allows for easier tests setup and easier migration from earlier versions where no logging parameter existed. And I am okay with letting the caller choose whether they want to use logging, although I think it would be more common to just have a logger with only debug output be injected when callers are not interested in logging. I do however think it should be a required parameter (allowing caller to pass null) at a preferably fixed position (I chose right after the IJsonApiOptions parameter). Because it is just too easy to forget passing the value through to all dependencies otherwise, which is actually what happened in this repo. This is a breaking change, but the migration is straightforward and it targets the next major version of JADNC so that should not be a problem.

For those who don't need logging it only adds noise to the constructor of their controller by having to null it out.

I believe forcing callers to choose whether they want logging or not improves the maintainability of code. The alternative, an optional parameter somewhere at the end, makes it easy to miss. In my opinion, the improvement in code maintainability outweighs the comfort of not passing anything, in the long term. I believe it is good to be explicit about dependencies. Logging becomes important when issues arise, so it's good to have it by default. Reducing logging noise is much easier than to inspect JADNC internals to determine what logging is missing.

  1. Usage of ILogger

Logging frameworks traditionally have had a bit of runtime magic around them, in that they are expected to automatically know who they are working for (the class name). The LoggerFactory nicely abstracts that concern away, making it possible to reuse a single dependency throughout the call stack. Having a different logger dependency all the time makes it very hard to manage dependencies without D/I.

For example: FooService internally uses a BarService. The constructor for FooService needs to accept a Logger<FooService> plus a Logger<BarService> in order to instantiate its dependency. Image the long list of typed loggers you'd need in a real complex application (noise). LoggerFactory solves this.

I think the SRP point is valid, but also a bit puristic. It's not that the class is instantiating the logger, but in both cases it explicitly states its needs. When I need to choose between letting the D/I subsystem or the logging subsystem provide the instance, the latter seems more appropriate to me. Internally they likely call into each other, but that is an implementation detail and subject to change.

The official docs show both logger and factory examples. Using ILogger directly works best to show the simplest example, but the factory indirection may prove valuable in more complex scenarios. Likewise, most examples do not contain exception handling code or authorization checks, in order to keep them as simple as possible.

The only strong reason I have against using typed loggers is for class hierarchies. Example:

class Base
{
  public Base(ILogger<Base> logger) { ... }
}

class Derived : Base
{
  public Derived(ILogger<Derived> logger, ILogger<Base> baseLogger) : base(baseLogger) { }
}

We need a separate logger at runtime for each type in the hierarchy to get the correct class names written. Using class names to track down where execution is coming from is so common in my experience that it is important to get it right. And losing the ability to pass custom category names is actually a good thing. Under what category/class name JADNC logs should be fixed, determined by JADNC and not library users. This is diagnostic information that may be shared on stackoverflow, issues etc. so it does not help if different users are using different categories to log the JADNC internal behavior.

@maurei
Copy link
Member

maurei commented Feb 12, 2020

The only strong reason I have against using typed loggers is for class hierarchies

Agree. Perhaps stick with ILogger then and leave it to the users to either directly resolve it normally from DI and pass it on to the base, or if more flexibility is required allow users to construct an ILogger themselves from ILoggerFactory (or equivalent) and pass that on to the base?

@maurei
Copy link
Member

maurei commented Feb 12, 2020

I do however think it should be a required parameter (allowing caller to pass null) at a preferably fixed position (I chose right after the IJsonApiOptions parameter)

Given how c# handles optional parameters (at the end with a default value), placing it in the middle without a default value and surrounded by non-optional params it will not suggest to users it is optional. Users would need to know about JADNC internals that passing null is equivalent to opting out on logging and will not cause a nullref exeception. I feel it will be more clear to users if we handle optional params the was as intended by c#

Because it is just too easy to forget passing the value through to all dependencies otherwise, which is actually what happened in this repo.

JADNC not passing it through was an error but any internal measures taken to ensure consistency here shouldn't ripple through to the user exposed API (should be achieved with tests instead)

Bart Koelman added 4 commits February 13, 2020 00:47
After removing all custom log setup, logging started to actually work, in Kestrel Console window and VS Debug Output. Console and Debug writers are added automatically by the runtime. And levels from appsettings.json are also picked up automatically.
@bart-degreed
Copy link
Contributor Author

Agree. Perhaps stick with ILogger then

I tried that, it does not work. How can the D/I container select which logger to create or reuse if nothing is specified? Note that once a logger instance is created, it is bound to a single type/category. That's why you should never share logger instances between types, not even in a type hierarchy. You need to either pass an ILogger<T> or ILoggerFactory.

Working example:

    public class PeopleController : JsonApiController<Person>
    {
        private readonly ILogger<PeopleController> _logger;

        public PeopleController(IJsonApiOptions jsonApiOptions, ILoggerFactory loggerFactory,
            IResourceService<Person> resourceService)
            : base(jsonApiOptions, loggerFactory, resourceService)
        {
            _logger = loggerFactory.CreateLogger<PeopleController>();

            // ...

            _logger.LogInformation("Message from PeopleController.");
        }
    }

    public class JsonApiController<T, TId> : BaseJsonApiController<T, TId> where T : class, IIdentifiable<TId>
    {
        private readonly ILogger<JsonApiController<T, TId>> _logger;

        public JsonApiController(IJsonApiOptions jsonApiOptions, ILoggerFactory loggerFactory,
            IResourceService<T, TId> resourceService)
            : base(jsonApiOptions, loggerFactory, resourceService)
        {
            _logger = loggerFactory.CreateLogger<JsonApiController<T, TId>>();

            // ...

            _logger.LogInformation("Message from JsonApiController.");
        }
    }

Are we in agreement to use ILoggerFactory instead of ILogger<T>?

@bart-degreed
Copy link
Contributor Author

Given how c# handles optional parameters (at the end with a default value), placing it in the middle without a default value and surrounded by non-optional params it will not suggest to users it is optional.

True, but realize that explicitly passing null for logging is very unlikely to happen in an ASP.NET Web Application project. See my recent push to this PR, where logging appears to be injected automatically without any configuration in Startup. This is how netcore3 works, so enforcing that null is passed for logging requires special effort anyway.

Users would need to know about JADNC internals that passing null is equivalent to opting out on logging and will not cause a nullref exeception.

Like any public API parameter, it should be documented whether it is required, what value range is acceptable, etc. Making it optional is for convenience in tests only. And even if that gets unnoticed, a test likely passes a Mock<> that always returns null and we have the same effect: no logging occurs, and no NullReferenceException.

I feel it will be more clear to users if we handle optional params the was as intended by c#

Optional parameters in C# are quite controversial. They were added to the language only after 10 years, being pushed back by the language designers until then. Eventually they were added in an effort to improve COM interop with the Word/Excel object models in VB, where optional parameters were used extensively. Calling them from C# required to pass Missing.Value about 14 times to match the COM signature. Some coding guidelines forbid the use of optional parameters entirely.

JADNC not passing it through was an error but any internal measures taken to ensure consistency here shouldn't ripple through to the user exposed API (should be achieved with tests instead)

This does not just apply to this repo, but to any source tree that derives from the types here, such as controllers, services and repositories. By making them optional, it is easily missed. For example:

    public class PeopleController : JsonApiController<Person>
    {
        public PeopleController(
            IJsonApiOptions jsonApiOptions,
            IResourceService<Person> resourceService) 
            : base(jsonApiOptions, resourceService/* oops, forgotten about logging: loggerFactory*/)
        { }
    }

This compiles just fine, while the library user may not have intended to disable logging in the entire type hierarchy. Its better to get a compile error, and realize you need to pass null to fix that, than to never be notified when doing it wrong accidentally.

@bart-degreed
Copy link
Contributor Author

@maurei
Copy link
Member

maurei commented Feb 13, 2020

Ah now I get it; the goal is to have unique logging categories per inheritance level within a single instance. A use-case for this would be easily differentiating between internal JADNC logs versus custom application logs? In this case ILoggerFactory would make more sense indeed, as it provides both the dev and JADNC with their responsibility of creating their respective loggers. Therefore, usage of ILoggerFactory: ✅

About the optional parameter: I realised my approach will lead to inconsistency. With out-of-the-box usage of JADNC, the dev never touches the constructors of services/repositories and since (like you mentioned) the logging services are always available, these parameters will indeed always be populated and as such there is no reason for them to be marked as optional there. The only way to disable logging there is to set the loglevel to none, which I guess is the recommended way in netcore3 anyway. Then for consistency the same approach for disabling logging should be pursued in other layers of the framework, i.e also the JsonApiController. Hence, non-optional argument: ✅

@maurei
Copy link
Member

maurei commented Feb 13, 2020

Probably we should extend this PR to also cover other places (services, repositories) where ILoggerFactory is referenced and make the argument non-optional

@bart-degreed
Copy link
Contributor Author

Ah now I get it; the goal is to have unique logging categories per...

Yes, exactly. The logging strategy (names, levels, stack traces, etc) from JADNC should be independent from the application logging strategy.

About the optional parameter: I realised my approach...

Yes, having null loggers is the exception rather than the common scenario. Another way to deactivate logging would be to detach all providers.

Today I discovered NullLoggerFactory.Instance, exists, which implements the null object design pattern.

This makes me reconsider whether ILoggerFactory would be better off being a required parameter after all. See also this guidance.

So we agree that ILoggerFactory should be a non-optional parameter, but passing null is allowed. While I can live with that, would you be okay to make it a required parameter instead?

Probably we should extend this PR...

We have been discussing controllers, but this PR has targeted all usages of ILoggerFactory in the codebase from the start.

Bart Koelman added 3 commits February 13, 2020 13:03
- Added single trace-level log message to controller, service and repository (to make sure we have no crashing tests because they incorrectly pass null).
- Removed conditional logging statement
@bart-degreed
Copy link
Contributor Author

I reverted formatting changes. Assuming you agree with making ILoggerFactory a required parameter, this PR is ready for merge.

@maurei maurei self-requested a review February 13, 2020 17:47
@maurei maurei merged commit 9fd3fc7 into json-api-dotnet:master Feb 13, 2020
@bart-degreed bart-degreed deleted the logging-cleanup branch February 13, 2020 18:11
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

2 participants