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

Log slow result set fetching in code generator #8464

Closed
lukaseder opened this issue Mar 29, 2019 · 1 comment
Closed

Log slow result set fetching in code generator #8464

lukaseder opened this issue Mar 29, 2019 · 1 comment

Comments

@lukaseder
Copy link
Member

lukaseder commented Mar 29, 2019

In large schemas, loading check constraints can cause significant querying overhead (see also #8463). When debug logging a code generation run on a large Oracle schema, we've seen:

15:03:04,921 [DEBUG] Executing query          : select "ac"."OWNER", "ac"."TABLE_NAME", "ac"."CONSTRAINT_NAME", "ac"."SEARCH_CONDITION" from "SYS"."ALL_CONSTRAINTS" "ac" where ("ac"."CONSTRAINT_TYPE" = ? and "ac"."OWNER" in (?, ?, ?, ?))
15:03:29,559 [DEBUG] Fetched result           : +-----+----------+---------------+---------------------+
15:03:29,559 [DEBUG]                          : |OWNER|TABLE_NAME|CONSTRAINT_NAME|SEARCH_CONDITION     |
15:03:29,560 [DEBUG]                          : +-----+----------+---------------+---------------------+
15:03:29,560 [DEBUG]                          : |SYS  |TS$       |SYS_C0061      |CONTENTS$ IS NOT NULL|
15:03:29,560 [DEBUG]                          : |SYS  |TS$       |SYS_C0060      |ONLINE$ IS NOT NULL  |
15:03:29,561 [DEBUG]                          : |SYS  |UNDO$     |SYS_C0052      |NAME IS NOT NULL     |
15:03:29,561 [DEBUG]                          : |SYS  |SEG$      |SYS_C0043      |MAXEXTS IS NOT NULL  |
15:03:29,561 [DEBUG]                          : |SYS  |TS$       |SYS_C0069      |DFLEXTPCT IS NOT NULL|
15:03:29,562 [DEBUG]                          : +-----+----------+---------------+---------------------+
15:03:29,562 [DEBUG]                          : |...record(s) truncated...
15:03:29,562 [DEBUG] Fetched row(s)           : 14005

The time between the beginning and the end of result fetching has not been considered for a log message via org.jooq.meta.AbstractDatabase$1$SQLPerformanceWarning, so this kind of problem has gone undetected so far.

We should log this as well, so users can assess whether to possibly change their code generation configuration to prevent such large result sets.

This logging should be accompanied by a new configuration flag <logSlowResultsAfterSeconds/>. See #8465

@lukaseder
Copy link
Member Author

Fixed in jOOQ 3.12. Backport scheduled to 3.11.11 (#8466) and 3.10.9 (#8467)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

1 participant