Intermittent -broken simulation.log - java.lang.NumberFormatException: For input string: "161701795909url get request"

[Victor Tanase]

Hi,

I have noticed an intermittent issue when running tests  which fails with connection times out.

I'm not sure if this is acoincidence but each time I see a broken report there are also error messages (connection timeout most of the cases)

I haven't seen it so far for successfull tests.

The test I'm running is the following: 2000-5000 active users/injector with peak requests rate of 700req/sec.

Is there a way to avoid these  exceptions ?

Thank you in advance!

gatling.version: 3.5.1 (tried also with 3.2.0 with same results)

gatling.maven.plugin.version:3.1.(3.0.5)

scala-maven-plugin.version 4.4.1(4.1.1)

Guilty line:

USER   Varnish START   161701795909url get request     1617017959045   1617017959066   KO      status.find.is(200), but actually found 429

Exception sample catched when trying to merge  report from multiple injectors:

Exception in thread "main" java.lang.NumberFormatException: For input string: "161701795909url get request"

        at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)

        at java.lang.Long.parseLong(Long.java:589)

        at java.lang.Long.parseLong(Long.java:631)

        at scala.collection.StringOps$.toLong$extension(StringOps.scala:902)

        at io.gatling.charts.stats.LogFileReader.$anonfun$firstPass$1(LogFileReader.scala:98)

        at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:553)

        at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:551)

        at scala.collection.AbstractIterator.foreach(Iterator.scala:1279)

        at io.gatling.charts.stats.LogFileReader.firstPass(LogFileReader.scala:87)

        at io.gatling.charts.stats.LogFileReader.$anonfun$firstPassData$1(LogFileReader.scala:139)

        at io.gatling.charts.stats.LogFileReader.parseInputFiles(LogFileReader.scala:65)

        at io.gatling.charts.stats.LogFileReader.<init>(LogFileReader.scala:139)

        at io.gatling.app.RunResultProcessor.initLogFileReader(RunResultProcessor.scala:52)

        at io.gatling.app.RunResultProcessor.processRunResult(RunResultProcessor.scala:34)

        at io.gatling.app.Gatling$.start(Gatling.scala:89)

        at io.gatling.app.Gatling$.fromArgs(Gatling.scala:45)

        at io.gatling.app.Gatling$.main(Gatling.scala:37)

        at io.gatling.app.Gatling.main(Gatling.scala)

another example:

12:50:36,048 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]

12:50:36,048 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]

12:50:36,048 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [jar:file:zzzzz.jar!/logback.xml]

12:50:36,056 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@763d9750 - URL [jar:file:/opt/gatling/zzzzz.jar.jar!/logback.xml] is not of type file

12:50:36,099 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set

12:50:36,099 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]

12:50:36,104 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [CONSOLE]

12:50:36,108 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property

12:50:36,145 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender]

12:50:36,148 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE]

12:50:36,153 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property

12:50:36,153 |-INFO in ch.qos.logback.core.FileAppender[FILE] - File property is set to [GATLING_LOGS_IS_UNDEFINED/gatling_logs/test_loadtest-gatling-summary-936323-f2t95.log]

12:50:36,156 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@17:22 - no applicable action for [immediateFlush], current ElementPath  is [[configuration][immediateFlush]]

12:50:36,156 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to ERROR

12:50:36,156 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[ROOT]

12:50:36,156 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.

12:50:36,157 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@5c0369c4 - Registering current configuration as safe fallback point

Parsing log file(s)...

