::nx::Class ::nsmcp::LogRecordParser

Methods: All Methods Documented Methods Hide Methods
Source: Display Source Hide Source
Variables: Show Variables Hide Variables

Class ::nsmcp::LogRecordParser

::nsmcp::LogRecordParser

create ... \
[ -colorCodeMap colorCodeMap ]

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

Class Relations

class: ::nx::Class
superclass: ::nsmcp::Object

::nx::Class create ::nsmcp::LogRecordParser \
     -superclass ::nsmcp::Object

Methods (to be applied on instances)

accessRequestIdentifier (scripted, public)
```
 <instance of nsmcp::LogRecordParser> accessRequestIdentifier \
    message
```
Extract the request identifier from a supported access-log message. Inspect the access-log identifier field rather than guessing from URLs or headers.

Parameters:

message (required)
Diagnostic message text.

Returns:
The validated request identifier, or an empty result when unavailable.

Testcases:
No testcase defined.
```
# OpenACS access format: peer request-id user [timestamp] ...
if {[regexp {^\S+[ \t]+(\S+)[ \t]+\S+[ \t]+\[} $message -> identifier] &&
    [:validRequestIdentifier $identifier]} {
    return $identifier
}
return {}
```
continuation (scripted, public)
```
 <instance of nsmcp::LogRecordParser> continuation message line
```
Decide whether a physical line continues the current logical record. Use supported continuation prefixes and message context to avoid treating unrelated lines as one record.

Parameters:

message (required)
Current logical-record message used to interpret continuation prefixes.

line (required)
Following physical line to classify.

Returns:
True when the line is a continuation, otherwise false.

Testcases:
No testcase defined.
```
return [expr {[string index $line 0] eq ":" ||
    ([regexp {^(DEBUG[1-5]?|LOG|INFO|NOTICE|WARNING|ERROR|FATAL|PANIC):[ \t]+} $message] &&
     [regexp {^(DETAIL|HINT|CONTEXT):[ \t]+} $line])}]
```

metadata (scripted, public)

 <instance of nsmcp::LogRecordParser> metadata message

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.

# 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

stripAnsi (scripted, public)

 <instance of nsmcp::LogRecordParser> stripAnsi message

Remove recognized ANSI formatting from a system-log message. Initialize the color-code map lazily; return unformatted input without further transformation.

Parameters:

message (required)
Diagnostic message text.

Returns:
The message with recognized ANSI codes removed.

Testcases:
No testcase defined.

if {[string first \x1b $message] < 0} {
    return $message
}
if {![info exists :colorCodeMap]} {
    set :colorCodeMap [list  [binary decode hex 1b5b303b33326d] {}  [binary decode hex 1b5b303b33396d] {}  [binary decode hex 1b5b306d] {}  [binary decode hex 1b5b313b33316d] {}  [binary decode hex 1b5b313b33396d] {}]
}
set message [string map ${:colorCodeMap} $message]
# Preserve support for uncommon/custom SGR sequences, off the fast path.
if {[string first \x1b $message] >= 0} {
    regsub -all {\x1b\[[0-9;]*m} $message {} message
}
return $message

timestampSeconds (scripted, public)

 <instance of nsmcp::LogRecordParser> timestampSeconds timestamp

Convert a supported NaviServer log timestamp to epoch seconds. Validate the timestamp layout and retain supported fractional-second information.

Parameters:

timestamp (required)
Parsed timestamp or timing base supplied by the parser.

Returns:
The parsed epoch timestamp, or an empty result for an invalid timestamp.

Testcases:
No testcase defined.

if {![regexp {^([0-9]{2}/[A-Za-z]{3}/[0-9]{4}:[0-9]{2}:[0-9]{2}:[0-9]{2})(\.[0-9]+)?( [+-][0-9]{4})?$} $timestamp -> base fraction zone]} {
    return {}
}
set format {%d/%b/%Y:%H:%M:%S}
if {$zone ne ""} {
    append base $zone
    append format { %z}
}
if {[catch {
    clock scan $base -format $format -locale C
} seconds]} {
    return {}
}
if {$fraction ne ""} {
    set seconds [expr {$seconds+double("0$fraction")}]
}
return $seconds

validConnectionIdentifier (scripted, public)
```
 <instance of nsmcp::LogRecordParser> validConnectionIdentifier \
    identifier
```
Validate a complete connection-thread identifier. Require the server, pool, worker and request fields of the connection identifier.

Parameters:

identifier (required)
Complete log-thread identifier, or the raw identifier field when parsing access records.

Returns:
True for a valid connection identifier, otherwise false.

Testcases:
No testcase defined.
```
return [regexp {^-conn:[^:\[\]\r\n]+:[^:\[\]\r\n]+:[0-9]+:[0-9]+-$} $identifier]
```
validRequestIdentifier (scripted, public)
```
 <instance of nsmcp::LogRecordParser> validRequestIdentifier \
    identifier
```
Validate a complete NaviServer log-thread identifier. Accept the dash-delimited identifier form used by connection, scheduler and job threads.

Parameters:

identifier (required)
Complete log-thread identifier, or the raw identifier field when parsing access records.

Returns:
True for an accepted request identifier, otherwise false.

Testcases:
No testcase defined.
```
# System-log identifiers are thread names, including sched/nsjob/SMTP.
return [regexp {^-[^\x00\[\]\s]+-$} $identifier]
```

Methods: All Methods Documented Methods Hide Methods
Source: Display Source Hide Source
Variables: Show Variables Hide Variables

Class ::nsmcp::LogRecordParser

Class Relations

Methods (to be applied on instances)

accessRequestIdentifier (scripted, public)

continuation (scripted, public)

metadata (scripted, public)

stripAnsi (scripted, public)

timestampSeconds (scripted, public)

validConnectionIdentifier (scripted, public)

validRequestIdentifier (scripted, public)