Getting Data In

HttpEventCollectorTraceListener doesn't flush

Explorer

I'm using the HttpEventCollectorTraceListener and originally my code looked like this:

using System;
using System.Configuration;
using System.Diagnostics;
using NLog;
using Splunk.Logging;

namespace SplunkDiscovery
{
    static class Program
    {
        private static readonly Logger Logger = LogManager.GetCurrentClassLogger();

        static void Main(string[] args)
        {
            Trace.Listeners.Clear();
            Trace.Listeners.Add(CreateSplunkListener());
            Logger.Info("Trace Listener setup. Test app started with {0} argument(s)", args.Length);
        }

        private static HttpEventCollectorTraceListener CreateSplunkListener()
        {
            var listener = new HttpEventCollectorTraceListener(
                new Uri(ConfigurationManager.AppSettings["SplunkUrl"], UriKind.Absolute), 
                ConfigurationManager.AppSettings["AppToken"]);

            return listener;
        }
    }
}

And an app.config like this:

<?xml version="1.0" encoding="utf-8"?>
<configuration>
  <configSections>
    <section name="nlog" type="NLog.Config.ConfigSectionHandler, NLog" />
  </configSections>
  <startup>
    <supportedRuntime version="v4.0" sku=".NETFramework,Version=v4.6" />
  </startup>
  <appSettings>
    <add key="AppToken" value="28BD5B15-CF19-416E-B147-BCB4DDBC83DB"/>
    <add key="SplunkUrl" value="https://splunk:8088/"/>
  </appSettings>
  <nlog xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
    <targets async="true">
      <target name="splunkTraceTarget" xsi:type="Trace" layout="${time}|${level:uppercase=true}|${logger}::${message}" />
      <target name="debugger" xsi:type="Debugger" layout="${time}|${level:uppercase=true}|${logger}::${message}" />
    </targets>s
    <rules>
      <logger name="*" minlevel="Debug" writeTo="splunkTraceTarget" />
    </rules>
  </nlog>
  <runtime>
    <assemblyBinding xmlns="urn:schemas-microsoft-com:asm.v1">
      <dependentAssembly>
        <assemblyIdentity name="NLog" publicKeyToken="5120e14c03d0593c" culture="neutral" />
        <bindingRedirect oldVersion="0.0.0.0-4.0.0.0" newVersion="4.0.0.0" />
      </dependentAssembly>
    </assemblyBinding>
  </runtime>
</configuration>

To me this should work since NLog target is set to Trace and I added the HTTP event collector trace listener and logged something, but it doesn't work.

The only way I can make it work is a hacky combination of adding Trace.WriteLine("hi"); and follow that with Trace.Close(); and then on the listener set batchInterval to 1 and batchSizeCount to 1.

So basically, nothing gets logged unless the batch size is met and something is written directly to Trace, without going through NLog to write to Trace.

Also, obviously those batch sizes aren't realistic for performance reasons. I've tried Flush(), Close(), and Dispose() at both the trace listener level and the Trace level, but that doesn't result in the data getting sent.

1 Solution

Splunk Employee
Splunk Employee

Hi Geoff

On the listener itself we expose a FlushAsync method. That should force it to flush. We handle everything async with the loggers in order to get better perf/scale. The challenge is that the Trace interface is not really designed for Async, but FlushAsync should work for you.

View solution in original post

0 Karma

Splunk Employee
Splunk Employee

Hi Geoff

On the listener itself we expose a FlushAsync method. That should force it to flush. We handle everything async with the loggers in order to get better perf/scale. The challenge is that the Trace interface is not really designed for Async, but FlushAsync should work for you.

View solution in original post

0 Karma

Explorer

FlushAsync works but it seems odd it wouldn't be there for flush and seems like on disposal it would flush automatically, otherwise there could often be log events lost when app shuts down.

Also this same problem exists for TcpTraceListener and UpdTraceListener and there's no FlushAsync there.

0 Karma

Splunk Employee
Splunk Employee

Did you try setting Autoflush on the Trace class?

0 Karma

Splunk Employee
Splunk Employee

It is possible we have a bug. We can investigate. Please file an issue in our github repo.

0 Karma

Explorer

Yeah AutoFlush didn't help with TcpTraceListener. I can file an issue. Thanks

0 Karma

Splunk Employee
Splunk Employee

It's not a trace listener issue in the case of TCP. Splunk has a buffer of like 1 mb for TCP, events won't get written out until the buffer is filled. it throws a lot of people for a loop :-(. There is no way to override that behavior AFAIK.

0 Karma

Splunk Employee
Splunk Employee

In other words, the data has probably been sent across the TCP channel and is sitting there in the buffer. If you close the socket, then it also writes hence why when you closed it makes it happen. Try writing a larger amount of data as a test and you should see it go through automatically.

0 Karma

Splunk Employee
Splunk Employee

The Trace class also exposes Autoflush, have you tried setting that? I notice it is false by default.

0 Karma