Firing events at a certain rate. The test configures the rolling file
appender to roll over once a second.
Specifically, the test ensures that the following works:
* Write log line 1 <-- second 1
* Write log line 2 <-- second 1
* Write log line 3, causes rollover <-- second 2
* Write log line 4 <-- second 2
* Write log line 5, causes rollover <-- second 3
....etc...
Under certain conditions(mostly when running under Github actions on
OSX) this can result in the file having 1 or 3 log messages in it,
instead of exactly 2. So it almost certainly has to do with the
particular scheduling and sleep interaction.
I'm thinking that the best thing to do is to change up the algorithm
slightly so that it does
* write log line 1
* write log line 2
* wait until the next second
* write log line 3, causing rollover
....etc...
-Robert Middleton
On Thu, Jul 1, 2021 at 3:22 PM Volkan Yazıcı <volkan.yaz...@gmail.com> wrote:
>
> What do you exactly mean by "ensuring"? Checking if the event rate was
> correct? Or rather firing events at a certain rate? For the former, you can
> collect all the events, split the collection into buckets of seconds, and
> count the number of events in each bucket. For the latter, did you try busy
> spinning rather than apr_sleep to avoid context switch costs? If I would
> want to implement this in Java, I would use a stock rate limiter, and shoot
> using that. That is,
>
> RateLimiter rateLimiter = RateLimiter.ofPermitsPerSecond(10);
> for (int i = 0; i < l; i++) {
> rateLimiter.acquire(); // This will block if the permit is not
> available.
> // You might want to sleep here some random amount of time, just to
> fluctuate the rate over time.
> logger.debug("event {}", i);
> }
>
> For RateLimiter, I would either use Guava or Resilience4j. I actually have a
> single-class rate limiter implementation
> <https://gist.github.com/vy/2f1ff259e0814c4bf32ee89f3a26dfff> that I stole
> from Resilience4j:
>
> On Tue, Jun 29, 2021 at 3:17 AM Robert Middleton <rmiddle...@apache.org>
> wrote:
>
> > Is there a reliable way to ensure that X number of log messages get
> > written out per second? I ask because one of the problems that we
> > have with log4cxx is that the TimeBasedRollingTest randomly fails(on
> > OSX). I've narrowed it down to the following function:
> >
> > void logMsgAndSleep(Pool & pool,
> > size_t howOften,
> > std::string srcFunc,
> > size_t srcLine,
> > size_t startWith = 0,
> > float waitFactor = 0.5)
> > {
> >
> > for (size_t i = startWith; i < startWith + howOften; ++i)
> > {
> > std::string message("Hello---");
> > message.append(pool.itoa(i));
> >
> > LOG4CXX_DEBUG(logger, message);
> > apr_sleep(APR_USEC_PER_SEC * waitFactor);
> > }
> >
> > }
> >
> > The issue seems to be that due to various scheduling whims, we may not
> > always get the correct number of messages printed out per second, so
> > the test will fail. Is there a better way to do this, perhaps
> > something in log4j?
> >
> > -Robert Middleton
> >
