Slowness during test execution

Hello everyone,

I am writing to you today because I need your help… When I launch my testSuite, from the 52nd test, Katalon Runtime takes more than 2 minutes to launch the browser instead of 10 seconds. Another project has exactly the same problem.
We run all this on a Linux VM.

My theory is that it would come from the machine side but we have enabled all the options to kill the different processes at the end of the processing. And nothing in the logs…
Have you ever had or heard of this issue please? I’ve tried a lot of things and I’m out of ideas.

Thanks in advance to all for your help !
Paul

Before the 52nd test :

From the 52nd test :

PS : I’m in last version of Katalon Studio ofc

Please check this thread …

1 Like

Hi discover.selenium,

Sorry for the delay, but : I have check this thread and we decide to upgrade our configuration to 20Go RAM (16Go → 20Go) and I see no change… Always the same bug at the 52nd test…

Any other idea please ?

have you tuned also the jvm xms and xmx allocations on your vm’s accordingly?
you can allocate terrabytes of resources to your ‘physical’ host
does KRE use them?

You should monitor how much memory KRE process occupies.

Try VisualVM to monitor the Heap size occupied by JVM. VisualVM is a good one and free of charge.

https://visualvm.github.io/

However, I guess that the allocatedJVM Heap size is not the cause of the problem of @paul.dufau.

Then why? ---- I don’t know.

@paul.dufau needs to investigate himself more before asking others for help.

You should check the way how your test script opens/closes browser.

Which type of browser — Chrome, FF, Edge ---- ? You should try other types and see what happens.

Is the browser opened Headless or Headed? You should try other mode and see what happens.

Does your Test Case "02 - ActionsComptes/ConnexionEntrepriseCree" opens/closes browser, or not? If not, how do you open browser? Do you have a Test Case "01 - ActionsComputes/openBrowser" and "xx - ActionsComputes/closeBrowser" ?

Does your script close the browser before opening a new one? or does your script opens multiple browsers — up 52 windows?

How many windows of browser do you open at a time? Are you aware of it?

Do you specify any Desired Capabilities when you open browser?

1 Like

Hello @kazurayam, hello all,

I took my time to answer because this was not at all part of the priorities as I only have one test suite with this problem because it is the only one with more than 50 tests.

To answer your questions, we have well analyzed the VM during its use:

  • the processor is never overloaded
  • the RAM is not overloaded either

On the test side:

  • We tried on Chrome and Firefox → same problem
  • We tried headless and headed → same problem
  • We open the browser at the beginning of the test and we close it at the end
  • We kill the WebDriver process at the end of each test

We are up to date at system/katalon/browser level

Here is the trace of the logs that we have when the bug occurs:

When working :

INFO: Using `new FirefoxOptions()` is preferred to `DesiredCapabilities.firefox()`
2023-02-16 09:06:43.603 INFO  c.k.k.c.w.util.WebDriverPropertyUtil     - User set preference: ['args', '[window-size=1920,1080]']
2023-02-16 09:06:43.603 INFO  c.k.k.core.webui.driver.DriverFactory    - Action delay is set to 850 milliseconds
1676538403655	geckodriver	INFO	Listening on 127.0.0.1:22765
1676538403702	mozrunner::runner	INFO	Running command: "/usr/lib/firefox/firefox" "--marionette" "-no-remote" "-profile" "/tmp/rust_mozprofileJHab5x"
[GFX1-]: glxtest: libpci missing
[GFX1-]: glxtest: libEGL missing
1676538404495	Marionette	INFO	Marionette enabled
1676538404499	Marionette	INFO	Listening on port 39535
Read port: 39535
1676538404629	RemoteAgent	WARN	TLS certificate errors will be ignored for this session
1676538404629	RemoteAgent	INFO	Proxy settings initialised: {"proxyType":"direct"}
console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/rust_mozprofileJHab5x/search.json.mozlz4", (void 0)))
Feb 16, 2023 9:06:45 AM org.openqa.selenium.remote.ProtocolHandshake createSession
INFO: Detected dialect: W3C
2023-02-16 09:06:45.958 INFO  c.k.k.core.webui.driver.DriverFactory    - sessionId = ae43f1de-6cbe-49de-8213-25e52560de74
2023-02-16 09:06:45.969 INFO  c.k.k.core.webui.driver.DriverFactory    - browser = Firefox 107.0
2023-02-16 09:06:45.970 INFO  c.k.k.core.webui.driver.DriverFactory    - platform = Linux
2023-02-16 09:06:45.970 INFO  c.k.k.core.webui.driver.DriverFactory    - seleniumVersion = 3.141.59

When we got the problem :

