Search code examples
.netnlog

Symbol \u0000 is rendered many times in logs, generated by NLog


I'm generating logs with NLog's JsonLayout and there are cases where I see such picture on Linux machine: too many \u0000
Why can such things are generated? Seems like there is some problem with JSON generation. What is the way to fix this?
My layout:

    <variable name="jsonDefaultLayout">
        <layout type="JsonLayout">
            <attribute name="time" layout="${longdate}" />
            <attribute name="level" layout="${level}" />
            <attribute name="logger" layout="${logger}" />
            <attribute name="activityId" layout="${aspnet-TraceIdentifier}" />
            <attribute name="ip" layout="${aspnet-request-ip}" />
            <attribute name="message" layout="${message:withException=true}" />
            <attribute name="eventProperties" encode="false">
                <layout type='JsonLayout' includeEventProperties="true" maxRecursionLimit="10" />
            </attribute>
            <attribute name="hostname" layout="${hostname}" />
            <attribute name="appdomain" layout="${appdomain:format={1\}}" />
        </layout>
    </variable>

\u0000 appear in message.

UPDATE:
The problem was with this code:

 private async Task<string> FormatRequest(HttpRequest request)
        {
            request.EnableBuffering();

            //We now need to read the request stream.  First, we create a new byte[] with the same length as the request stream...
            var buffer = new byte[Convert.ToInt32(request.ContentLength)];
  
            var stream = request.BodyReader.AsStream(true);
            await stream.ReadAsync(buffer, 0, buffer.Length);
            var bodyAsText = Encoding.UTF8.GetString(buffer);
            request.Body.Seek(0, SeekOrigin.Begin);

            string log = $"{request.Scheme}://{request.Host}{request.Path}{request.QueryString}";
            return new
            {
                Url = log,
                Body = LogInputSanitizer(bodyAsText)
            }.ToJson(Formatting.None);
        }

When I've changed the way I read the stream to:

  request.EnableBuffering();
  string bodyAsText = await new StreamReader(request.Body).ReadToEndAsync();

Everything seems fixed now. Guys, thanks for the comments! The question that is left for me:
What was the problem with the old code?


Solution

  • As you have discovered then NLog is just outputting the provided property-value, and in this case a string-value containing only null-chars.

    The string-value comes from your FormatRequest-method that converts byte-array to string, but if byte-array is not filled with any data then it becomes string-value with only null-chars.

    When using Read / ReadAsync from a stream, then one must check the return value to see how many bytes has been read. This should done in a loop until receiving zero bytes meaning end-of-stream. When using StreamReader then it handles everything for you (including recognizing encoding).

    Consider changing your code to this:

    private async Task<string> FormatRequest(HttpRequest request)
    {
       var contentLength = request.ContentLength;
       if (contentLength <= 0)
            return string.Empty; // What if 100 MByte ?
    
       request.EnableBuffering();
       string bodyAsText = await new StreamReader(request.Body).ReadToEndAsync();
       return bodyAsText;
    }
    

    Notice NLog.Web.AspNetCore provides ${aspnet-request-posted-body} (Instead of inserting into LogEventInfo-properties). See also: https://github.com/NLog/NLog.Web/wiki/HTTP-Request-Logging