Thank you for the proposal, Ilya!
Looks like a really nice change. I can't see any of the mentioned
attachments for some reason, though
On Sun, Nov 6, 2022 at 10:05 AM Ilya Korol <llivezk...@gmail.com> 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.
>
>
--
With regards,
Aleksandr Polovtsev
