Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Read classes takes up to minutes each time #2516

Open
alisevych opened this issue Aug 15, 2023 · 5 comments · Fixed by #2546
Open

Read classes takes up to minutes each time #2516

alisevych opened this issue Aug 15, 2023 · 5 comments · Fixed by #2546
Assignees
Labels
ctg-bug Issue is a bug spec-performance Performance-related issue

Comments

@alisevych
Copy link
Member

Description

Even for a simple project with 5 classes, read classes phase take up to 10 seconds each time.

To Reproduce

  1. Install UnitTestBot plugin built from main in IntelliJ IDEA - this one was used
  2. Open UTBotJava project
  3. Generate tests for ArrayQuickSort
  4. Check how long Generate tests: read classes is displayed in progress bar

Expected behavior

It is expected that 5-10 simplest classes will be read in 0.5-1 seconds.

Actual behavior

Generate tests: read classes is displayed for 6 seconds each time.

Screenshots, logs

image

Environment

IntelliJ IDEA version - Ultimate 2023.2
Project - Gradle
JDK - 17
OS - Windows 10 Pro
CPU - 13% usage
Memory - 70%

Additional context

In TwoAnimals Spring-based project - for 1 class - it takes 10 seconds each time.

@alisevych alisevych added ctg-bug Issue is a bug spec-performance Performance-related issue labels Aug 15, 2023
@alisevych alisevych added this to the Spring Phase 4 milestone Aug 15, 2023
@EgorkaKulikov
Copy link
Collaborator

@Vassiliy-Kudryashov please investigate. May be we have changed something in Soot loading recently, so scanning dependencies is now longer that before. Also I suggest to rename read classes to scanning dependencies.

@alisevych alisevych changed the title Read a couple of classes takes up to 10 seconds each time Read a couple of classes takes up to minutes each time Aug 21, 2023
@alisevych
Copy link
Member Author

@Vassiliy-Kudryashov Could you please check. With the latest updates on main it takes minutes sometimes.

@alisevych
Copy link
Member Author

Either "Generate tests: read classes" or "Initialization" now takes 25 seconds, up to minutes each time.
It's a performance regression issue.

Here is the comparison of test generation on the same project, same class (also checked in another project):
On July's build (2023.7.4725) - issue is present (25 sec)
On June's build (2023.6.4492) - issue is present (16 sec), a bit less critical
On May's build (2023.5.4440) - issue is present (16 sec)
On March release (2023.3) - issue is present (11 sec), there is no Spring support yet

@Markoutte Could you please check the reason and whether the generation pre-phase can be speed up?

@alisevych alisevych reopened this Aug 23, 2023
@github-project-automation github-project-automation bot moved this from Todo to In Progress in UTBot Java Aug 23, 2023
@Vassiliy-Kudryashov
Copy link
Member

Vassiliy-Kudryashov commented Aug 23, 2023

Well, confusing message was replaced with "Generate tests: starting engine", real investigation of time consumption should be provided later.
@Markoutte, please take look at that.

@alisevych alisevych changed the title Read a couple of classes takes up to minutes each time Read classes takes up to minutes each time Aug 23, 2023
@Markoutte
Copy link
Collaborator

Either "Generate tests: read classes" or "Initialization" now takes 25 seconds, up to minutes each time. It's a performance regression issue.

Here is the comparison of test generation on the same project, same class (also checked in another project): On July's build (2023.7.4725) - issue is present (25 sec) On June's build (2023.6.4492) - issue is present (16 sec), a bit less critical On May's build (2023.5.4440) - issue is present (16 sec) On March release (2023.3) - issue is present (11 sec), there is no Spring support yet

@Markoutte Could you please check the reason and whether the generation pre-phase can be speed up?

I profiled this part and generally the Soot initialization consumes all the time. Even for a small project it loads nearly 10K classes. You can see the results of profiling below. I found 2 major problems:

  1. There's a many isRegularFile checks inside the Soot, that are not as fast as it can be, but we cannot do anything with it.
  2. There're many communications using Rd from the for-loop when initializing Soot. I tried to fix it in this PR: Extract option values from forEach loop #2565

image

@alisevych alisevych removed this from the September Release milestone Sep 12, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
ctg-bug Issue is a bug spec-performance Performance-related issue
Projects
Status: In Progress
4 participants