27 use Psr\Log\LoggerInterface;
28 use Psr\Log\LoggerAwareInterface;
29 use Psr\Log\NullLogger;
66 'readQueryTime' => INF,
67 'writeQueryTime' => INF
108 $this->expect[$event] = isset( $this->expect[$event] )
109 ? min( $this->expect[$event],
$value )
111 if ( $this->expect[$event] ==
$value ) {
112 $this->expectBy[$event] =
$fname;
126 foreach ( $expects
as $event =>
$value ) {
137 foreach ( $this->hits
as &$val ) {
141 foreach ( $this->expect
as &$val ) {
145 $this->expectBy = [];
159 if ( $this->hits[
'conns']++ == $this->expect[
'conns'] ) {
162 if ( $isMaster && $this->hits[
'masterConns']++ == $this->expect[
'masterConns'] ) {
177 $name =
"{$server} ({$db}) (TRX#$id)";
178 if ( isset( $this->dbTrxHoldingLocks[
$name] ) ) {
179 $this->logger->info(
"Nested transaction for '$name' - out of sync." );
181 $this->dbTrxHoldingLocks[
$name] = [
182 'start' => microtime(
true ),
185 $this->dbTrxMethodTimes[
$name] = [];
187 foreach ( $this->dbTrxHoldingLocks
as $name => &$info ) {
189 $info[
'conns'][
$name] = 1;
204 $eTime = microtime(
true );
205 $elapsed = ( $eTime - $sTime );
207 if ( $isWrite && $n > $this->expect[
'maxAffected'] ) {
209 "Query affected $n row(s):\n" .
$query .
"\n" .
210 (
new RuntimeException() )->getTraceAsString() );
214 if ( $this->hits[
'queries']++ == $this->expect[
'queries'] ) {
217 if ( $isWrite && $this->hits[
'writes']++ == $this->expect[
'writes'] ) {
221 if ( !$isWrite && $elapsed > $this->expect[
'readQueryTime'] ) {
224 if ( $isWrite && $elapsed > $this->expect[
'writeQueryTime'] ) {
228 if ( !$this->dbTrxHoldingLocks ) {
231 } elseif ( !$isWrite && $elapsed < $this->eventThreshold ) {
236 foreach ( $this->dbTrxHoldingLocks
as $name => $info ) {
237 $lastQuery = end( $this->dbTrxMethodTimes[
$name] );
240 $lastEnd = $lastQuery[2];
241 if ( $sTime >= $lastEnd ) {
242 if ( ( $sTime - $lastEnd ) > $this->eventThreshold ) {
244 $this->dbTrxMethodTimes[
$name][] = [
'...delay...', $lastEnd, $sTime ];
246 $this->dbTrxMethodTimes[
$name][] = [
$query, $sTime, $eTime ];
250 if ( $sTime >= $info[
'start'] ) {
251 $this->dbTrxMethodTimes[
$name][] = [
$query, $sTime, $eTime ];
270 $name =
"{$server} ({$db}) (TRX#$id)";
271 if ( !isset( $this->dbTrxMethodTimes[
$name] ) ) {
272 $this->logger->info(
"Detected no transaction for '$name' - out of sync." );
279 if ( $writeTime > $this->expect[
'writeQueryTime'] ) {
282 "[transaction $id writes to {$server} ({$db})]",
288 $lastQuery = end( $this->dbTrxMethodTimes[
$name] );
290 $now = microtime(
true );
291 $lastEnd = $lastQuery[2];
292 if ( ( $now - $lastEnd ) > $this->eventThreshold ) {
293 $this->dbTrxMethodTimes[
$name][] = [
'...delay...', $lastEnd, $now ];
297 foreach ( $this->dbTrxMethodTimes[
$name]
as $info ) {
298 $elapsed = ( $info[2] - $info[1] );
299 if ( $elapsed >= $this->dbLockThreshold ) {
306 foreach ( $this->dbTrxMethodTimes[
$name]
as $i => $info ) {
308 $trace .= sprintf(
"%d\t%.6f\t%s\n", $i, ( $end - $sTime ),
$query );
310 $this->logger->info(
"Sub-optimal transaction on DB(s) [{dbs}]: \n{trace}", [
311 'dbs' => implode(
', ', array_keys( $this->dbTrxHoldingLocks[
$name][
'conns'] ) ),
315 unset( $this->dbTrxHoldingLocks[
$name] );
316 unset( $this->dbTrxMethodTimes[
$name] );
325 if ( $this->silenced ) {
330 $by = $this->expectBy[
$expect];
331 $actual = ( $actual !== null ) ?
" (actual: $actual)" :
"";
334 "Expectation ($expect <= $n) by $by not met$actual:\n$query\n" .
335 (
new RuntimeException() )->getTraceAsString()