ConvertToArrayFilter: System.ArgumentNullException: Value cannot be null

[DmitryMak]

We are getting this exception when trying to log with log4stash 3.0.0 and log4net 2.0.11.

log4net:ERROR [ElasticSearchAppender] ErrorCode: GenericFailure. Failed in DoAppend
System.ArgumentNullException: Value cannot be null.
Parameter name: input
   at System.Text.RegularExpressions.Regex.Split(String input)
   at log4stash.Filters.ConvertToArrayFilter.ValueToArray(String value)
   at log4stash.Filters.ConvertFilter.PrepareEvent(Dictionary`2 logEvent)
   at log4stash.ElasticAppenderFilters.PrepareEvent(Dictionary`2 logEvent)
   at log4stash.ElasticSearchAppender.PrepareAndAddToBulk(Dictionary`2 logEvent)
   at log4stash.ElasticSearchAppender.Append(LoggingEvent loggingEvent)
   at log4net.Appender.AppenderSkeleton.DoAppend(LoggingEvent loggingEvent)

Not sure if it is related but we use custom log4net code like LogicalThreadContext.Stacks["FirstName"].Push("Alice")

With log4stash config like

<ElasticFilters>
    <Convert>
        <ToString>FirstName</ToString>
        <ToArray>
            <SourceKey>FirstName</SourceKey>
        </ToArray>

Edit: Code to reproduce the issue:

_log.Warn("Will be logged without FirstName");
using (LogicalThreadContext.Stacks["FirstName"].Push("Alice")) {
    _log.Warn("Will be logged with FirstName = Alice");
}
_log.Warn("This and further messages will not be logged due to ArgumentNullException in ConvertToArrayFilter");

[eran-gil]

Try using this line instead: LogicalThreadContext.Properties["FirstName"] = "Alice";

[DmitryMak]

We rely on IDisposable returned from Push. Could you help us understand how this will fix the ArgumentNullException?

[eran-gil]

Look at https://github.com/urielha/log4stash/blob/master/src/log4stash/LogEvent/BasicLoggingEventParser.cs line 111 method. It takes its values from the properties of the thread context and not the stack, these are different storages. Therefore, you need to use properties with the current code. Or, you can add a pull request with a way to sort it out.

[DmitryMak]

Based on my experiments it is a bug ConvertToArrayFilter. When I turn it off by removing <ToArray> in the config, the exception disappears. The underlying issue that we were having also goes away. The ArgumentNullException prevented further logging. Removing <ToArray> filter fixed that.

So based on that, the issue is not related to Properties vs Stack. We've been using Stack for a long time and it always, and still, works.

[eran-gil]

You are right, it does work, my bad :) Anyways, it seems either somehow instead of "Alice" you send null or somehow the value is overwritten to null in log4stash

[DmitryMak]

You are right, it does work, my bad :) Anyways, it seems either somehow instead of "Alice" you send null or somehow the value is overwritten to null in log4stash

We remove "Alice" by calling IDisposable.Dispose. I updated the bug description with a code sample.

[eran-gil]

From what I see, since you dispose "Alice" before logging without popping it from the stack it stays null and therefore causes the exception, I debugged log4stash with a sample code similar to yours and that's what I saw

[DmitryMak]

My understanding is that explicit Pop call is not required. Based on log4net documentation for the Push, they seem to recommend this pattern:

using(log4net.LogicalThreadContext.Stacks["NDC"].Push("Stack_Message"))
{
    log.Warn("This should have an ThreadContext Stack message");
}

[eran-gil]

It was my understanding too, but in fact that's what happens when debugging the code

[DmitryMak]

I have do a bit more research on this, but IMHO ToArray filter needs to be fixed to behave like ToString filter. ToString does not crash in the same scenario.