You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@sling.apache.org by piyush goyal <co...@gmail.com> on 2016/06/01 10:19:04 UTC

Fwd: Change in log level removes appenders attached to async appender

Hi Team,

We are trying to writing our custom appenders on top of sling in AEM and
referred to documentation
<https://sling.apache.org/documentation/development/logging.html#appenders-as-osgi-services>.
We want to send logs of the configured loggers to redis. For this, we wrote
a custom Redis Appender extending UnsynchronizedAppenderBase which would
just send the logs to redis. This redis appender is wrapped inside an async
appender which is getting registered as an OSGI service after reading the
redis related configurations from config manager page. Below is a small
snapshot of the custom code:

       redisAppender = new RedisAppender(host, port, redisList);
asyncAppender = new AsyncAppender();
        asyncAppender.setName("ASYNC");
        asyncAppender.setDiscardingThreshold(0);
        asyncAppender.addAppender(this.redisAppender);

        Dictionary<String, Object> asyncProps = new Hashtable<String,
Object>();

        String[] loggers = {
                "com.foo.base"
        };

        asyncAppenderRegistration =
bundleContext.registerService(Appender.class.getName(), asyncAppender,
asyncProps);


  As soon as the async appender is registered as a service, we can see our
logs reaching the redis instance. Since no logging level is defined for the
logger, it inherits from the ROOT logger which is by default INFO. The
problem comes when we try to change the log level of ROOT logger. We saw
that when we change the log level, logbackManager class is called and a
context reset method is executed. After this process, although Async
Appender is still linked to the defined loggers, but async appender looses
the redis appender attached to it.

I tried doing the same process with config fragment as well, but everytime
a change in log level causes redis appender to be detached from the async
appender. I even tried creating factory.config so that I can directly
change the logger level of the my logger and not inheriting it from ROOT
level. But here also async appender detaches the redis appender attached to
it.

What could be the reason behind it? And what should be the correct approach
to be taken so that after changing the log level, async appender does not
detach redis appender.

Thanks and Regards
Piyush Goyal

Re: Change in log level removes appenders attached to async appender

Posted by Chetan Mehrotra <ch...@gmail.com>.
Thanks for the details. Would try to have a look at the issue soon

Chetan Mehrotra

On Thu, Jun 2, 2016 at 4:17 PM, piyush goyal <co...@gmail.com> wrote:

