Denis Chudov created IGNITE-12070:
-------------------------------------
Summary: Document the new ability to track system/user time of
transactions
Key: IGNITE-12070
URL: https://issues.apache.org/jira/browse/IGNITE-12070
Project: Ignite
Issue Type: Task
Components: documentation
Reporter: Denis Chudov
Now there is ability to track system/user time of transactions. System time is
the time that is spent for system activities - i.e. time while aquiring locks,
preparing, commiting, etc.User time is the time that is spent for user
activities when client node runs some code while holding transaction.
We have ability to log info about transactions that exceed some threshold
execution timeout, or some percentage of all transactions. Log record in case
of long-running transactions looks like following:
{code:java}
[2019-08-09 13:39:49,130][WARN ][sys-stripe-1-#101%client%][root] Long
transaction time dump [startTime=13:39:47.970, totalTime=1160, systemTime=157,
userTime=1003, cacheOperationsTime=141, prepareTime=15, commitTime=0,
tx=GridNearTxLocal [...]]
{code}
In case of sampling of all transactions:
{code:java}
[2019-08-09 13:39:54,079][INFO ][sys-stripe-2-#102%client%][root] Transaction
time dump [startTime=13:39:54.063, totalTime=15, systemTime=6, userTime=9,
cacheOperationsTime=2, prepareTime=3, commitTime=0, tx=GridNearTxLocal [...]]
{code}
Also some of transactions can be skipped to not overflow the log, information
about this log throttling looks like this:
{code:java}
[2019-08-09 13:39:55,109][INFO ][sys-stripe-0-#100%client%][root] Transaction
time dumps skipped because of log throttling: 2
{code}
There are JMX parameters and JVM options to control this behavior:
1)
JVM option: IGNITE_LONG_TRANSACTION_TIME_DUMP_THRESHOLD
JMX parameter: TransactionsMXBean.longTransactionTimeDumpThreshold
Threshold timeout in milliseconds for long transactions, if transaction exceeds
it, it will be dumped in log with information about how much time did it spent
in system time and user time. Default value is 0. No info about system/user
time of long transactions is dumped in log if this parameter is not set.
2)
JVM option: IGNITE_TRANSACTION_TIME_DUMP_SAMPLES_COEFFICIENT
JMX parameter: TransactionsMXBean.transactionTimeDumpSamplesCoefficient
The coefficient for samples of completed transactions that will be dumped in
log. Must be float value between 0.0 and 1.0 inclusive. Default value is 0.0.
3)
JVM option: IGNITE_TRANSACTION_TIME_DUMP_SAMPLES_PER_SECOND_LIMIT
JMX parameter: TransactionsMXBean.transactionTimeDumpSamplesPerSecondLimit
The limit of samples of completed transactions that will be dumped in log per
second, if IGNITE_TRANSACTION_TIME_DUMP_SAMPLES_COEFFICIENT is above 0.0. Must
be integer value greater than 0. Default value is 5.
For the existing long running transaction warning was added information about
current system and user time of transaction:
{code:java}
[2019-08-09 14:10:31,835][WARN ][grid-timeout-worker-#122%client%][root] First
10 long running transactions [total=1]
[2019-08-09 14:10:31,835][WARN ][grid-timeout-worker-#122%client%][root] >>>
Transaction [startTime=14:10:31.170, curTime=14:10:31.750, systemTime=32,
userTime=548, tx=GridNearTxLocal [...]]
{code}
Also added following metrics to monitor system and user time for single node:
diagnostic.transactions.totalNodeSystemTime - Total transactions system time on
node.
diagnostic.transactions.totalNodeUserTime - Total transactions user time on
node.
diagnostic.transactions.nodeSystemTimeHistogram - Transactions system times on
node represented as histogram.
diagnostic.transactions.nodeUserTimeHistogram - Transactions user times on node
represented as histogram.
--
This message was sent by Atlassian JIRA
(v7.6.14#76016)
