Have configurable verbosity on none passing test

[kanedafromparis]

Description
Some Feedback on non-working test (for instance N+1 select) are very long.
It's useful but it could be drawing (overwhelming) sometime.
It also could fill the CI system

It could be nice have its verbosity configurable
Implementation ideas
(If you have any implementation ideas, they can go here.)
It would be great to works with -Dquickperf.hints=0

[FTarfasse]

Hello,

I'd like to give this a try.
@jeanbisutti, in terms of functionality would working withe the actual @JvmOption and a custom QuickPerfConfiguration (for global scope) be a solution to explore ?

Thanks,

Kind regards,
Fabrice

[jeanbisutti]

Hello Fabrice,

The main use case would be to limit what we printed on the console during the execution of a CI build. If one test fails, the developer could launch it from his computer with all the information that could help him to fix the issue.

Let's take an N+1 select example:

[PERF] You may think that <1> select statement was sent to the database
       But in fact <3>...

💣 You may have even more select statements with production data.
 Be careful with the cost of JDBC server roundtrips: https://blog.jooq.org/2017/12/18/the-cost-of-jdbc-server-roundtrips/

💡 Perhaps you are facing an N+1 select issue
	* With Hibernate, you may fix it by using JOIN FETCH
	                                       or LEFT JOIN FETCH
	                                       or FetchType.LAZY
	                                       or ...
	  Some examples: https://stackoverflow.com/questions/32453989/what-is-the-solution-for-the-n1-issue-in-jpa-and-hibernate";
	                 https://stackoverflow.com/questions/52850442/how-to-get-rid-of-n1-with-jpa-criteria-api-in-hibernate/52945771?stw=2#52945771
	                 https://thoughts-on-java.org/jpa-21-entity-graph-part-1-named-entity/

	* With Spring Data JPA, you may fix it by adding @EntityGraph(attributePaths = { "..." })
	  on repository method: https://docs.spring.io/spring-data/jpa/docs/current/reference/html/#jpa.entity-graph