> Hi Chetan,
>
> Thanks for the response. I tried using the work around you referred to.
> Eating up stop() call to didn't work.
> Next was to define our own LoggerContextListener and onReseting starting
> the appender and adding it to async appender.
> This is what I tried to do in the reset method of Listener:
>
>             final ch.qos.logback.classic.Logger ricLogger =
> context.getLogger(logger);
>             AsyncAppender ricAsyncAppender = (AsyncAppender)
> ricLogger.getAppender("ricAsyncAppender");
>             asyncAppender.addAppender(redisAppender);
>
> I tried to add redis appender to already existing async appender of my
> logger. Well this didnt work either because AsyncAppenderBase class uses a
> counter "appenderCount". The problem with this counter is it is only
> updated when an appender is added to async appender and never gets reset to
> 0 either through detachAppender or stop or any method.
>
> Now the already existing thread of asyncAppender has the value of
> appenderCount as 1 but there was no appender attached to it. And since it
> was greater than 0, we can't attach any appender to asyncAppender. :(
>
> The last alternative was to remove the existing asyncAppender from the
> logger. Create a new Async Appender and add that to the logger. Again a new
> problem. The existing AsyncAppender was already registered as a service.
> And any new appender again has to be registered as a service. So now till
> the time I don't unregister the existing appender(Service), my list of
> unused services/appenders kept on increasing because everytime a change in
> log level means a new appender.
> Finally, I was forced to put in a hack with following statements:
>
>   if (asyncAppenderRegistration != null) {
>                 asyncAppenderRegistration.unregister();
>             }
>
>             asyncAppenderRegistration =
> bundleContext.registerService(Appender.class.getName(), asyncAppender,
> serviceRegistrationProps);
>
> That is unregistering the previously defined async appender as services and
> registering new appender as service.
>
> Hope to see the bug fix soon.
>
> Thanks and Regards
> Piyush Goyal
>
> On Wed, Jun 1, 2016 at 5:39 PM, Chetan Mehrotra <chetan.mehrotra@gmail.com
> >
> wrote:
>
> > Looks like a bug in Sling Logback integration. What happens here is that
> >
> > 1. On initial registration of Appender the AppenderTracker in Sling
> Commons
> > Log would "start" the appender and attach it to logger
> >
> > 2. When you change the log level  via global config it kinds of reset the
> > Logback. In reset it would "stop" the appender and detach it
> >
> > 3. Post reset Sling Commons Log would again "attach" the appender but
> would
> > not start it again.
> >
> > Now for in memory appenders this would not cause issue. But for async
> > appender once it is stopped the backing thread is shutdown and as there
> is
> > no further start the thread does not get started again.
> >
> > Can you open a bug for this in Sling?
> >
> > For now you can go for workaround
> >
> > 1. Implement a LoggerContextListener [1] and have its isResetResistant
> > return true
> > 2. Register this listener with LoggerContext - You can get that via
> casting
> > org.slf4j.LoggerFactory.getILoggerFactory()
> > 3. Then onReset you start the appender again
> >
> > Or you eat out the stop call and stop it upon your component
> deactivation!
> >
> > Chetan Mehrotra
> >
> > [1]
> >
> >
> http://logback.qos.ch/apidocs/ch/qos/logback/classic/spi/LoggerContextListener.html
> >
> > On Wed, Jun 1, 2016 at 3:49 PM, piyush goyal <co...@gmail.com>
> > wrote:
> >
> > > Hi Team,
> > >
> > > We are trying to writing our custom appenders on top of sling in AEM
> and
> > > referred to documentation
> > > <
> > >
> >
> https://sling.apache.org/documentation/development/logging.html#appenders-as-osgi-services
> > > >.
> > > We want to send logs of the configured loggers to redis. For this, we
> > wrote
> > > a custom Redis Appender extending UnsynchronizedAppenderBase which
> would
> > > just send the logs to redis. This redis appender is wrapped inside an
> > async
> > > appender which is getting registered as an OSGI service after reading
> the
> > > redis related configurations from config manager page. Below is a small
> > > snapshot of the custom code:
> > >
> > >        redisAppender = new RedisAppender(host, port, redisList);
> > > asyncAppender = new AsyncAppender();
> > >         asyncAppender.setName("ASYNC");
> > >         asyncAppender.setDiscardingThreshold(0);
> > >         asyncAppender.addAppender(this.redisAppender);
> > >
> > >         Dictionary<String, Object> asyncProps = new Hashtable<String,
> > > Object>();
> > >
> > >         String[] loggers = {
> > >                 "com.foo.base"
> > >         };
> > >
> > >         asyncAppenderRegistration =
> > > bundleContext.registerService(Appender.class.getName(), asyncAppender,
> > > asyncProps);
> > >
> > >
> > >   As soon as the async appender is registered as a service, we can see
> > our
> > > logs reaching the redis instance. Since no logging level is defined for
> > the
> > > logger, it inherits from the ROOT logger which is by default INFO. The
> > > problem comes when we try to change the log level of ROOT logger. We
> saw
> > > that when we change the log level, logbackManager class is called and a
> > > context reset method is executed. After this process, although Async
> > > Appender is still linked to the defined loggers, but async appender
> > looses
> > > the redis appender attached to it.
> > >
> > > I tried doing the same process with config fragment as well, but
> > everytime
> > > a change in log level causes redis appender to be detached from the
> async
> > > appender. I even tried creating factory.config so that I can directly
> > > change the logger level of the my logger and not inheriting it from
> ROOT
> > > level. But here also async appender detaches the redis appender
> attached
> > to
> > > it.
> > >
> > > What could be the reason behind it? And what should be the correct
> > approach
> > > to be taken so that after changing the log level, async appender does
> not
> > > detach redis appender.
> > >
> > > Thanks and Regards
> > > Piyush Goyal
> > >
> >
>

Re: Change in log level removes appenders attached to async appender

Posted by piyush goyal <co...@gmail.com>.
Hi Chetan,

