You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-user@logging.apache.org by Tolga Kavukcu <ka...@gmail.com> on 2017/09/28 08:45:15 UTC
AbstactDatabase appender issue with AsyncLogger
Hello,
I use log4j2 AsycLogger Implementation With a custom database appender.
As i investigated the async logger mechanism works like that.
- Messages are put into DistruptorRingBuffer
*Than *
RingBufferLogEventHandler's onEvent mehtod is called and message is passed
to appender asyncronously.
In *AbstractDatabaseAppender* case
The messages also put into an ArrayList to make batches for bulk insert to
table.
@Override
public final void append(final LogEvent event) {
this.readLock.lock();
try {
this.getManager().write(event);
} catch (final LoggingException e) {
LOGGER.error("Unable to write to database [{}] for appender
[{}].", this.getManager().getName(),
this.getName(), e);
throw e;
} catch (final Exception e) {
LOGGER.error("Unable to write to database [{}] for appender
[{}].", this.getManager().getName(),
this.getName(), e);
throw new AppenderLoggingException("Unable to write to
database in appender: " + e.getMessage(), e);
} finally {
this.readLock.unlock();
}
}
Than Abstract Database manager puts LogEvent into ArrayList
public final synchronized void write(final LogEvent event) {
if (this.bufferSize > 0) {
this.buffer.add(event);
if (this.buffer.size() >= this.bufferSize || event.isEndOfBatch()) {
this.flush();
}
} else {
this.connectAndStart();
try {
this.writeInternal(event);
} finally {
this.commitAndClose();
}
}
}
After that correspoding LogEvent object can be re-used in the
DistruptorRingBuffer mechanism.
So if a delay could happen in the database the LogEvent objects are
overriden with same referance which causes inconsitency while preparing
batches.
I believe this points to a bug or design problem.
Thanks for any help and guidance.
--
*Tolga KAVUKÇU*
Re: AbstactDatabase appender issue with AsyncLogger
Posted by Tolga Kavukcu <ka...@gmail.com>.
I have created LOG4J2-2060.
Thanks.
On Thu, Sep 28, 2017 at 6:33 PM, Matt Sicker <bo...@gmail.com> wrote:
> Yes, a jira ticket would be useful, thanks.
>
> On 28 September 2017 at 09:29, Tolga Kavukcu <ka...@gmail.com>
> wrote:
>
> > Hi Remko,
> >
> > If it's a subject of a bug fix, do you think a ticket should be created.
> So
> > that i can continue the discussion in the dev-list even for a
> contribution.
> >
> > Regards.
> >
> > On Thu, Sep 28, 2017 at 5:21 PM, Remko Popma <re...@gmail.com>
> > wrote:
> >
> > > I'm away from my PC but it sounds like Log4j2 needs to take a snapshot
> of
> > > the log event before adding it to the list.
> > >
> > > (Shameless plug) Every java main() method deserves http://picocli.info
> > >
> > > > On Sep 28, 2017, at 17:45, Tolga Kavukcu <ka...@gmail.com>
> > > wrote:
> > > >
> > > > Hello,
> > > >
> > > > I use log4j2 AsycLogger Implementation With a custom database
> appender.
> > > >
> > > > As i investigated the async logger mechanism works like that.
> > > >
> > > > - Messages are put into DistruptorRingBuffer
> > > >
> > > > *Than *
> > > >
> > > > RingBufferLogEventHandler's onEvent mehtod is called and message is
> > > passed
> > > > to appender asyncronously.
> > > >
> > > > In *AbstractDatabaseAppender* case
> > > >
> > > > The messages also put into an ArrayList to make batches for bulk
> insert
> > > to
> > > > table.
> > > >
> > > > @Override
> > > > public final void append(final LogEvent event) {
> > > > this.readLock.lock();
> > > > try {
> > > > this.getManager().write(event);
> > > > } catch (final LoggingException e) {
> > > > LOGGER.error("Unable to write to database [{}] for appender
> > > > [{}].", this.getManager().getName(),
> > > > this.getName(), e);
> > > > throw e;
> > > > } catch (final Exception e) {
> > > > LOGGER.error("Unable to write to database [{}] for appender
> > > > [{}].", this.getManager().getName(),
> > > > this.getName(), e);
> > > > throw new AppenderLoggingException("Unable to write to
> > > > database in appender: " + e.getMessage(), e);
> > > > } finally {
> > > > this.readLock.unlock();
> > > > }
> > > > }
> > > >
> > > > Than Abstract Database manager puts LogEvent into ArrayList
> > > >
> > > > public final synchronized void write(final LogEvent event) {
> > > > if (this.bufferSize > 0) {
> > > >
> > > > this.buffer.add(event);
> > > > if (this.buffer.size() >= this.bufferSize ||
> > > event.isEndOfBatch()) {
> > > > this.flush();
> > > > }
> > > > } else {
> > > > this.connectAndStart();
> > > > try {
> > > > this.writeInternal(event);
> > > > } finally {
> > > > this.commitAndClose();
> > > > }
> > > > }
> > > > }
> > > >
> > > > After that correspoding LogEvent object can be re-used in the
> > > > DistruptorRingBuffer mechanism.
> > > >
> > > > So if a delay could happen in the database the LogEvent objects are
> > > > overriden with same referance which causes inconsitency while
> preparing
> > > > batches.
> > > >
> > > > I believe this points to a bug or design problem.
> > > >
> > > > Thanks for any help and guidance.
> > > > --
> > > >
> > > > *Tolga KAVUKÇU*
> > >
> > > ---------------------------------------------------------------------
> > > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > > For additional commands, e-mail: log4j-user-help@logging.apache.org
> > >
> > >
> >
> >
> > --
> >
> > *Tolga KAVUKÇU*
> >
>
>
>
> --
> Matt Sicker <bo...@gmail.com>
>
--
*Tolga KAVUKÇU*
Re: AbstactDatabase appender issue with AsyncLogger
Posted by Matt Sicker <bo...@gmail.com>.
Yes, a jira ticket would be useful, thanks.
On 28 September 2017 at 09:29, Tolga Kavukcu <ka...@gmail.com>
wrote:
> Hi Remko,
>
> If it's a subject of a bug fix, do you think a ticket should be created. So
> that i can continue the discussion in the dev-list even for a contribution.
>
> Regards.
>
> On Thu, Sep 28, 2017 at 5:21 PM, Remko Popma <re...@gmail.com>
> wrote:
>
> > I'm away from my PC but it sounds like Log4j2 needs to take a snapshot of
> > the log event before adding it to the list.
> >
> > (Shameless plug) Every java main() method deserves http://picocli.info
> >
> > > On Sep 28, 2017, at 17:45, Tolga Kavukcu <ka...@gmail.com>
> > wrote:
> > >
> > > Hello,
> > >
> > > I use log4j2 AsycLogger Implementation With a custom database appender.
> > >
> > > As i investigated the async logger mechanism works like that.
> > >
> > > - Messages are put into DistruptorRingBuffer
> > >
> > > *Than *
> > >
> > > RingBufferLogEventHandler's onEvent mehtod is called and message is
> > passed
> > > to appender asyncronously.
> > >
> > > In *AbstractDatabaseAppender* case
> > >
> > > The messages also put into an ArrayList to make batches for bulk insert
> > to
> > > table.
> > >
> > > @Override
> > > public final void append(final LogEvent event) {
> > > this.readLock.lock();
> > > try {
> > > this.getManager().write(event);
> > > } catch (final LoggingException e) {
> > > LOGGER.error("Unable to write to database [{}] for appender
> > > [{}].", this.getManager().getName(),
> > > this.getName(), e);
> > > throw e;
> > > } catch (final Exception e) {
> > > LOGGER.error("Unable to write to database [{}] for appender
> > > [{}].", this.getManager().getName(),
> > > this.getName(), e);
> > > throw new AppenderLoggingException("Unable to write to
> > > database in appender: " + e.getMessage(), e);
> > > } finally {
> > > this.readLock.unlock();
> > > }
> > > }
> > >
> > > Than Abstract Database manager puts LogEvent into ArrayList
> > >
> > > public final synchronized void write(final LogEvent event) {
> > > if (this.bufferSize > 0) {
> > >
> > > this.buffer.add(event);
> > > if (this.buffer.size() >= this.bufferSize ||
> > event.isEndOfBatch()) {
> > > this.flush();
> > > }
> > > } else {
> > > this.connectAndStart();
> > > try {
> > > this.writeInternal(event);
> > > } finally {
> > > this.commitAndClose();
> > > }
> > > }
> > > }
> > >
> > > After that correspoding LogEvent object can be re-used in the
> > > DistruptorRingBuffer mechanism.
> > >
> > > So if a delay could happen in the database the LogEvent objects are
> > > overriden with same referance which causes inconsitency while preparing
> > > batches.
> > >
> > > I believe this points to a bug or design problem.
> > >
> > > Thanks for any help and guidance.
> > > --
> > >
> > > *Tolga KAVUKÇU*
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> > For additional commands, e-mail: log4j-user-help@logging.apache.org
> >
> >
>
>
> --
>
> *Tolga KAVUKÇU*
>
--
Matt Sicker <bo...@gmail.com>
Re: AbstactDatabase appender issue with AsyncLogger
Posted by Tolga Kavukcu <ka...@gmail.com>.
Hi Remko,
If it's a subject of a bug fix, do you think a ticket should be created. So
that i can continue the discussion in the dev-list even for a contribution.
Regards.
On Thu, Sep 28, 2017 at 5:21 PM, Remko Popma <re...@gmail.com> wrote:
> I'm away from my PC but it sounds like Log4j2 needs to take a snapshot of
> the log event before adding it to the list.
>
> (Shameless plug) Every java main() method deserves http://picocli.info
>
> > On Sep 28, 2017, at 17:45, Tolga Kavukcu <ka...@gmail.com>
> wrote:
> >
> > Hello,
> >
> > I use log4j2 AsycLogger Implementation With a custom database appender.
> >
> > As i investigated the async logger mechanism works like that.
> >
> > - Messages are put into DistruptorRingBuffer
> >
> > *Than *
> >
> > RingBufferLogEventHandler's onEvent mehtod is called and message is
> passed
> > to appender asyncronously.
> >
> > In *AbstractDatabaseAppender* case
> >
> > The messages also put into an ArrayList to make batches for bulk insert
> to
> > table.
> >
> > @Override
> > public final void append(final LogEvent event) {
> > this.readLock.lock();
> > try {
> > this.getManager().write(event);
> > } catch (final LoggingException e) {
> > LOGGER.error("Unable to write to database [{}] for appender
> > [{}].", this.getManager().getName(),
> > this.getName(), e);
> > throw e;
> > } catch (final Exception e) {
> > LOGGER.error("Unable to write to database [{}] for appender
> > [{}].", this.getManager().getName(),
> > this.getName(), e);
> > throw new AppenderLoggingException("Unable to write to
> > database in appender: " + e.getMessage(), e);
> > } finally {
> > this.readLock.unlock();
> > }
> > }
> >
> > Than Abstract Database manager puts LogEvent into ArrayList
> >
> > public final synchronized void write(final LogEvent event) {
> > if (this.bufferSize > 0) {
> >
> > this.buffer.add(event);
> > if (this.buffer.size() >= this.bufferSize ||
> event.isEndOfBatch()) {
> > this.flush();
> > }
> > } else {
> > this.connectAndStart();
> > try {
> > this.writeInternal(event);
> > } finally {
> > this.commitAndClose();
> > }
> > }
> > }
> >
> > After that correspoding LogEvent object can be re-used in the
> > DistruptorRingBuffer mechanism.
> >
> > So if a delay could happen in the database the LogEvent objects are
> > overriden with same referance which causes inconsitency while preparing
> > batches.
> >
> > I believe this points to a bug or design problem.
> >
> > Thanks for any help and guidance.
> > --
> >
> > *Tolga KAVUKÇU*
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-user-help@logging.apache.org
>
>
--
*Tolga KAVUKÇU*
Re: AbstactDatabase appender issue with AsyncLogger
Posted by Remko Popma <re...@gmail.com>.
I'm away from my PC but it sounds like Log4j2 needs to take a snapshot of the log event before adding it to the list.
(Shameless plug) Every java main() method deserves http://picocli.info
> On Sep 28, 2017, at 17:45, Tolga Kavukcu <ka...@gmail.com> wrote:
>
> Hello,
>
> I use log4j2 AsycLogger Implementation With a custom database appender.
>
> As i investigated the async logger mechanism works like that.
>
> - Messages are put into DistruptorRingBuffer
>
> *Than *
>
> RingBufferLogEventHandler's onEvent mehtod is called and message is passed
> to appender asyncronously.
>
> In *AbstractDatabaseAppender* case
>
> The messages also put into an ArrayList to make batches for bulk insert to
> table.
>
> @Override
> public final void append(final LogEvent event) {
> this.readLock.lock();
> try {
> this.getManager().write(event);
> } catch (final LoggingException e) {
> LOGGER.error("Unable to write to database [{}] for appender
> [{}].", this.getManager().getName(),
> this.getName(), e);
> throw e;
> } catch (final Exception e) {
> LOGGER.error("Unable to write to database [{}] for appender
> [{}].", this.getManager().getName(),
> this.getName(), e);
> throw new AppenderLoggingException("Unable to write to
> database in appender: " + e.getMessage(), e);
> } finally {
> this.readLock.unlock();
> }
> }
>
> Than Abstract Database manager puts LogEvent into ArrayList
>
> public final synchronized void write(final LogEvent event) {
> if (this.bufferSize > 0) {
>
> this.buffer.add(event);
> if (this.buffer.size() >= this.bufferSize || event.isEndOfBatch()) {
> this.flush();
> }
> } else {
> this.connectAndStart();
> try {
> this.writeInternal(event);
> } finally {
> this.commitAndClose();
> }
> }
> }
>
> After that correspoding LogEvent object can be re-used in the
> DistruptorRingBuffer mechanism.
>
> So if a delay could happen in the database the LogEvent objects are
> overriden with same referance which causes inconsitency while preparing
> batches.
>
> I believe this points to a bug or design problem.
>
> Thanks for any help and guidance.
> --
>
> *Tolga KAVUKÇU*
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org