codecentric / gatling-jdbc

JDBC support for Gatling
Apache License 2.0
23 stars 18 forks source link

Queries running sequentially and not parallel for virtual users #2

Closed hinawatts closed 6 years ago

hinawatts commented 6 years ago

Hi, I am trying to use jdbc protocol with 10 virtual users using atOnce(10) where I expected the queries in my data set would run in parallel. But the queries are running sequentially where one user starts and complete the query and then the next query is picked by next user.

rbraeunlich commented 6 years ago

Hi @hina1234 that is of course a big no-go. I'll have a look into that immediately. How did you recognize that the queries were running sequentially?

rbraeunlich commented 6 years ago

I created a simple scenario to check the parallel execution.

  val feeder = Iterator.continually(Map("rand" -> (Random.alphanumeric.take(20).mkString + "@foo.com")))

  val testScenario = scenario("createTable").
    exec(jdbc("bar table")
      .create()
      .table("bar")
      .columns(
        column(
          name("abc"),
          dataType("VARCHAR"),
          constraint("PRIMARY KEY")
        )
      )
    )
    .feed(feeder)
    .repeat(10, "n") {
    exec(jdbc("insertion")
      .insert()
      .into("bar (abc)")
      .values("'${rand} + ${n}'")
    )
  }

And in the simulation.log I can see intermixed execution times and users (createTable might now be the best scenario name):

REQUEST createTable 5       insertion   1530862515339   1530862515359   OK   
REQUEST createTable 5       insertion   1530862515360   1530862515361   OK   
REQUEST createTable 7       insertion   1530862515338   1530862515362   OK   
REQUEST createTable 5       insertion   1530862515361   1530862515363   OK   
REQUEST createTable 7       insertion   1530862515362   1530862515364   OK   
REQUEST createTable 2       insertion   1530862515332   1530862515364   OK   
REQUEST createTable 3       insertion   1530862515337   1530862515365   OK   
REQUEST createTable 8       insertion   1530862515338   1530862515365   OK   
REQUEST createTable 5       insertion   1530862515363   1530862515365   OK   
hinawatts commented 6 years ago

I am using the scenario as below -

var testScenario = scenario("select table").feed(csvfeeder).exec(runquery)
def runQuery = exec(jdbc("selection").customQuery .query(s"${queryFromFeeder.toString}"))
 setUp(testScenario.inject(atOnceUsers(10))).protocols(jdbcConfig) 
```(where jdbcConfig is jdbc initialized with database details)

For customQuery I have included below code in gatling-jdbc 

case class JdbcCustomQueryAction(requestName: Expression[String], query: Expression[String], checks: List[JdbcCheck], statsEngine: StatsEngine, next: Action) extends JdbcAction {

override def name: String = genName("jdbcCustomQuery")

override def execute(session: Session): Unit = { val start = nowMillis

val validatedQuery = query.apply(session)

val sqlString = validatedQuery match {
  case (Success(queryString)) => queryString
  case _ => throw new IllegalArgumentException
}

println(s"Query is $sqlString")

val tried = Try(DB autoCommit { implicit session =>
  SQL(sqlString).map(rs => rs.toMap()).toList().apply()
})

if (tried.isSuccess) {
  performChecks(session, start, tried.get)
} else {
  tried.recover {
    case psqlException: org.postgresql.util.PSQLException if psqlException.getSQLState == "02000" =>
      log(start, nowMillis, scala.util.Success(""), requestName, session, statsEngine)
    case x: Throwable => println(s"Throws error $x")
      log(start, nowMillis, tried, requestName, session, statsEngine)
  }
  next ! session
}

}

hinawatts commented 6 years ago

I have added print statement in JdbcCustomQueryAction, to print the query before executing. This print is happening each time the previous query gets completed. So on start, one query gets printed, and I get active=10, done=0 in log. When done gets equal to 1, another query gets printed. In parallel scenario, another query print should not wait for previous query to complete.

hinawatts commented 6 years ago

@rbraeunlich - Did you get a chance to look into this?

rbraeunlich commented 6 years ago

Hi @hina1234 Unfortunately not yet, but it's my first priority on Friday.

rbraeunlich commented 6 years ago

Hey @hina1234 I think I found the problem. It seems like the problem was the call

val tried = Try(DB autoCommit { implicit session =>
  SQL(sqlString).map(rs => rs.toMap()).toList().apply()
})

And the ones in the other action classes accordingly. Since JDBC is blocking, the call waits for it to return. The session is not being passed to the next action and therefore everything finishes in order. Wrapping the whole thing in a future should solve this, e.g. like:

        val future = Future {
          DB autoCommit { implicit session =>
            SQL(s).execute().apply()
          }
        }
        future.onComplete(result => log(start, nowMillis, result, requestName, session, statsEngine)
        )

I will try to find a way to force the simulation to wait for the statements to finish before exiting.

rbraeunlich commented 6 years ago

@hina1234 I pushed a fix now that should solve the problem. When you confirm the same with your custom JDBC action I will publish a 1.0.1 version containing the fix. If not we can re-open the issue.