[
https://issues.apache.org/jira/browse/CAY-2912?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Andrus Adamchik updated CAY-2912:
---------------------------------
Fix Version/s: 5.0-M3
(was: 5.0-M2)
> Compact SQL logger
> ------------------
>
> Key: CAY-2912
> URL: https://issues.apache.org/jira/browse/CAY-2912
> Project: Cayenne
> Issue Type: Improvement
> Reporter: Andrus Adamchik
> Assignee: Andrus Adamchik
> Priority: Major
> Fix For: 5.0-M3
>
>
> Our good old JdbcEventLogger provides a bunch of good information about each
> query, but is also very verbose and splits each query into multiple log
> lines. This leads to problems at scale - very large log files and the need to
> locate and aggregate multiple lines for a unified view. Let's switch to a
> more terse version of the logger, with a user-configurable option to make it
> more verbose or less verbose (less by default).
> h2. SELECT
> h3. Current
> {noformat}
> INFO o.a.c.l.JdbcEventLogger --- transaction started.
> INFO o.a.c.l.JdbcEventLogger SELECT t0.id FROM my_table t0 WHERE t0.user_id =
> ? [bind: 1->user_id:15]
> INFO o.a.c.l.JdbcEventLogger === returned 1 row. - took 1 ms.
> INFO o.a.c.l.JdbcEventLogger +++ transaction committed.
> {noformat}
> h3. New default
> Single line, no query timer, no tx boundaries, terse params
> {noformat}
> INFO cayenne-sql SELECT t0.id FROM my_table t0 WHERE t0.user_id = ?
> bind:[user_id:15] selected:1
> {noformat}
> h3. New default with DEBUG on
> Same as default, but adds tx boundaries
> {noformat}
> DEBUG cayenne-sql tx started
> INFO cayenne-sql SELECT t0.id FROM my_table t0 WHERE t0.user_id = ?
> bind:[user_id:15] selected:1
> DEBUG cayenne-sql tx committed{noformat}
> h2. UPDATE
> h3. Current
> {noformat}
> INFO o.a.c.l.JdbcEventLogger --- transaction started.
> INFO o.a.c.l.JdbcEventLogger INSERT INTO table1(id, name) VALUES(?, ?)
> INFO o.a.c.l.JdbcEventLogger [batch bind: 1->id:3, 2->name:'n3']
> INFO o.a.c.l.JdbcEventLogger [batch bind: 1->id:1, 2->name:'n1']
> INFO o.a.c.l.JdbcEventLogger [batch bind: 1->id:5, 2->name:'n5']
> INFO o.a.c.l.JdbcEventLogger [batch bind: 1->id:4, 2->name:'n4']
> INFO o.a.c.l.JdbcEventLogger [batch bind: 1->id:2, 2->name:'n2']
> INFO o.a.c.l.JdbcEventLogger === updated 5 rows.
> INFO o.a.c.l.JdbcEventLogger +++ transaction committed.
> {noformat}
> h3. New default
> Single line, no query timer, no tx boundaries, terse params, truncate long
> batches. Batch param trucation will be controlled by a config setting
> {noformat}
> INFO cayenne-sql INSERT INTO table1(id, name) VALUES(?, ?) bind:[[id:3
> name:'n3']..3..[id:2 name:'n2']] updated:5
> {noformat}
> h3. New default with DEBUG on
> Same as default, but adds tx boundaries
> {noformat}
> DEBUG cayenne-sql tx started
> INFO cayenne-sql INSERT INTO table1(id, name) VALUES(?, ?) bind:[[id:3
> name:'n3']..3..[id:2 name:'n2']] updated:5
> DEBUG cayenne-sql tx committed{noformat}
> h2. MIXED
> A mix of select and update operations is a tricky one. I guess we keep it
> multi-line, replacing the query and the bindings with "also ... "
> {noformat}
> INFO cayenne-sql call my_proc(?, ?) bind:[[id:3 name:'n3']..3..[id:2
> name:'n2']] selected:5
> INFO cayenne-sql also updated:10
> INFO cayenne-sql also updated:20
> INFO cayenne-sql also updated:30
> {noformat}
> h2. Legacy "Compact" Logger
> _Note that we do have a "compact" logger implemented per CAY-2485 that_
> * _parses every piece of SQL on every query. For a typical query it does 1
> Pattern.match(..), 1 toUpperCase(), 2 "indexOf(..)" and 1 "split"!! This is
> gotta be slow. A logger shouldn't be doing that_
> * _generates output like "SELECT (60 columns) FROM ..."_ _so hiding the
> interesting parts of the query_
> * _still displays multi-line logs_
> * _Parameters logging is still sparse_
> * _TX boundaries are not logged under any circumstances_
> _So I am trying to rethink the approach into something more compact by
> default, but also more performant and configurable._
> h2. Operation Observability Stack Changes
> We may use this opportunity to rethink how logger callbacks are invoked.
> Instead of logger being called directly from within Transaction and DataNode,
> we may try to pass it from DataDomain via a combination of
> TransactionListener and OperationObserver. Both will require slight API
> extension.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
