24 use Psr\Log\LoggerAwareInterface;
25 use Psr\Log\LoggerInterface;
26 use Psr\Log\NullLogger;
95 $this->dbTrxHoldingLocks = [];
96 $this->dbTrxMethodTimes = [];
98 $this->silenced =
false;
114 $this->silenced = $value;
130 if ( !isset( $this->expect[$event] ) ) {
134 if ( $limit <= $this->expect[$event][self::FLD_LIMIT] ) {
136 $this->expect[$event] = [
137 self::FLD_LIMIT => $limit,
138 self::FLD_FNAME => $fname
155 foreach ( $expects as $event => $value ) {
202 "[connect to $server ($db)]",
211 "[connect to $server ($db)]",
212 $this->hits[
'masterConns']
227 $name =
"{$server} ({$db}) (TRX#$id)";
228 if ( isset( $this->dbTrxHoldingLocks[$name] ) ) {
229 $this->logger->warning(
"Nested transaction for '$name' - out of sync." );
231 $this->dbTrxHoldingLocks[$name] = [
232 'start' => microtime(
true ),
235 $this->dbTrxMethodTimes[$name] = [];
237 foreach ( $this->dbTrxHoldingLocks as $name => &$info ) {
239 $info[
'conns'][$name] = 1;
254 $eTime = microtime(
true );
255 $elapsed = ( $eTime - $sTime );
259 } elseif ( !$isWrite && $this->
isAboveThreshold( $rowCount,
'readQueryRows' ) ) {
278 if ( !$this->dbTrxHoldingLocks ) {
281 } elseif ( !$isWrite && $elapsed < self::EVENT_THRESHOLD_SEC ) {
286 foreach ( $this->dbTrxHoldingLocks as $name => $info ) {
287 $lastQuery = end( $this->dbTrxMethodTimes[$name] );
290 $lastEnd = $lastQuery[2];
291 if ( $sTime >= $lastEnd ) {
292 if ( ( $sTime - $lastEnd ) > self::EVENT_THRESHOLD_SEC ) {
294 $this->dbTrxMethodTimes[$name][] = [
'...delay...', $lastEnd, $sTime ];
296 $this->dbTrxMethodTimes[$name][] = [ $query, $sTime, $eTime ];
300 if ( $sTime >= $info[
'start'] ) {
301 $this->dbTrxMethodTimes[$name][] = [ $query, $sTime, $eTime ];
327 $name =
"{$server} ({$db}) (TRX#$id)";
328 if ( !isset( $this->dbTrxMethodTimes[$name] ) ) {
329 $this->logger->warning(
"Detected no transaction for '$name' - out of sync." );
339 "[transaction $id writes to {$server} ({$db})]",
348 "[transaction $id writes to {$server} ({$db})]",
353 $lastQuery = end( $this->dbTrxMethodTimes[$name] );
355 $now = microtime(
true );
356 $lastEnd = $lastQuery[2];
357 if ( ( $now - $lastEnd ) > self::EVENT_THRESHOLD_SEC ) {
358 $this->dbTrxMethodTimes[$name][] = [
'...delay...', $lastEnd, $now ];
362 foreach ( $this->dbTrxMethodTimes[$name] as $info ) {
363 $elapsed = ( $info[2] - $info[1] );
364 if ( $elapsed >= self::DB_LOCK_THRESHOLD_SEC ) {
371 foreach ( $this->dbTrxMethodTimes[$name] as $i => [ $query, $sTime, $end ] ) {
373 "%d\t%.6f\t%s\n", $i, ( $end - $sTime ), self::queryString( $query ) );
375 $this->logger->warning(
"Sub-optimal transaction on DB(s) [{dbs}]: \n{trace}", [
376 'dbs' => implode(
', ', array_keys( $this->dbTrxHoldingLocks[$name][
'conns'] ) ),
380 unset( $this->dbTrxHoldingLocks[$name] );
381 unset( $this->dbTrxMethodTimes[$name] );
385 $this->expect = array_fill_keys(
387 [ self::FLD_LIMIT => INF, self::FLD_FNAME =>
null ]
390 $this->hits = array_fill_keys( self::COUNTER_EVENT_NAMES, 0 );
399 return ( $value > $this->expect[$expectation][self::FLD_LIMIT] );
407 $newValue = ++$this->hits[$expectation];
409 return ( $newValue > $this->expect[$expectation][self::FLD_LIMIT] );
418 if ( $this->silenced ) {
422 $this->logger->warning(
423 "Expectation ({measure} <= {max}) by {by} not met (actual: {actual}):\n{query}\n",
425 'measure' => $expectation,
426 'max' => $this->expect[$expectation][self::FLD_LIMIT],
427 'by' => $this->expect[$expectation][self::FLD_FNAME],
429 'query' => self::queryString( $query ),
430 'exception' =>
new RuntimeException()