Thanks for the response. I tried using the work around you referred to.
Eating up stop() call to didn't work.
Next was to define our own LoggerContextListener and onReseting starting
the appender and adding it to async appender.
This is what I tried to do in the reset method of Listener:

            final ch.qos.logback.classic.Logger ricLogger =
context.getLogger(logger);
            AsyncAppender ricAsyncAppender = (AsyncAppender)
ricLogger.getAppender("ricAsyncAppender");
            asyncAppender.addAppender(redisAppender);

I tried to add redis appender to already existing async appender of my
logger. Well this didnt work either because AsyncAppenderBase class uses a
counter "appenderCount". The problem with this counter is it is only
updated when an appender is added to async appender and never gets reset to
0 either through detachAppender or stop or any method.

Now the already existing thread of asyncAppender has the value of
appenderCount as 1 but there was no appender attached to it. And since it
was greater than 0, we can't attach any appender to asyncAppender. :(

The last alternative was to remove the existing asyncAppender from the
logger. Create a new Async Appender and add that to the logger. Again a new
problem. The existing AsyncAppender was already registered as a service.
And any new appender again has to be registered as a service. So now till
the time I don't unregister the existing appender(Service), my list of
unused services/appenders kept on increasing because everytime a change in
log level means a new appender.
Finally, I was forced to put in a hack with following statements:

  if (asyncAppenderRegistration != null) {
                asyncAppenderRegistration.unregister();
            }

            asyncAppenderRegistration =
bundleContext.registerService(Appender.class.getName(), asyncAppender,
serviceRegistrationProps);

That is unregistering the previously defined async appender as services and
registering new appender as service.

Hope to see the bug fix soon.

Thanks and Regards
Piyush Goyal

On Wed, Jun 1, 2016 at 5:39 PM, Chetan Mehrotra <ch...@gmail.com>
wrote:

> Looks like a bug in Sling Logback integration. What happens here is that
>
> 1. On initial registration of Appender the AppenderTracker in Sling Commons
> Log would "start" the appender and attach it to logger
>
> 2. When you change the log level  via global config it kinds of reset the
> Logback. In reset it would "stop" the appender and detach it
>
> 3. Post reset Sling Commons Log would again "attach" the appender but would
> not start it again.
>
> Now for in memory appenders this would not cause issue. But for async
> appender once it is stopped the backing thread is shutdown and as there is
> no further start the thread does not get started again.
>
> Can you open a bug for this in Sling?
>
> For now you can go for workaround
>
> 1. Implement a LoggerContextListener [1] and have its isResetResistant
> return true
> 2. Register this listener with LoggerContext - You can get that via casting
> org.slf4j.LoggerFactory.getILoggerFactory()
> 3. Then onReset you start the appender again
>
> Or you eat out the stop call and stop it upon your component deactivation!
>
> Chetan Mehrotra
>
> [1]
>
> http://logback.qos.ch/apidocs/ch/qos/logback/classic/spi/LoggerContextListener.html
>
> On Wed, Jun 1, 2016 at 3:49 PM, piyush goyal <co...@gmail.com>
> wrote:
>
> > Hi Team,
> >
> > We are trying to writing our custom appenders on top of sling in AEM and
> > referred to documentation
> > <
> >
> https://sling.apache.org/documentation/development/logging.html#appenders-as-osgi-services
> > >.
> > We want to send logs of the configured loggers to redis. For this, we
> wrote
> > a custom Redis Appender extending UnsynchronizedAppenderBase which would
> > just send the logs to redis. This redis appender is wrapped inside an
> async
> > appender which is getting registered as an OSGI service after reading the
> > redis related configurations from config manager page. Below is a small
> > snapshot of the custom code:
> >
> >        redisAppender = new RedisAppender(host, port, redisList);
> > asyncAppender = new AsyncAppender();
> >         asyncAppender.setName("ASYNC");
> >         asyncAppender.setDiscardingThreshold(0);
> >         asyncAppender.addAppender(this.redisAppender);
> >
> >         Dictionary<String, Object> asyncProps = new Hashtable<String,
> > Object>();
> >
> >         String[] loggers = {
> >                 "com.foo.base"
> >         };
> >
> >         asyncAppenderRegistration =
> > bundleContext.registerService(Appender.class.getName(), asyncAppender,
> > asyncProps);
> >
> >
> >   As soon as the async appender is registered as a service, we can see
> our
> > logs reaching the redis instance. Since no logging level is defined for
> the
> > logger, it inherits from the ROOT logger which is by default INFO. The
> > problem comes when we try to change the log level of ROOT logger. We saw
> > that when we change the log level, logbackManager class is called and a
> > context reset method is executed. After this process, although Async
> > Appender is still linked to the defined loggers, but async appender
> looses
> > the redis appender attached to it.
> >
> > I tried doing the same process with config fragment as well, but
> everytime
> > a change in log level causes redis appender to be detached from the async
> > appender. I even tried creating factory.config so that I can directly
> > change the logger level of the my logger and not inheriting it from ROOT
> > level. But here also async appender detaches the redis appender attached
> to
> > it.
> >
> > What could be the reason behind it? And what should be the correct
> approach
> > to be taken so that after changing the log level, async appender does not
> > detach redis appender.
> >
> > Thanks and Regards
> > Piyush Goyal
> >
>

