Enterprise Library RollingFlatFileTraceListenerData JsonLogFormatter file format

Question

I'm looking for way make the RollingFlatFileTraceListenerData create a valid JSON document when using JsonLogFormatter. Like the XML parser, the RollingFlatFileTraceListenerData only appends items, just giving you an option to add an item header and footer, but not a higher level file header, footer header and item separator. I realize I can modify the file after the fact, but I would rather have the process build with a valid format. Opening the active file with an external process would be risky because it could block the logging process if it needed to open the file to log again.

Current Output:

{
  "Message": "Log entry created using the simplest overload.",
  "Categories": [
    "General"
  ],
  "Priority": -1,
  "EventId": 1,
  "Severity": 8,
  "LoggedSeverity": "Information",
  "Title": "",
  "TimeStamp": "2013-11-07T20:33:38.6537773Z",
  "MachineName": "Acme01",
  "AppDomainName": "Acme.TestDriver.vshost.exe",
  "ProcessId": "10348",
  "ProcessName": "C:\\dev\\Acme.TestDriver\\bin\\Debug\\Acme.TestDriver.vshost.exe",
  "ManagedThreadName": null,
  "Win32ThreadId": "11204",
  "ExtendedProperties": {},
  "TimeStampString": "11/7/2013 8:33:38 PM",
  "ActivityId": "00000000-0000-0000-0000-000000000000",
  "RelatedActivityId": null,
  "ErrorMessages": null,
  "ActivityIdString": "00000000-0000-0000-0000-000000000000",
  "CategoriesStrings": [
    "General"
  ]
}
{
  "Message": "Log entry with a single category.",
  "Categories": [
    "General"
  ],
  "Priority": -1,
  "EventId": 1,
  "Severity": 8,
  "LoggedSeverity": "Information",
  "Title": "",
  "TimeStamp": "2013-11-07T20:33:38.6537773Z",
  "MachineName": "Acme01",
  "AppDomainName": "Acme.TestDriver.vshost.exe",
  "ProcessId": "10348",
  "ProcessName": "C:\\dev\\Acme.TestDriver\\bin\\Debug\\Acme.TestDriver.vshost.exe",
  "ManagedThreadName": null,
  "Win32ThreadId": "11204",
  "ExtendedProperties": {},
  "TimeStampString": "11/7/2013 8:33:38 PM",
  "ActivityId": "00000000-0000-0000-0000-000000000000",
  "RelatedActivityId": null,
  "ErrorMessages": null,
  "ActivityIdString": "00000000-0000-0000-0000-000000000000",
  "CategoriesStrings": [
    "General"
  ]
}

Preferred:

[
 {
      "Message": "Log entry created using the simplest overload.",
      "Categories": [
        "General"
      ],
      "Priority": -1,
      "EventId": 1,
      "Severity": 8,
      "LoggedSeverity": "Information",
      "Title": "",
      "TimeStamp": "2013-11-07T20:33:38.6537773Z",
      "MachineName": "Acme01",
      "AppDomainName": "Acme.TestDriver.vshost.exe",
      "ProcessId": "10348",
      "ProcessName": "C:\\dev\\Acme.TestDriver\\bin\\Debug\\Acme.TestDriver.vshost.exe",
      "ManagedThreadName": null,
      "Win32ThreadId": "11204",
      "ExtendedProperties": {},
      "TimeStampString": "11/7/2013 8:33:38 PM",
      "ActivityId": "00000000-0000-0000-0000-000000000000",
      "RelatedActivityId": null,
      "ErrorMessages": null,
      "ActivityIdString": "00000000-0000-0000-0000-000000000000",
      "CategoriesStrings": [
        "General"
      ]
    }
,
    {
      "Message": "Log entry with a single category.",
      "Categories": [
        "General"
      ],
      "Priority": -1,
      "EventId": 1,
      "Severity": 8,
      "LoggedSeverity": "Information",
      "Title": "",
      "TimeStamp": "2013-11-07T20:33:38.6537773Z",
      "MachineName": "Acme01",
      "AppDomainName": "Acme.TestDriver.vshost.exe",
      "ProcessId": "10348",
      "ProcessName": "C:\\dev\\Acme.TestDriver\\bin\\Debug\\Acme.TestDriver.vshost.exe",
      "ManagedThreadName": null,
      "Win32ThreadId": "11204",
      "ExtendedProperties": {},
      "TimeStampString": "11/7/2013 8:33:38 PM",
      "ActivityId": "00000000-0000-0000-0000-000000000000",
      "RelatedActivityId": null,
      "ErrorMessages": null,
      "ActivityIdString": "00000000-0000-0000-0000-000000000000",
      "CategoriesStrings": [
        "General"
      ]
    }
]

Answer 1

Out of the box the trace listeners just append to the file. You won't be able to open the file and modify it because the file is locked. If you want to create a well formed document then you will have to create a custom trace listener that creates the start tag and ensures that the closing tag is always at the bottom of the file.

Answer 2

I too tried to correct the output but finally gave up and handled everything on the consumption side. Below is my sample program which spams events and then attempts to consume them, based on code from https://stackoverflow.com/a/26610684/4904200

Key points:

• The RollingFlatFileTraceListener Header and Footer are set to ""
• When consuming the logs our stream is set to FileShare.ReadWrite so we don't interfere with writing
• JsonReader.SupportMultipleContent = true is what lets us handle multiple objects in a file as long as they are on separate lines.

This uses Microsoft Enterprise Logging Library v6 and Newtonsoft JSON v8.

static void Main(string[] args) {
  Thread producer = new Thread(new ThreadStart(Produce));
  Thread consumer = new Thread(new ThreadStart(Consume));
  producer.Start();
  consumer.Start();
  while (true)
    Thread.Sleep(1000);
}

public static void Produce() {
  RollingFlatFileTraceListener listener = new RollingFlatFileTraceListener(
    fileName: "jsontest",
    formatter: new JsonLogFormatter(),
    header: "",
    footer: "",
    rollSizeKB: 1024);
  LoggingConfiguration configuration = new LoggingConfiguration();
  configuration.Filters.Add(new CategoryFilter("Category Filter", new string[] { "none" }, CategoryFilterMode.AllowAllExceptDenied));
  configuration.AddLogSource("Any", SourceLevels.All, true, listener);
  LogWriter writer = new LogWriter(configuration);

  while (true)
    writer.Write(DateTime.Now);
}

public static void Consume() {
  while (true) {
    try {
      using (var fileStream = File.Open("jsontest", FileMode.Open, FileAccess.Read, FileShare.ReadWrite)) {
        LogEntry latestEntry = ReadJson<LogEntry>(fileStream).OrderBy(x => x.TimeStamp).FirstOrDefault();
        if (latestEntry == null)
          continue;
        Console.WriteLine("Consume\t" + latestEntry.Message);
      }
    } catch (FileNotFoundException) {
      Console.WriteLine("File Not Found");
    } catch (IOException) {
      Console.WriteLine("File Is Probably Busy");
    }
  }
}


public static IEnumerable<TResult> ReadJson<TResult>(Stream stream) {
  var serializer = new JsonSerializer();
  using (var reader = new StreamReader(stream))
  using (var jsonReader = new JsonTextReader(reader)) {
    jsonReader.SupportMultipleContent = true;
    while (jsonReader.Read()) {
      yield return serializer.Deserialize<TResult>(jsonReader);
    }
  }
}