Issues with custom appender and Apache Ignite integration

classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|

Issues with custom appender and Apache Ignite integration

Mitchell Rathbun (BLOOMBERG/ 731 LEX)
I am having some issues with a custom appender when I enable logging for Apache Ignite. I have a cl and pretty much follows the code laid out here: http://logging.apache.org/log4j/2.x/manual/extending.html#Appenders. The class also overrides append. Without enabling Ignite logging, things seem to work fine. However, after I enable Ignite logging, I will see the following repeatedly:

2020-02-12 12:52:37,946 INFO  STDERR [Thread-2] {} 2020-02-12 12:52:37,943 Log4j2-TF-2-AsyncLoggerConfig-2 ERROR Attempted to append to non-started appender ActLogAppender.

From that same log file and additional log statements added in ActLogAppender, I see:

2020-02-12 12:52:32,106 INFO  ActLogAppender [main] {} CreateAppender called: ActLogAppender, wing1112, %date{DEFAULT} %-5level %logger{2}.%method.%line [%thread] %mdc %msg%n, null
2020-02-12 12:52:32,144 INFO  ActLogAppender [main] {} ActLogAppender start called
2020-02-12 12:52:32,144 INFO  ActLogAppender [main] {} ActLogAppender start done being called with state: true

So the Appender should be started before these error messages are seen. This could be an error within the Ignite code, but I want to understand the error before digging deeper into that code. A couple of questions:

-What could cause this error occur, given that createAppender and start are called before the append error occurs? The implementation of ActLogAppender relies on the singleton pattern, so createAppender should always return the same instance. I also only see createAppender being called once.

-The errors posted above are usually prepended to the log file, overwriting the log statements that were there previously. We have even seen the case were a new log file is created that contains only those error messages. We no longer get any new logs at this point even though our process is still running. Why does this happen? It kind of seems like there are two different loggers writing to the same file, but not sure.