Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

C# Tracing truncate long messages

Tags:

c#

In C# I've enabled tracing and a net tracing source.

    <?xml version="1.0" encoding="utf-8" ?>
<configuration>
    <startup> 
        <supportedRuntime version="v4.0" sku=".NETFramework,Version=v4.5" />
    </startup>
  <system.diagnostics>
    <sources>
      <source name="System.Net" tracemode="includehex" maxdatasize="1024">
        <listeners>
          <add name="System.Net"/>
        </listeners>
      </source>
    </sources>
    <switches>
      <add name="System.Net" value="Verbose"/>
    </switches>
    <sharedListeners>
      <add name="System.Net"
        type="TraceTest.StringWriterTraceListener, TraceTest"
        initializeData="myfile.log"
      />
    </sharedListeners>
    <trace autoflush="true" indentsize="4" />    
  </system.diagnostics>
</configuration>

But longer messages get truncated (long like 12Kb/30 lines, not long like 1GB!) so I end up in a situation where only part of web reqiest headers are logged.

How to fix that?

Or do you know a book or some resource that explains .Net tracing and debugging in great detail?

log example:

            System.Net Information: 0 : [1204] Connection#63291458 - Received headers
        {
        Transfer-Encoding: chunked
        Connection: keep-alive
        Keep-Alive: timeout=10
        Content-Type: text/html; charset=windows-1251
        Date: Mon, 04 Jul 2016 17:50:33 GMT
        Set-Cookie: uid=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0,uid=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0; path=/,uid=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0; path=/; domain=.zamunda.net,pass=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0,pass=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0; path=/,pass=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0; path=/; domain=.zamunda.net,bitbucketz=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0,bitbucketz=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0; path=/,bitbucketz=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0; path=/; domain=.zamunda.net,cats=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0,cats=deleted; expires=Thu, 01-Jan-1970 00:00:01 GMT; Max-Age=0; path=/,cats=deleted;
expires=...}.

This is one message, somehow Write method on the TraceListener is called whit that single message as parameter that is being truncated (the "...}." at the end)

Also cookies are terribly written and are almost unparsable, but I can live with that...

Yeah, sadly enough apart from tampering with System.dlls or using some odd and complex type inheritance there is not much to be done.

like image 929
JDE Avatar asked Oct 18 '22 06:10

JDE


1 Answers

You'll not get the extra data.

Your typical example is coming from an private method called ParseResponseData which calls this:

Logging.PrintInfo(Logging.Web, this, SR.GetString("net_log_received_headers", new object[]
    {
        this.m_ResponseData.m_ResponseHeaders.ToString(true)
    }));

The internal sealed static class SR with method GetString is the culprit here. The net_log_received_headers resource string is Received headers {{{0}}}.. ILSpy reveals this code:

public static string GetString(string name, params object[] args)
{
    SR sR = SR.GetLoader();
    if (sR == null)
    {
        return null;
    }
    string @string = sR.resources.GetString(name, SR.Culture);
    if (args != null && args.Length != 0)
    {
        for (int i = 0; i < args.Length; i++)
        {
            string text = args[i] as string;
            if (text != null && text.Length > 1024)
            {
                args[i] = text.Substring(0, 1021) + "...";
            }
        }
        return string.Format(CultureInfo.CurrentCulture, @string, args);
    }
    return @string;
}

You notice this piece:

if (text != null && text.Length > 1024)
{
    args[i] = text.Substring(0, 1021) + "...";
}

What ever you throw at it, it will rewrite the arguments to limit its length to 1024 characters.

As the ResponseHeaders collection write all its name/values to a single string, once it is handed to SR.GetString all that effort and memory is wasted.

When SR.GetString is involved in the logging, you'll risk having your data truncated. The only way to know where that happens is by inspecting the assembly or the .Net Reference Source

The maxdatasize setting in the config is used when the Dump method of the internal Logging class is called. However, you'll not have to guess if the data is truncated because it will tell you that in the log file:

int maxDumpSizeSetting = Logging.GetMaxDumpSizeSetting(traceSource);
if (length > maxDumpSizeSetting)
{
    Logging.PrintLine(traceSource, TraceEventType.Verbose, 0, string.Concat(new string[]
    {
        "(printing ",
        maxDumpSizeSetting.ToString(NumberFormatInfo.InvariantInfo),
        " out of ",
        length.ToString(NumberFormatInfo.InvariantInfo),
        ")"
    }));
    length = maxDumpSizeSetting;
}
like image 167
rene Avatar answered Nov 12 '22 23:11

rene