AbstactDatabase appender issue with AsyncLogger

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

AbstactDatabase appender issue with AsyncLogger

Tolga Kavukcu
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*
Reply | Threaded
Open this post in threaded view
|

Re: AbstactDatabase appender issue with AsyncLogger

Remko Popma-2
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 <[hidden email]> 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: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: AbstactDatabase appender issue with AsyncLogger

Tolga Kavukcu
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 <[hidden email]> 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 <[hidden email]>
> 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: [hidden email]
> For additional commands, e-mail: [hidden email]
>
>


--

*Tolga KAVUKÇU*
Reply | Threaded
Open this post in threaded view
|

Re: AbstactDatabase appender issue with AsyncLogger

Matt Sicker
Yes, a jira ticket would be useful, thanks.

On 28 September 2017 at 09:29, Tolga Kavukcu <[hidden email]>
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 <[hidden email]>
> 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 <[hidden email]>
> > 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: [hidden email]
> > For additional commands, e-mail: [hidden email]
> >
> >
>
>
> --
>
> *Tolga KAVUKÇU*
>



--
Matt Sicker <[hidden email]>
Reply | Threaded
Open this post in threaded view
|

Re: AbstactDatabase appender issue with AsyncLogger

Tolga Kavukcu
I have created LOG4J2-2060.

Thanks.

On Thu, Sep 28, 2017 at 6:33 PM, Matt Sicker <[hidden email]> wrote:

> Yes, a jira ticket would be useful, thanks.
>
> On 28 September 2017 at 09:29, Tolga Kavukcu <[hidden email]>
> 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 <[hidden email]>
> > 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 <[hidden email]>
> > > 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: [hidden email]
> > > For additional commands, e-mail: [hidden email]
> > >
> > >
> >
> >
> > --
> >
> > *Tolga KAVUKÇU*
> >
>
>
>
> --
> Matt Sicker <[hidden email]>
>



--

*Tolga KAVUKÇU*