nsmcp::LogRecordParser method metadata (public)

 <instance of nsmcp::LogRecordParser> metadata message

Defined in /usr/local/ns/tcl/nsmcp/log-record.tcl

Extract structured metadata from a log message. Normalize supported system/access layouts and enrich request timing when an access parser is available.

Parameters:

message (required)

Diagnostic message text.

Returns:

The parsed metadata dictionary.

Testcases:

No testcase defined.

Source code:

# Access logs contain no ANSI formatting. Strip only system-log rows.
if {[string index $message 0] eq "\[" || [string index $message 0] eq "\x1b"} {
    set message [:stripAnsi $message]
}
set result [dict create timestamp {} processThread {} logThread {}  severity {} requestIdentifier {} peerAddress {} method {} url {}  protocol {} status {} responseBytes {} recordType unknown]
if {[regexp {^\[([^\]\r\n]+)\]\[([^\]\r\n]+)\]\[([^\]\r\n]+)\][ \t]+([A-Za-z][A-Za-z0-9_()-]*):[ \t]*}  $message -> timestamp processThread thread severity]} {
    dict set result recordType system
    dict set result timestamp $timestamp
    dict set result processThread $processThread
    dict set result logThread $thread
    dict set result severity $severity
} elseif {[regexp {^\[([^\]\r\n]+)\][ \t]+([A-Za-z][A-Za-z0-9_()-]*):[ \t]*}  $message -> thread severity]} {
    # Startup logging can omit the date and process/thread fields.
    dict set result recordType system-short
    dict set result logThread $thread
    dict set result severity $severity
} elseif {[regexp {^\[([^\]\r\n]+)\][ \t]+Mutex unlock ([^\r\n]+): lock duration ([0-9]+(?:\.[0-9]+)?) \(deferred condition-wait holds ([0-9]+), total ([0-9]+(?:\.[0-9]+)?)\)[ \t]*(?:\r?\n|$)}  $message -> thread mutex maximum observations total]
          && [string length $maximum]<=32 && [string length $total]<=32
          && [string is double -strict $maximum] && [string is double -strict $total]
          && [string length $observations]<=19 && [string is entier -strict $observations]
          && $observations>=1 && $observations<=9223372036854775807
          && $total+0.000001>=$maximum && $total<=$maximum*$observations+0.000001} {
    # The duration is the maximum of N represented intervals, not one
    # sample or the total. The thread identifies that maximum's owner.
    dict set result recordType mutex-trace
    dict set result logThread $thread
    dict set result mutexName $mutex
    dict set result mutexOperation unlock
    dict set result mutexMetric hold
    dict set result mutexDurationSeconds [expr {double($maximum)}]
    dict set result mutexObservationCount [expr {wide($observations)}]
    dict set result mutexTotalSeconds [expr {double($total)}]
    dict set result mutexDeferred true
} elseif {[regexp {^\[([^\]\r\n]+)\][ \t]+Mutex (lock|unlock) ([^\r\n]+): (wait|lock) duration (-?[0-9]+(?:\.[0-9]+)?)[ \t]*(?:\r?\n|$)}  $message -> thread operation mutex metric duration]
          && [string length $duration]<=32
          && (($operation eq "lock" && $metric eq "wait") || ($operation eq "unlock" && $metric eq "lock"))} {
    # mutexlocktrace uses stderr to avoid recursively taking log locks.
    # No timestamp or log severity is present; neither is inferred.
    dict set result recordType mutex-trace
    dict set result logThread $thread
    dict set result mutexName $mutex
    dict set result mutexOperation $operation
    dict set result mutexMetric [expr {$metric eq "wait" ? "wait" : "hold"}]
    dict set result mutexDurationSeconds [expr {double($duration)}]
} elseif {[regexp {^\[([^\]\r\n]+)\][ \t]+Mutex lock ([^\r\n]+) warning: wait duration (-?[0-9]+(?:\.[0-9]+)?|0\.-[0-9]{1,6}) is negative[ \t]*(?:\r?\n|$)}  $message -> thread mutex duration] && [string length $duration]<=32} {
    dict set result recordType mutex-trace
    dict set result logThread $thread
    dict set result severity Warning
    dict set result mutexName $mutex
    dict set result mutexOperation lock
    dict set result mutexMetric wait
    # NS_TIME_FMT prints a negative subsecond timeval as 0.-00001:
    # the signed integer microseconds must be divided by one million.
    if {[string match {0.-*} $duration]} {
        scan [string range $duration 3 end] %d micros
        set seconds [expr {-$micros/1000000.0}]
    } else {
        set seconds [expr {double($duration)}]
    }
    dict set result mutexDurationSeconds $seconds
} elseif {[regexp {^(Ns_MutexLock|Ns_MutexTryLock|Ns_MutexUnlock|NsGetLock): called with uninitialized lock pointer\. This should not happen, call Ns_MutexInit\(\) before this call(?:\r?\n|$)} $message]} {
    # Historical stderr diagnostics contain no thread or timestamp.
    dict set result recordType system-short
    dict set result severity Warning
} elseif {[regexp {^(DEBUG[1-5]?|LOG|INFO|NOTICE|WARNING|ERROR|FATAL|PANIC):[ \t]+} $message -> level]} {
    dict set result recordType postgres
    dict set result severity [string totitle $level]
} elseif {[regexp {^(\S+)[ \t]+(\S+)[ \t]+\S+[ \t]+\[([0-9]{2}/[A-Za-z]{3}/[0-9]{4}:[0-9]{2}:[0-9]{2}:[0-9]{2}[ \t]+[+-][0-9]{4})\][ \t]+"((?:[^"\\\r\n]|\\.)*)"[ \t]+([1-5][0-9]{2})[ \t]+(-|[0-9]+)(?:[ \t]|$)}  $message -> peer identifier timestamp request status bytes]} {
    dict set result recordType access
    dict set result timestamp $timestamp
    dict set result peerAddress $peer
    if {[:validRequestIdentifier $identifier]} {
        dict set result requestIdentifier $identifier
    }
    dict set result status [scan $status %d]
    if {$bytes ne "-"} {
        set bytes [string trimleft $bytes 0]
        dict set result responseBytes [expr {$bytes eq "" ? 0 : $bytes}]
    }
    # Preserve the logged request target; do not decode percent escapes
    # or interpret the application's query parameters here.
    if {[regexp {^(\S+)[ \t]+(\S+)[ \t]+(HTTP/[0-9]+\.[0-9]+)$}  $request -> method url protocol]} {
        dict set result method $method
        dict set result url $url
        dict set result protocol $protocol
    }
}
set thread [dict get $result logThread]
if {$thread ne "" && [:validRequestIdentifier $thread]} {
    dict set result requestIdentifier $thread
}
if {[dict get $result status] ne "" && [nsf::object::exists ::nsmcp::accessRecordParser]} {
    set access [::nsmcp::accessRecordParser parse $message]
    foreach key {requestIdentifier method url protocol pool startTime timingSource acceptTime queueTime filterTime runTime recordSource driver requestIdentifierUnique phaseTimingAvailable phaseTimingReason} {
        if {[dict exists $access $key]} {
            dict set result $key [dict get $access $key]
        }
    }
}
return $result

XQL Not present:

Generic, PostgreSQL, Oracle