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

NLogTargetListener is not using the LogListenerParser #19

Closed
savarobert opened this issue Oct 14, 2019 · 4 comments
Closed

NLogTargetListener is not using the LogListenerParser #19

savarobert opened this issue Oct 14, 2019 · 4 comments
Labels
SDK-NLog Related to NLog integration

Comments

@savarobert
Copy link

savarobert commented Oct 14, 2019

Registering the NLogTargetListener the following way

// NLog listener
config.Listeners.Add(new NLogTargetListener()
{
    ShouldWriteBeginRequestEvent = (KissLog.Web.HttpRequest httpRequest) => true,
    ShouldWriteFlushEvent = (KissLog.FlushArgs.FlushLogArgs args) => true,
    Parser = new MyCustomParser()
});

results in KissLog flushing every single message into NLog, ignoring the custom parser:

2019-10-14 16:29:09.4802 [GET /] 
2019-10-14 16:29:10.3469 AuthenticationHandler started. 
2019-10-14 16:29:10.3679 Swagger request. No authentication context established. 
2019-10-14 16:29:11.9607 [301 MovedPermanently][GET /] Duration: 2,246ms 
2019-10-14 16:29:12.0635 [GET /swagger/ui/index] 
2019-10-14 16:29:12.1023 AuthenticationHandler started. 
2019-10-14 16:29:12.1323 Swagger request. No authentication context established. 
2019-10-14 16:29:12.6863 [GET /swagger/ui/css/typography-css] 
2019-10-14 16:29:12.7531 AuthenticationHandler started. 
2019-10-14 16:29:12.7840 Swagger request. No authentication context established. 
2019-10-14 16:29:12.8040 [GET /swagger/ui/css/reset-css] 
@catalingavan catalingavan added the SDK-NLog Related to NLog integration label Oct 14, 2019
@catalingavan
Copy link
Owner

catalingavan commented Oct 14, 2019

Hi Robert,

The NLogTargetListener is sending the logs to NLog as soon as they get executed in the code.

This implies that, by the time LogListenerParser.ShouldLog(FlushLogArgs args) is evaluating the condition, the logs have already been saved to text files.

Below is the execution workflow:

Begin GET /swagger/         <---- start of the request


_logger.Debug("step 1");    <---- "step 1" is sent to NLog (text file)
_logger.Debug("step 2");    <---- "step 2" is sent to NLog (text file)
...
_logger.Debug("step n");    <---- "step n" is sent to NLog (text file)


                            <---- by this time, the log messages have already been sent to the NLog targets

							
END 200 OK GET /swagger/    <---- end of the request
                            <---- ShouldLog(FlushLogArgs args) is executed at this step

One possible solution would be to update the LogListenerParser and provide callback for the BeginRequest event.

public class LogListenerParser
{
    // will get executed just at the beginning of the request
    // if return false, the listener will not listen for any logs for the current request
    public virtual bool ShouldLog(BeginRequestArgs args)
    {
        if (args.Request.Url.LocalPath.Contains("/swagger/"))
            return false;

        return true;
    }

    public virtual bool ShouldLog(FlushLogArgs args, ILogListener logListener)
    {
        return true;
    }
}

@savarobert
Copy link
Author

One quick workaround was to inherit the NLogTargetListener and add my own logic to bypass the verbosity of the text log:

public class NLogCustomTargetListener : NLogTargetListener, ILogListener
{
    public new void OnBeginRequest(KissLog.Web.HttpRequest httpRequest, ILogger logger)
    {
        if (httpRequest.Url.PathAndQuery.IndexOf("/swagger/", StringComparison.InvariantCultureIgnoreCase) >= 0)
        {
            return;
        }
        base.OnBeginRequest(httpRequest, logger);
    }
}

In the web interface everything works the same, as expected.

@catalingavan
Copy link
Owner

If it works, keep it a while :)
I will update SDK to provide more flexibility for this scenario. I will keep you updated.

catalingavan added a commit that referenced this issue Oct 16, 2019
* updated LogListenerParser to fix issue #19
@catalingavan
Copy link
Owner

catalingavan commented Oct 17, 2019

Published KissLog 3.5.1 which fixes this issue.

Updated LogListenerParser with one new method:

public class LogListenerParser
{
    public virtual bool ShouldLog(BeginRequestArgs args, ILogListener logListener)
    {
        return true;
    }
}

This method gets executed at the begging of the request.

If the result is false, the Listener will stop logging the current request.

Begin GET /swagger/         <---- start of the request
                            <---- ShouldLog(BeginRequestArgs args) is executed
                            <---- if false, skip;


_logger.Debug("step 1");    <---- skipped
_logger.Debug("step 2");    <---- skipped
...
_logger.Debug("step n");    <---- skipped

							
END 200 OK GET /swagger/    <---- end of the request

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
SDK-NLog Related to NLog integration
Projects
None yet
Development

No branches or pull requests

2 participants