INFO: Using `new FirefoxOptions()` is preferred to `DesiredCapabilities.firefox()`
2023-02-16 09:49:41.998 INFO  c.k.k.c.w.util.WebDriverPropertyUtil     - User set preference: ['args', '[window-size=1920,1080]']
2023-02-16 09:49:41.998 INFO  c.k.k.core.webui.driver.DriverFactory    - Action delay is set to 850 milliseconds
1676540982170	geckodriver	INFO	Listening on 127.0.0.1:19967
1676540982587	mozrunner::runner	INFO	Running command: "/usr/lib/firefox/firefox" "--marionette" "-no-remote" "-profile" "/tmp/rust_mozprofile3zAawU"
[GFX1-]: glxtest: libpci missing
[GFX1-]: glxtest: libEGL missing
1676540984259	Marionette	INFO	Marionette enabled
1676540984269	Marionette	INFO	Listening on port 32853
Read port: 32853
1676540984682	RemoteAgent	WARN	TLS certificate errors will be ignored for this session
1676540984685	RemoteAgent	INFO	Proxy settings initialised: {"proxyType":"direct"}
console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/rust_mozprofile3zAawU/search.json.mozlz4", (void 0)))
Feb 16, 2023 9:49:48 AM org.openqa.selenium.remote.ProtocolHandshake createSession
INFO: Detected dialect: W3C

