Hello Ilya,
I think that you might satisfy your requirements using MDC. It is
refereed as Managed/Mapped Diagnostic Context [1], some logging
libraries call it also Nested Diagnostic Context. Using it you can mark
log entries with context specific information which is provided
elsewhere. Standard mechanism of log4j keep MDC using thread locals.
Using MDC require some small adjustments in the code.
Looking at Log4j2Logger which is injectable into each ignite instance
you can try managing MDC inside ignite logger itself. Instead of placing
application and node id inside system property you push it using log4j2
thread context. All you need to do is to surround each "impl" logger call:
try (final CloseableThreadContext.Instance ctc =
CloseableThreadContext.put("app", application)
.put("node", String.valueOf(nodeId))) {
impl.info(getMarkerOrNull(marker), msg);
}
Both of these keys will be available under $X{app} and $X{node}.
Very similar mechanism is available with an old log4j 1.x.
[1] https://logging.apache.org/log4j/2.x/manual/thread-context.html
Kind regards,
Łukasz
On 6.11.2022 09:05, Ilya Korol wrote:
Hi Igniters,
I would like to discuss the Ignite logging.
I found current logging implementation a little bit inflexible for
several use-cases.
Assume that I want to run multiple Ignite instances in same JVM process and
I also want that all messages from each Ignite instance go to separate
file.
Actually we have an log4j config in our examples that, at first glance,
should do the trick:
<Routing name="FILE">
<Routes pattern="$${sys:nodeId}">
<Route>
<RollingFile name="Rolling-${sys:nodeId}"
fileName="${sys:IGNITE_HOME}/work/log/${sys:appId}-${sys:nodeId}.log"
filePattern="${sys:IGNITE_HOME}/work/log/${sys:appId}-${sys:nodeId}-%i-%d{yyyy-MM-dd}.log.gz">
<PatternLayout
pattern="[%d{ISO8601}][%-5p][%t][%c{1}]%notEmpty{[%markerSimpleName]}
%m%n"/>
<Policies>
<TimeBasedTriggeringPolicy interval="6"
modulate="true" />
<SizeBasedTriggeringPolicy size="10 MB" />
</Policies>
</RollingFile>
</Route>
</Routes>
</Routing>
This works good if we will feed this config to separate ignite instances
(each in its own JVM), however in my case this will not work as expected.
In this log4j config we rely on java System properties ${sys.nodeId} and
${sys.appId} that we set inside Log4jLogger:
@Override public void setApplicationAndNode(@Nullable String
application, UUID nodeId) {
...
// Set nodeId as system variable to be used at configuration.
System.setProperty(NODE_ID, U.id8(nodeId));
System.setProperty(APP_ID, application != null
? application
: System.getProperty(APP_ID, "ignite"));
...
}
But when second Ignite instance will be initialized this code will
overwrite nodeId property with id of current node, so eventually I will
get two files:
ignite-node1.log // contains messages of first instance up to the
moment when second instance overwrite nodeId sys property
ignite-node2.log // contains messages from both nodes from mentioned
moment
The problem is that there is no reliable *discriminator* for
RoutingAppender. So I want to propose a some rework
of IgniteLogger implementations, to add some logic for logger
customization where user would be able to configure such *discriminator
/ tag*,
and later exploit in appender configuration.
1. What IgniteLogger implementation it affects
*Log4j2Logger* (we rely on RoutingAppender)
*Slf4jLogger* (we rely on Logback SiftingAppender)
Other logging frameworks/libraries (JUL / JCL) don't provide required
features, so there is nothing we can do about.
2. What to use for discriminator
From my perspective (after some googling, and studying log4j/slf4j
docs) so called "Markers" would be perfect fit for such purpose.
Marker conception exist in both slf4j and log4j frameworks, and there is
already exist possibility to supply markers in IgniteLogger.*() methods.
Additional benefit that I see from using markers is that, we would be
able to avoid to add Ignite instance name post-fixes
in IgniteKernal loggers and thread names:
2022-11-05T23:24:17,365 INFO [main] [o.a.i.i.IgniteKernal%server-0]
Daemon mode: off
2022-11-05T23:24:17,368 INFO [main] [o.a.i.i.IgniteKernal%server-0] OS:
Linux 5.13.0-28-generic amd64
2022-11-05T23:24:17,372 INFO [main] [o.a.i.i.IgniteKernal%server-0] OS
user: ikorol
2022-11-05T23:24:17,375 INFO [main] [o.a.i.i.IgniteKernal%server-0]
PID: 2791603
2022-11-05T23:24:17,555 WARN [pub-#21%server-0%]
[o.a.i.i.GridDiagnostic] Initial heap size is 498MB (should be no less
than 512MB, use -Xms512m -Xmx512m).
2022-11-05T23:24:19,993 INFO [disco-notifier-worker-#51%server-0%]
[o.a.i.i.p.c.GridClusterStateProcessor] Received activate cluster
request ...
Instead we can have (just need to add marker to appender message layout):
2022-11-05T23:24:17,365 INFO [server-0] [main] [o.a.i.i.IgniteKernal]
Daemon mode: off
2022-11-05T23:24:17,368 INFO [server-0] [main] [o.a.i.i.IgniteKernal]
OS: Linux 5.13.0-28-generic amd64
2022-11-05T23:24:17,372 INFO [server-0] [main] [o.a.i.i.IgniteKernal] OS
user: ikorol
2022-11-05T23:24:17,375 INFO [server-0] [main] [o.a.i.i.IgniteKernal]
PID: 2791603
2022-11-05T23:24:17,555 WARN [server-0] [pub-#21]
[o.a.i.i.GridDiagnostic] Initial heap size is 498MB (should be no less
than 512MB, use -Xms512m -Xmx512m).
2022-11-05T23:24:19,993 INFO [server-0] [disco-notifier-worker-#51]
[o.a.i.i.p.c.GridClusterStateProcessor] Received activate cluster
request ...
I think it looks much cleaner, and even if multiple Ignite instances
would log messages to same file,
it would be be easier to separate/grep lines for particular instance
I've attached a diagram that should represent the proposal.
I believe there may be some underwater rocks, but before digging further
I would like to get some feedback,
do you think it may be useful and worth the effort or not.
PS. Diagram description:
Picture represents single physical instance where we run two JVM.
JVM 1 includes two Ignite nodes and some application logic.
JVM 2 is pure Ignite node without third-party code.
Every Ignite instance should supply a tag (discriminator) for Routing
appenders, that will dispatch every message to separate log file.
Application code doesn't provide any tag, so user would have to
configure appenders to route such messages to fallback log file (app.log).
I've also added 2 log files for Ignite 3 instance, to represent node
restart: after restart nodeId was changed, so logging tag was changed as
well, leading to new log file creation.