Re: Change in log level removes appenders attached to async appender

Posted by Chetan Mehrotra <ch...@gmail.com>.
Looks like a bug in Sling Logback integration. What happens here is that

1. On initial registration of Appender the AppenderTracker in Sling Commons
Log would "start" the appender and attach it to logger

2. When you change the log level  via global config it kinds of reset the
Logback. In reset it would "stop" the appender and detach it

3. Post reset Sling Commons Log would again "attach" the appender but would
not start it again.

Now for in memory appenders this would not cause issue. But for async
appender once it is stopped the backing thread is shutdown and as there is
no further start the thread does not get started again.

Can you open a bug for this in Sling?

For now you can go for workaround

1. Implement a LoggerContextListener [1] and have its isResetResistant
return true
2. Register this listener with LoggerContext - You can get that via casting
org.slf4j.LoggerFactory.getILoggerFactory()
3. Then onReset you start the appender again

Or you eat out the stop call and stop it upon your component deactivation!

Chetan Mehrotra

[1]
http://logback.qos.ch/apidocs/ch/qos/logback/classic/spi/LoggerContextListener.html

On Wed, Jun 1, 2016 at 3:49 PM, piyush goyal <co...@gmail.com> wrote:

> Hi Team,
>
> We are trying to writing our custom appenders on top of sling in AEM and
> referred to documentation
> <
> https://sling.apache.org/documentation/development/logging.html#appenders-as-osgi-services
> >.
> We want to send logs of the configured loggers to redis. For this, we wrote
> a custom Redis Appender extending UnsynchronizedAppenderBase which would
> just send the logs to redis. This redis appender is wrapped inside an async
> appender which is getting registered as an OSGI service after reading the
> redis related configurations from config manager page. Below is a small
> snapshot of the custom code:
>
>        redisAppender = new RedisAppender(host, port, redisList);
> asyncAppender = new AsyncAppender();
>         asyncAppender.setName("ASYNC");
>         asyncAppender.setDiscardingThreshold(0);
>         asyncAppender.addAppender(this.redisAppender);
>
>         Dictionary<String, Object> asyncProps = new Hashtable<String,
> Object>();
>
>         String[] loggers = {
>                 "com.foo.base"
>         };
>
>         asyncAppenderRegistration =
> bundleContext.registerService(Appender.class.getName(), asyncAppender,
> asyncProps);
>
>
>   As soon as the async appender is registered as a service, we can see our
> logs reaching the redis instance. Since no logging level is defined for the
> logger, it inherits from the ROOT logger which is by default INFO. The
> problem comes when we try to change the log level of ROOT logger. We saw
> that when we change the log level, logbackManager class is called and a
> context reset method is executed. After this process, although Async
> Appender is still linked to the defined loggers, but async appender looses
> the redis appender attached to it.
>
> I tried doing the same process with config fragment as well, but everytime
> a change in log level causes redis appender to be detached from the async
> appender. I even tried creating factory.config so that I can directly
> change the logger level of the my logger and not inheriting it from ROOT
> level. But here also async appender detaches the redis appender attached to
> it.
>
> What could be the reason behind it? And what should be the correct approach
> to be taken so that after changing the log level, async appender does not
> detach redis appender.
>
> Thanks and Regards
> Piyush Goyal
>