Exception in thread "main" java.lang.NumberFormatException: For input string: "START"

        at java.lang.NumberFormatException.forInputString(NumberFormatException.java:65)

        at java.lang.Long.parseLong(Long.java:589)

        at java.lang.Long.parseLong(Long.java:631)

        at scala.collection.StringOps$.toLong$extension(StringOps.scala:902)

        at io.gatling.charts.stats.LogFileReader.$anonfun$firstPass$1(LogFileReader.scala:98)

        at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:553)

        at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:551)

        at scala.collection.AbstractIterator.foreach(Iterator.scala:1279)

        at io.gatling.charts.stats.LogFileReader.firstPass(LogFileReader.scala:87)

        at io.gatling.charts.stats.LogFileReader.$anonfun$firstPassData$1(LogFileReader.scala:139)

        at io.gatling.charts.stats.LogFileReader.parseInputFiles(LogFileReader.scala:65)

        at io.gatling.charts.stats.LogFileReader.<init>(LogFileReader.scala:139)

        at io.gatling.app.RunResultProcessor.initLogFileReader(RunResultProcessor.scala:52)

        at io.gatling.app.RunResultProcessor.processRunResult(RunResultProcessor.scala:34)

        at io.gatling.app.Gatling$.start(Gatling.scala:89)

        at io.gatling.app.Gatling$.fromArgs(Gatling.scala:45)

        at io.gatling.app.Gatling$.main(Gatling.scala:37)

        at io.gatling.app.Gatling.main(Gatling.scala)

[Stéphane LANDELLE]

Honestly, no idea, all the more as this issue has never been reported until now.

Please provide a way to reproduce on our side.

Stéphane Landelle Chief Technical Officer twitter: @slandelle site: gatling.io

--
You received this message because you are subscribed to the Google Groups "Gatling User Group" group.
To unsubscribe from this group and stop receiving emails from it, send an email to gatling+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/gatling/5efdd68e-77ea-4f48-a7d1-42afbcad6639n%40googlegroups.com.

[Victor Tanase]

You can use the below simplified sample script.

Run it from multiple injectors (keep increasing the injector number until it wil reproduce).

I noticed it crashed even with more gentle scenarios (3000-4000 req/sec).Workaround was to run test one more time but when huge amount of req/high error rate then the simulation.log is beyond repair and running it twice will produce the same result.

import scala.concurrent.duration._

class InfraSimulation extends Simulation {

  val activeUser=200

  val rampUpTime=10

  val rpsAtPeakReachInSecs=80

  val rpsAtPeak=700

  val holdPeakRPSInSecs=60

  val minPauseDuration=1

  val maxPauseDuration=2

  val rpsAtMean=40

  val holdMeanRPSInSecs=60

  

  private val users = constantUsersPerSec(activeUser) during (rampUpTime seconds)

  private val varnishUrl: steps.GatlingSiteUrlGet = new steps.GatlingSiteUrlGet()

  var scn = scenario("Test")

    .repeat(5) {

      exec(varnishUrl.VarnishGetCall(AppConfig.host)).pause(minPauseDuration, maxPauseDuration)

    }

  setUp(scn.inject(users))

    .protocols(AppConfig.httpProtocol)

    .throttle(reachRps(rpsAtPeak) in (rpsAtPeakReachInSecs seconds),

      holdFor(holdPeakRPSInSecs seconds), jumpToRps(rpsAtMean), holdFor(holdMeanRPSInSecs seconds))

}

import io.gatling.core.Predef._

import io.gatling.http.Predef._

class GatlingSiteUrlGet {

  def VarnishGetCall(hostname: String) = {

        exec(http("url get request")

        .get("http://computer-database.gatling.io")

        .check(status.is(200))

      )

[Stéphane LANDELLE]

> Run it from multiple injectors (keep increasing the injector number until it will reproduce).

It looks like an issue with your custom made distributed Gatling solution.

I recommend you have a look at FrontLine that officially supports this use case.

Regards,

Stéphane Landelle Chief Technical Officer twitter: @slandelle site: gatling.io

To view this discussion on the web visit https://groups.google.com/d/msgid/gatling/b85ebee6-cc00-4367-93bd-e647903fccb3n%40googlegroups.com.

[Victor Tanase]

So your suspicion is  it is more something related to the environment than a software issue?

[Stéphane LANDELLE]

Most likely, yes.

Stéphane Landelle Chief Technical Officer twitter: @slandelle site: gatling.io

To view this discussion on the web visit https://groups.google.com/d/msgid/gatling/809c3b70-624c-4485-9533-bb119da26eefn%40googlegroups.com.