[SQL EXECUTIONS]
	Time:0, Success:False, Type:Prepared, Batch:False, QuerySize:1, BatchSize:0, Query:["
    select
        player0_.id as id1_0_,
        player0_.first_name as first_na2_0_,
        player0_.last_name as last_nam3_0_,
        player0_.team_id as team_id4_0_ 
    from
        player player0_"], Params:[()]

	Time:0, Success:False, Type:Prepared, Batch:False, QuerySize:1, BatchSize:0, Query:["
    select
        team0_.id as id1_1_0_,
        team0_.name as name2_1_0_ 
    from
        team team0_ 
    where
        team0_.id=?"], Params:[(1)]

	Time:0, Success:False, Type:Prepared, Batch:False, QuerySize:1, BatchSize:0, Query:["
    select
        team0_.id as id1_1_0_,
        team0_.name as name2_1_0_ 
    from
        team team0_ 
    where
        team0_.id=?"], Params:[(2)]

We could only keep this part in the CI build

[PERF] You may think that <1> select statement was sent to the database
       But in fact <3>...

We could also provide a way not to display the JDBC batching suggestions (see HibernateSuggestion.BATCHING and SpringDataJpaSpringBootSuggestion.BATCHING).

With @ProfileJvm, we may provide a way to disable the display of JVM profiling data on the console ( see DisplayJvmProfilingValueVerifier class):

------------------------------------------------------------------------------
 ALLOCATION (estimations)     |   GARBAGE COLLECTION           |  THROWABLE
 Total       : 3,68 GiB       |   Total pause     : 1,264 s    |  Exception: 0
 Inside TLAB : 3,67 GiB       |   Longest GC pause: 206,519 ms |  Error    : 36
 Outside TLAB: 12,7 MiB       |   Young: 13                    |  Throwable: 36
 Allocation rate: 108.1 MiB/s |   Old  : 3                     |
------------------------------------------------------------------------------
 COMPILATION                  |   CODE CACHE
 Number : 157                 |   The number of full code cache events: 0
 Longest: 1,615 s             |   
------------------------------------------------------------------------------
 JVM
 Name     : OpenJDK 64-Bit Server VM
 Version  : OpenJDK 64-Bit Server VM (11.0.1+13) for windows-amd64 JRE (11.0.1+13), built on Oct  6 2018 13:18:13 by "mach5one" with MS VC++ 15.5 (VS2017)
 Arguments: -Xms6g -Xmx6g -XX:+FlightRecorder -XX:+UnlockDiagnosticVMOptions -XX:+DebugNonSafepoints -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=C:\Users\JEANBI~1\AppData\Local\Temp\QuickPerf-1155358826815951142\heap-dump.hprof -DquickPerfToExecInASpecificJvm=true -DquickPerfWorkingFolder=C:\Users\JEANBI~1\AppData\Local\Temp\QuickPerf-1155358826815951142
------------------------------------------------------------------------------
 HARDWARE
 Hardware threads: 8
 Cores           : 4
 Sockets         : 1
 CPU
		Brand: Intel(R) Core(TM) i7-8550U CPU @ 1.80GHz, Vendor: GenuineIntel
		Family: <unknown> (0x6), Model: <unknown> (0x8e), Stepping: 0xa
		Ext. family: 0x0, Ext. model: 0x8, Type: 0x0, Signature: 0x000806ea
		Features: ebx: 0x03100800, ecx: 0xfedaf387, edx: 0xbfebfbff
		Ext. features: eax: 0x00000000, ebx: 0x00000000, ecx: 0x00000121, edx: 0x2c100800
		Supports: On-Chip FPU, Virtual Mode Extensions, Debugging Extensions, Page Size Extensions, Time Stamp Counter, Model Specific Registers, Physical Address Extension, Machine Check Exceptions, CMPXCHG8B Instruction, On-Chip APIC, Fast System Call, Memory Type Range Registers, Page Global Enable, Machine Check Architecture, Conditional Mov Instruction, Page Attribute Table, 36-bit Page Size Extension, CLFLUSH Instruction, Debug Trace Store feature, ACPI registers in MSR space, Intel Architecture MMX Technology, Fast Float Point Save and Restore, Streaming SIMD extensions, Streaming SIMD extensions 2, Self-Snoop, Hyper Threading, Thermal Monitor, Streaming SIMD Extensions 3, PCLMULQDQ, 64-bit DS Area, Enhanced Intel SpeedStep technology, Thermal Monitor 2, Supplemental Streaming SIMD Extensions 3, Fused Multiply-Add, CMPXCHG16B, xTPR Update Control, Perfmon and Debug Capability, Process-context identifiers, Streaming SIMD extensions 4.1, Streaming SIMD extensions 4.2, MOVBE, Popcount instruction, AESNI, XSAVE, OSXSAVE, AVX, F16C, LAHF/SAHF instruction support, Advanced Bit Manipulations: LZCNT, SYSCALL/SYSRET, Execute Disable Bit, RDTSCP, Intel 64 Architecture, Invariant TSC
------------------------------------------------------------------------------

I prefer to configure independently, the quantity of information displayed on the console for SQL and JVM annotations.

Having said that, the user could limit the console display with -DlimitQuickPerfJvmInfoOnConsole=true and -DlimitQuickPerfSqlInfoOnConsole=true.

Implementation tips: see SystemProperties class.

@kanedafromparis (the creator of this issue) and @FTarfasse, I will be glad to have your opinions.

Kind regards,

Jean

[FTarfasse]

Hi Jean,

Thank you for the hints and insights.

I think the question would be to know if we base this feature on a boolean logic (display or no display) or can / should we have more nuances in terms of informations (nothing, something, everything) ?
Anyhow, I ll work on a flexible way to meet the actual idea of the feature. I ll get back to you (two) for adjustments and feedbacks.

Thanks,

Kind regards,
Fabrice

[jeanbisutti]

Hi Fabrice,

I think the question would be to know if we base this feature on a boolean logic (display or no display) or can / should we have more nuances in terms of informations (nothing, something, everything) ?

Perhaps. I just would like that the configuration stays simple to use and explicit.

Anyhow, I ll work on a flexible way to meet the actual idea of the feature. I ll get back to you (two) for adjustments and feedbacks.

It seems an excellent idea to discuss from a first implementation.

Thanks Fabrice.

Don't hesitate if you have any questions.

Kind regards,

Jean

[FTarfasse]

Hi Jean,

Here's the code based on today's discussion (thanks again for your time :) ).

Note that I have:

• refactored HasSameSelectTypesWithDiffParamValuesVerifier.java to allow custom reporting.
• did not push any test or test modifications (as already discussed),
• solely focused on the limitation of the SQL console message for this commit (nothing done on @ProfileJvm here).

As a reminder for our future selfves (especially me hum ...), local mvn clean install is mandatory before trying anything from the command line such as:

mvn -pl sql/sql-memory-test -Dtest=ExpectSelectTest -DfailIfNoTests=false -DlimitQuickPerfSqlInfoOnConsole=true test

Cheers,
Fabrice

[jeanbisutti]

Hi Fabrice,

You are welcome!

The modifications seem ok for me. Could you please rebase on master and after that create a PR? So, I could merge the changes.

Would you like to work on @ProfileJvm part? A SystemProperties value has to be added and, in DisplayJvmProfilingValueVerifier, I think that this type of code has to be added:

    @Override
    public PerfIssue verifyPerfIssue(ProfileJvm annotation, JfrEventsMeasure jfrEventsMeasure) {


        if(SystemProperties.SIMPLIFIED_JVM%_DISPLAY.evaluate()) {
            return PerfIssue.NONE;
        }

Kind regards,

Jean

[jeanbisutti]

Hi Fabrice,

I refactored the code.

SELECT suggestions are now gathered here.

Kind regards,

Jean

[FTarfasse]

Hi Jean,

Duly noted ! I am updating everything in my local branch based on your refactoring. I'll send a PR today hopefully.

Kind regards,
Fabrice

[FTarfasse]

Jean,

What kind of behavior should be expected from a disabled @ProfileJvm display ? Should we keep JFREventsLoader message ? This class handles this part of the message in the @ProfileJvm report system (it is the first part before the detailled part):

[QUICK PERF] JVM was profiled with Java Flight Recorder (JFR).
The recording file is available here: /tmp/QuickPerf-7253414720024934608/jvm-profiling.jfr
You can open it with Java Mission Control (JMC).
Where to find Java Mission Control? 👉 https://tinyurl.com/find-jmc

After spending some time on this and as the display of this annotation is not related to failing tests, I don't see a real use case where this behavior will really shine (from my understanding of course). Can you give me your take on this ?

Thanks,

Kind regards,
Fabrice

[jeanbisutti]

Fabrice,

Should we keep JFREventsLoader message ? This class handles this part of the message in the @ProfileJvm report system (it is the first part before the detailled part):

[QUICK PERF] JVM was profiled with Java Flight Recorder (JFR).
The recording file is available here: /tmp/QuickPerf-7253414720024934608/jvm-profiling.jfr
You can open it with Java Mission Control (JMC).
Where to find Java Mission Control? 👉 https://tinyurl.com/find-jmc

Yes.

I don't see a real use case where this behavior will really shine (from my understanding of course). Can you give me your take on this ?

With @ProfileJvm, JVM is profiled with JDK Flight Recorder (JFR). The console displays the path to the recording file. The user can open this file with JDK Mission Control, a graphical user interface to explore and analyze the JVM profiling. Other annotations, like @MeasureHeapAllocation or @DisplaySqlOfTestMethod Body, are not done to develop non-regression tests.

Kind regards,

Jean

[jeanbisutti]

Fixed with #101 7a5fed7

Thanks @kanedafromparis for the idea and @FTarfasse for the implementation!