--------------------------------------------------------------------------------
Test Suites/TS/99-ExecutionTotale - Firefox - 20230216_090308........54/143(38%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
Test Suites/TS/99-ExecutionTotale - Firefox - 20230216_090308........54/143(38%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
Test Suites/TS/99-ExecutionTotale - Firefox - 20230216_090308........54/143(38%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
Test Suites/TS/99-ExecutionTotale - Firefox - 20230216_090308........54/143(38%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
Test Suites/TS/99-ExecutionTotale - Firefox - 20230216_090308........54/143(38%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
Test Suites/TS/99-ExecutionTotale - Firefox - 20230216_090308........54/143(38%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
Test Suites/TS/99-ExecutionTotale - Firefox - 20230216_090308........54/143(38%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
Test Suites/TS/99-ExecutionTotale - Firefox - 20230216_090308........54/143(38%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
Test Suites/TS/99-ExecutionTotale - Firefox - 20230216_090308........54/143(38%)
--------------------------------------------------------------------------------

2023-02-16 09:51:58.639 INFO  c.k.k.core.webui.driver.DriverFactory    - sessionId = af9d0cd0-415c-4793-8006-801033d0fe95
2023-02-16 09:51:58.692 INFO  c.k.k.core.webui.driver.DriverFactory    - browser = Firefox 107.0
2023-02-16 09:51:58.692 INFO  c.k.k.core.webui.driver.DriverFactory    - platform = Linux
2023-02-16 09:51:58.692 INFO  c.k.k.core.webui.driver.DriverFactory    - seleniumVersion = 3.141.59

We can see that there is a repetition of

--------------------------------------------------------------------------------
Test Suites/TS/99-ExecutionTotale - Firefox - 20230216_090308........54/143(38%)
--------------------------------------------------------------------------------

for no reason and I have no explanation for this. Did I miss something ?

I am thinking about this concern to fix it now so I will answer quickly if you need more logs or information about our structure.

Sorry, I do not think I can help you with this issue.

There seem to be a bug of Katalon here. But I can’t see anything informative in what you provided.

Do you execute this Test Case as a part of a Test Suite?

If you execute a Test Suite, then check its “Execution Information”

You have configured an immediate retry for hundreds of times, don’t you?

Hi!

Omg, you are not ready to this… After many exchanges with Katalon customer service, here is the solution:

  1. Create a new package com.kms.katalon.core.webui.driver and a class DriverFactory2.java in the folder Include/scripts/groovy

  2. Copy the content of the attached file into DriverFactory2.java

DriverFactory2.java (73.8 KB)

  1. Replace the WebUI.openBrowser() keyword with the script below:

import org.openqa.selenium.WebDriver
import com.kms.katalon.core.webui.driver.DriverFactory
import com.kms.katalon.core.webui.driver.DriverFactory2
import com.kms.katalon.core.webui.keyword.WebUiBuiltInKeywords as WebUI

WebDriver driver = DriverFactory2.openWebDriver()DriverFactory2.java
DriverFactory.changeWebDriver(driver)

Here is the reason of the problem :
"We see the potential issue here is that the 50th+ WebDriver instance will start after 2 minutes when running Test Suite that contains more than 50 WebUI test cases on a Linux environment (including a Docker environment). Our development team is planning the investigate and fix this issue soon. "

Thanks you all for your help! I hope that will help some other!

I have seen very similar issue as described here related to over 50 test but noticed that Katalon tests running inside katalon containers behaves differently depending on underlying Linux OS kernel. Did two identical setups of VMs, one AlmaLinux 8 and CentOS 7 with Docker on top etc. Running the containerized tests on AlmaLinux 8 then I see the issues where it kind of seems to hang for around 2 minutes when you run WebUI.openBrowser. Running that container with exact same configuration on CentOS 7 with Docker then I do not see these issues.

My conclusion is that the root cause issues are related somewhere around system calls or other kernel related things since we are running in containers with exact setups of Docker and very similar OS setups. Right now I do not have any clue to understand the root cause and if it is possible to solve in some additional configuration to ChromeDriver or in the OS or container runtime etc.

well… hard to compare such.
centos7 is really old.
alma8 will be the equivalent of centos8 but not identical
so, different kernel generation, different init system, different docker versions etc.

even if the vm’s hardware capabilities are similar, too many differences at the OS and associated software level

Yes, I know there are many aspects here but I was trying to limit the different moving parts to see if for example Linux OS with kernel 3.x performing similar to kernel 4.x, both based on RHEL source. We are talking about tests passing in 10 minutes compared to 20 minutes or more when running on AlmaLinux 8.

  1. My tests were done on same underlying physical hardware to rule out that aspect
  2. Installation of Docker and configuration of OS is as similar as possible because I use same automation for the OSes (CentOS 7 and AlmaLinux 8).

Additional tests I did was running on different hardware and RHEL 7, very different setup in OS in general, little bit older Docker Engine version, then it performed same as with my test in CentOS 7.

This is the reason I thinking about the kernel version differences and what system calls that the software uses which cause these 2 minutes delays after you pass around 50 tests.

Since containers are in user space but uses kernel space from the VM some configuration in the VM OS will not matter.

You may be surprised to find out that, this is not 100% true with docker.
Containers needs elevated privileges.
With podman, you may be able to run them rootless.
But those are details.
Aside of that, Alma is not Centos, it is a fork of it.
To make a fair compair between kernel generation, and yet again I have to mention a plethora of other tools making an OS (even docker version can make a huge difference), a better starting point will be to test Centos7 vs Centos8
Or various Ubuntu generations (i think 16. 04 it still avaliable as a minimum, beying LTS and you can go up to 22.04)

That is true that it is not 100%.

And yes, “Alma is not Centos”. Right now CentOS 8 Stream only exists and not the same as CentOS 7 Linux which is quite different because CentOS 7 Linux was a downstream project to RHEL while CentOS 8 Stream is an upstream development branch to RHEL. Bugs might be lurking there so to speak.

Ensuring Docker versions are the same would not be a problem but right now the smaller difference in Docker versions between the different OSes I so far tested on does not matter looking at the test result.

@anon46315158 If it would be that the testing results would show the same difference when testing this on RHEL 7 and RHEL 8, what would be your suggestion to do at that point then?

First, let’s see the results, after that we dig more.
Another thing to consider is the hypervisor, but more on that later.
Up to now, the only constants you have are, the host OS (therefore the hypervisor) and the VM’s allocation.
But the host OS kernel may perform better or worse with various kernels installed in guest OS’s.
And top of that we add containerization drivers, alongside various other guest OS characteristics.

So… start to test and collect more data, like:

  • host OS and host hardware capabilities
  • virtualization platform used (vbox,vmware etc)
  • kernel, init systems, docker engine etc for te guest OS
  • how do you measure the performance…
    and so on

This is also partly true.
Centos8 ISO images are still available for download.
The ‘stream’ in the name it may be misleading at this point.
It only means the update process is changed to the rolling stream model.
But Centos8 as it is is still available, until 2024 i think, when will be also EOL’ed so no further ‘Centos9’ will exist, but just the stream variant.
RHEL7 and RHEL8 are also a good base.
Basically, RHEL is the enterprise frozen in time version from Centos, and for desktop use are just Fedora snapshots (Fedora being the comunity upstream for both of those).

Alma, RockyLinux etc are just forks of Centos model, because some people (me inculded) consider that the LTS model is more appropiate for enterpise use, the pure rolling model may lead to unexpected situations.
However, they bring some changes into the building process, patches applied and so on.

On the other side, you can also consider using Ubuntu as guestOS’es, you have some playground there and they still keep the LTS model.

To be noticed, as far as I know, the development (and poor testing) for Katalon Linux currently happens only on Ubuntu environments … so from the development team point of view, RHEL family and anything else is viewed as ‘experimental’

Thank you for engaging in this conversation! Related to OS choice I do not have that option to choose really what to run on since I work in an organization which is using RHEL or RHEL based OSes. :slight_smile: So when it comes to testing I can only do that on those. But thanks also for letting me know that what you know Katalon mainly runs on Ubuntu environment and that is good to know.

Related to the findings I have seen I cannot disclose some information there due to company policies and need to extract different parts to show what I’ve seen in regards to execution times and will extract some data collected in Cucumber reports to show you that suddenly after 50 test case a setup phase where WebUI.openBrowser is called takes over 2 minutes compared to around 2 seconds etc. If you look back in this thread about the logs published in a post I see that exact same behavior where last line you see is “INFO: Detected dialect: W3C” before it “hangs” for 2 minutes until the DriverFactory in Katalon prints the sessionId. I have looked through some code on Github related to the Katalon to try to backtrace where it might be spending that time but I have too little knowledge around the combination of Katalon, Selenium and ChromDriver etc.

Well, yeah, I understand such.
So, please collect and filter the data and share as much as you can.
On the other side, I don’t see a direct connection for your problem with the issue in the originating topic, which is marked as solved.

So, perhaps, better rise a new topic for this specific matter and we will continue there.

Here I will show you why I think it is the same issue becasue if you compare my log and the log in this post then you will see same behavior. Also this starts to happen in my case after around 50 openBrowser calls seen in the log.

2023-06-03 22:19:59.151 DEBUG testcase.Teardown data                   - 1: sendRequestAndVerify(findTestObject("Teardown/Teardown"))
2023-06-03 22:19:59.300 DEBUG testcase.Teardown                        - 1: request = getInstance().getCurrentRequest()
2023-06-03 22:19:59.301 DEBUG testcase.Teardown                        - 2: response = getInstance().getCurrentResponse()
2023-06-03 22:19:59.301 DEBUG testcase.Teardown                        - 3: verifyResponseStatusCode(response, 200)
2023-06-03 22:19:59.303 DEBUG testcase.Teardown data                   - 2: closeBrowser()
2023-06-03 22:19:59.379 DEBUG c.runtime.formatter.CucumberReporter     - ✓ Data cleaned
2023-06-03 22:19:59.380 DEBUG c.runtime.formatter.CucumberReporter     - STEP Start enviroment
2023-06-03 22:19:59.438 DEBUG testcase.Start                           - 1: openBrowser(URL)
Jun 03, 2023 10:19:59 PM org.openqa.selenium.remote.DesiredCapabilities chrome
INFO: Using `new ChromeOptions()` is preferred to `DesiredCapabilities.chrome()`
Starting ChromeDriver 108.0.5359.71 (###REDACTED###@{#1016}) on port 4872
Only local connections are allowed.
Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
[1685823599.456][SEVERE]: bind() failed: Cannot assign requested address (99)
ChromeDriver was started successfully.
Jun 03, 2023 10:19:59 PM org.openqa.selenium.remote.ProtocolHandshake createSession
INFO: Detected dialect: W3C

--------------------------------------------------------------------------------
###REDACTED### - Chrome (headless) - 20230603_221502....3/6(50%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
###REDACTED### - Chrome (headless) - 20230603_221502....3/6(50%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
###REDACTED### - Chrome (headless) - 20230603_221502....3/6(50%)
--------------------------------------------------------------------------------

--------------------------------------------------------------------------------
###REDACTED### - Chrome (headless) - 20230603_221502....3/6(50%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
###REDACTED### - Chrome (headless) - 20230603_221502....3/6(50%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
###REDACTED### - Chrome (headless) - 20230603_221502....3/6(50%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
###REDACTED### - Chrome (headless) - 20230603_221502....3/6(50%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
###REDACTED### - Chrome (headless) - 20230603_221502....3/6(50%)
--------------------------------------------------------------------------------


--------------------------------------------------------------------------------
###REDACTED### - Chrome (headless) - 20230603_221502....3/6(50%)
--------------------------------------------------------------------------------

2023-06-03 22:22:12.520 DEBUG testcase.Start                           - 2: setViewPortSize(1440, 900)
2023-06-03 22:22:12.631 DEBUG c.runtime.formatter.CucumberReporter     - ✓ Start enviroment

I also attach snippets from the cucumber report where it is visible the times are increased becasue of this additional 2 minute “wait” after around 50 openBrowser calls.

CentOS 7:
time_summary_centos7

AlmaLinux 8/9:
time_summary_almalinux

Did not manage to get the suggested solution to use a different DriverFactory to compile correctly so I will need to try that again to see if that resolves the issue, just feels it something other than the DriverFactory that is the root cause.