SQL Log
For ORM, it is important to print generated SQL in logs.
Enable SQL Log
There are two ways to enable SQL logs:
-
When using Spring Boot Starter, there are two ways to configure:
-
Modify
application.yml
(or application.properties)jimmer:
show-sql: true -
Configure global Bean
- Java
- Kotlin
@Bean
public Executor executor() {
return Executor.log();
}@Bean
fun executor(): Executor =
Executor.log()infoIf both methods above are used (not recommended), the second method takes precedence.
-
-
Use underlying API
- Java
- Kotlin
JSqlClient sqlClient = JSqlClient
.newBuilder()
.setExecutor(Executor.log())
...Omit other configurations...
.build();val sqlClient = newKSqlClient {
setExecutor(Executor.log())
...Omit other configurations...
}
The actual printed logs are as follows:
jimmer> sql: select tb_1_.ID, tb_1_.CREATED_TIME, tb_1_.MODIFIED_TIME, tb_1_.NAME, tb_1_.EDITION, tb_1_.PRICE, tb_1_.STORE_ID from BOOK tb_1_ where lower(tb_1_.NAME) like ? order by tb_1_.NAME asc, tb_1_.EDITION desc limit ?, ?, variables: [%graphql%, 0, 10], purpose: QUERY
If only the SQL log is turned on, the above log will not wrap.
The log has three parts:
-
sql
: The SQL statement being executed -
variables
: The JDBC parameters associated withsql
, which is an array whose length is the same as the number of "?" characters insql
. -
purpose
: The reason why the SQL is executed, which is an enum with the following values:-
QUERY
: Query directly executed by developers -
UPDATE
: Operations performed by developers via update statements -
DELETE
: Operations performed by developers via delete statements -
LOAD
: Query executed automatically by Jimmer to get the value of associated properties or calculated properties in object fetcher. -
EXPORT
: The user initiates a query to other microservices, and its object fetcher contains remote associations pointing to the current service. Jimmer automatically exposes the data of this service. -
MUTATE
: Operations specified by developers via save commands -
EVICT
: In some cases, the cache that should be cleared cannot be determined solely based on the event information of Jimmer triggers. Jimmer will automatically execute some queries to accurately determine which caches should be cleared.
-
Pretty SQL
In the previous example, the SQL log is printed in one line, which is poorly readable.
Therefore, the SQL needs to be formatted. There are two implementation methods:
-
When using Spring Boot Starter
Modify
application.yml
(or application.properties)jimmer:
show-sql: true
pretty-sql: true -
When using underlying API
- Java
- Kotlin
JSqlClient sqlClient = JSqlClient
.newBuilder()
.setExecutor(Executor.log())
.setSqlFormatter(SqlFormatter.PRETTY)
...Omit other configurations...
.build();val sqlClient = newKSqlClient {
setExecutor(Executor.log())
setSqlFormatter(SqlFormatter.PRETTY)
...Omit other configurations...
}
The log output is as follows:
Execute SQL===>
Purpose: QUERY
SQL: select
tb_1_.ID,
tb_1_.CREATED_TIME,
tb_1_.MODIFIED_TIME,
tb_1_.NAME,
tb_1_.EDITION,
tb_1_.PRICE,
tb_1_.STORE_ID
from BOOK tb_1_
where
lower(tb_1_.NAME) like ? /* %graphql% */ ❶
order by
tb_1_.NAME asc,
tb_1_.EDITION desc
limit ? /* 0 */ ❷, ? /* 10 */ ❸
JDBC response status: success
Time cost: 8ms
<===Execute SQL
In this mode:
-
The SQL statement will be automatically formatted, automatically wrapped, and automatically indented.
-
❶ ❷ ❸ Unlike the previous example, all JDBC parameters are not printed together, but injected into the original SQL as comments.
-
Other information will be printed, such as whether SQL execution is successful, total execution time of SQL. For insert, update, delete operations, the number of affected rows will also be printed.
Inline SQL Parameters
In the previous examples, the JDBC parameters in the SQL logs were inserted after the JDBC parameter placeholders ?
as comment, e.g. ? /* %graphql% */
.
Perhaps you want the parameters to be inlined into the SQL statement directly, making it look as if no JDBC parameters were used. This way, the SQL statement in the logs can be copied directly into a SQL IDE to execute.
There are two ways to achieve this
-
Using Spring Boot Starter:
Modify
application.yml
(or application.properties):jimmer:
show-sql: true
pretty-sql: true
inline-sql-variables: true -
Using low-level API
- Java
- Kotlin
JSqlClient sqlClient = JSqlClient
.newBuilder()
.setExecutor(Executor.log())
.setSqlFormatter(SqlFormatter.INLINE_PRETTY)
...other configs omitted...
.build();val sqlClient = newKSqlClient {
setExecutor(Executor.log())
setSqlFormatter(SqlFormatter.INLINE_PRETTY)
...other configs omitted...
}
The log output is as follows:
Execute SQL===>
Purpose: QUERY
SQL: select
tb_1_.ID,
tb_1_.CREATED_TIME,
tb_1_.MODIFIED_TIME,
tb_1_.NAME,
tb_1_.EDITION,
tb_1_.PRICE,
tb_1_.STORE_ID
from BOOK tb_1_
where
lower(tb_1_.NAME) like '%graphql%' ❶
order by
tb_1_.NAME asc,
tb_1_.EDITION desc
limit 0 ❷, 10 ❸
JDBC response status: success
Time cost: 8ms
<===Execute SQL
In this mode, we can see the parameters at ❶ ❷ ❸ are directly inlined.
This only affects the logs. The actual SQL executed still uses JDBC parameters.
Embed Stack Trace
In addition to coding, developers often need to troubleshoot issues. Whether it is a functional error or a performance issue, the developer needs to investigate it.
If the SQL log only prints JDBC information centered on SQL, the user cannot associate the SQL log with the application code, which is not conducive to users troubleshooting.
Jimmer provides a configuration option that if specified, before executing SQL, it will check the stack trace information of the current thread.
However, these stack traces contain too much information, including infrastructure call frames represented by jdk, jdbc driver, jimmer and spring, while the business-related information that developers care about will be overwhelmed in the ocean of information.
This configuration type is java.util.Collection<String>
allowing developers to specify multiple packages or class prefixes. Jimmer will use them to filter the stack trace information. If a call frame can pass the filter, Jimmer will consider it related to user business and include it in the callback parameter before execution.
For SQL log printing, call frames that can pass the filter will appear in the print output to help users troubleshoot issues.
There are two implementation methods:
-
When using Spring Boot Starter
Modify
application.yml
(or application.properties)jimmer:
show-sql: true
pretty-sql: true
executor-context-prefixes:
- com.example.business -
When using underlying API
- Java
- Kotlin
JSqlClient sqlClient = JSqlClient
.newBuilder()
.setExecutor(Executor.log())
.setSqlFormatter(SqlFormatter.PRETTY)
.setExecutorContextPrefixes(
Collections.singleton(
"com.example.business"
)
)
...Omit other configurations...
.build();val sqlClient = newKSqlClient {
setExecutor(Executor.log())
setSqlFormatter(SqlFormatter.PRETTY)
setExecutorContextPrefixes(
listOf(
"com.example.business"
)
)
...Omit other configurations...
}
The log output is as follows:
Execute SQL===>
--- Business related stack trace information --- ❶
com.example.business.BookService.findBooks(BookService.java:55) ❷
Purpose: QUERY
SQL: select
tb_1_.ID,
tb_1_.CREATED_TIME,
tb_1_.MODIFIED_TIME,
tb_1_.NAME,
tb_1_.EDITION,
tb_1_.PRICE,
tb_1_.STORE_ID
from BOOK tb_1_
where
lower(tb_1_.NAME) like ? /* %graphql% */
order by
tb_1_.NAME asc,
tb_1_.EDITION desc
limit ? /* 0 */, ? /* 10 */
JDBC response status: success
Time cost: 9ms
<===Execute SQL
At ❶ and ❷, the stack trace information of the thread executing the SQL operation is printed.
However, a large amount of stack trace information is not blindly printed, only what users care about is printed.