24 use Psr\Log\LoggerAwareInterface;
25 use Psr\Log\LoggerInterface;
26 use Psr\Log\NullLogger;
28 use Wikimedia\ScopedCallback;
96 $this->dbTrxHoldingLocks = [];
97 $this->dbTrxMethodTimes = [];
99 $this->silenced =
false;
115 $this->silenced = $value;
126 return new ScopedCallback(
function () use ( $oldSilenced ) {
142 if ( !isset( $this->expect[$event] ) ) {
146 if ( $limit <= $this->expect[$event][self::FLD_LIMIT] ) {
148 $this->expect[$event] = [
149 self::FLD_LIMIT => $limit,
150 self::FLD_FNAME => $fname
167 foreach ( $expects as $event => $value ) {
214 "[connect to $server ($db)]",
223 "[connect to $server ($db)]",
224 $this->hits[
'masterConns']
239 $name =
"{$server} ({$db}) (TRX#$id)";
240 if ( isset( $this->dbTrxHoldingLocks[$name] ) ) {
241 $this->logger->warning(
"Nested transaction for '$name' - out of sync." );
243 $this->dbTrxHoldingLocks[$name] = [
244 'start' => microtime(
true ),
247 $this->dbTrxMethodTimes[$name] = [];
249 foreach ( $this->dbTrxHoldingLocks as $name => &$info ) {
251 $info[
'conns'][$name] = 1;
273 ?
string $serverName =
null
275 $eTime = microtime(
true );
276 $elapsed = ( $eTime - $sTime );
280 } elseif ( !$isWrite && $this->
isAboveThreshold( $rowCount,
'readQueryRows' ) ) {
299 if ( !$this->dbTrxHoldingLocks ) {
302 } elseif ( !$isWrite && $elapsed < self::EVENT_THRESHOLD_SEC ) {
307 foreach ( $this->dbTrxHoldingLocks as $name => $info ) {
308 $lastQuery = end( $this->dbTrxMethodTimes[$name] );
311 $lastEnd = $lastQuery[2];
312 if ( $sTime >= $lastEnd ) {
313 if ( ( $sTime - $lastEnd ) > self::EVENT_THRESHOLD_SEC ) {
315 $this->dbTrxMethodTimes[$name][] = [
'...delay...', $lastEnd, $sTime ];
317 $this->dbTrxMethodTimes[$name][] = [ $query, $sTime, $eTime ];
321 if ( $sTime >= $info[
'start'] ) {
322 $this->dbTrxMethodTimes[$name][] = [ $query, $sTime, $eTime ];
348 $name =
"{$server} ({$db}) (TRX#$id)";
349 if ( !isset( $this->dbTrxMethodTimes[$name] ) ) {
350 $this->logger->warning(
"Detected no transaction for '$name' - out of sync." );
360 "[transaction writes to {$server} ({$db})]",
370 "[transaction writes to {$server} ({$db})]",
376 $lastQuery = end( $this->dbTrxMethodTimes[$name] );
378 $now = microtime(
true );
379 $lastEnd = $lastQuery[2];
380 if ( ( $now - $lastEnd ) > self::EVENT_THRESHOLD_SEC ) {
381 $this->dbTrxMethodTimes[$name][] = [
'...delay...', $lastEnd, $now ];
385 foreach ( $this->dbTrxMethodTimes[$name] as $info ) {
386 $elapsed = ( $info[2] - $info[1] );
387 if ( $elapsed >= self::DB_LOCK_THRESHOLD_SEC ) {
394 foreach ( $this->dbTrxMethodTimes[$name] as $i => [ $query, $sTime, $end ] ) {
398 $this->logger->warning(
"Sub-optimal transaction on DB(s) [{dbs}]: \n{trace}", [
399 'dbs' => implode(
', ', array_keys( $this->dbTrxHoldingLocks[$name][
'conns'] ) ),
403 unset( $this->dbTrxHoldingLocks[$name] );
404 unset( $this->dbTrxMethodTimes[$name] );
408 $this->expect = array_fill_keys(
410 [ self::FLD_LIMIT => INF, self::FLD_FNAME =>
null ]
413 $this->hits = array_fill_keys( self::COUNTER_EVENT_NAMES, 0 );
422 return ( $value > $this->expect[$expectation][self::FLD_LIMIT] );
430 $newValue = ++$this->hits[$expectation];
432 return ( $newValue > $this->expect[$expectation][self::FLD_LIMIT] );
446 ?
string $trxId =
null,
447 ?
string $serverName =
null
449 if ( $this->silenced ) {
455 $message =
"Expectation ($expectation <=) $max by $by not met (actual: {actual})";
457 $message .=
' in trx #{trxId}';
459 $message .=
":\n{query}\n";
460 $this->logger->warning(
463 'measure' => $expectation,
464 'maxSeconds' => $max,
466 'actualSeconds' => $actual,
468 'exception' =>
new RuntimeException(),
470 'fullQuery' => $this->
getRawSql( $query ),
471 'dbHost' => $serverName