nsmcp::LogService method run (public)

 <instance of nsmcp::LogService> run handle [ operation ] \
    [ identifier ]

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

Execute a scan slice using private state retained under its job handle. The optional arguments accept jobs queued before a live reload.

Parameters:

handle (required)

principal-bound job handle

operation (optional)

legacy queued operation

identifier (optional)

legacy queued arguments

Testcases:

No testcase defined.

Source code:

ns_mutex lock ${:mutex}
try {
    if {![nsv_exists ${:store} $handle]} return
    set record [nsv_get ${:store} $handle]
    if {[dict get $record status] in {complete failed}} return
    if {[dict exists $record operation]} {
        set operation [dict get $record operation]
        set identifier [dict get $record identifier]
    }
    dict set record status running
    if {![dict exists $record firstStartedMs]} {dict set record firstStartedMs [clock milliseconds]}
    nsv_set ${:store} $handle $record
} finally {ns_mutex unlock ${:mutex}}
set mappings {}
set sliceStarted [clock milliseconds]
try {
    if {$operation eq "errors"} {
        if {![catch {dict get $identifier severity} severity]} {
            set snapshot [${:correlation} errors $severity [dict get $identifier literal] [dict get $identifier limit]]
        } else {
            # Jobs queued before reload carried only the severity string.
            set snapshot [${:correlation} errors {*}[expr {$identifier eq "" ? {} : [list $identifier]}]]
        }
        set data [:summary $snapshot mappings]
        set searchSnapshots [list $snapshot]
    } elseif {$operation eq "accessFileSummary"} {
        if {[dict get $record expires]<=[clock seconds]} {
            if {[dict exists $identifier scanState]} {::nsmcp::accessScanCleanup [dict get $identifier scanState]}
            error "access-log summary expired before completion"
        }
        set summary [${:correlation} accessFileSummary $identifier ${:redactor} [list [self] accessProgress $handle]]
        ns_mutex lock ${:mutex}
        try {
            set latest [nsv_get ${:store} $handle]
            if {[dict exists $latest progress]} {dict set record progress [dict get $latest progress]}
        } finally {ns_mutex unlock ${:mutex}}
        set data [lindex $summary 2]
        set continuation [lindex $summary 3]
        if {$continuation ne ""} {
            dict set identifier scanState $continuation
            dict set record identifier $identifier
            ns_mutex lock ${:mutex}
            try {::nsmcp::logJobTiming record $sliceStarted; nsv_set ${:store} $handle $record} finally {ns_mutex unlock ${:mutex}}
            ns_job queue -detached ${:queue} [list [self] run $handle]
            return
        }
    } elseif {$operation eq "errorSummary"} {
        set summary [${:correlation} errorSummary $identifier ${:redactor}]
        set data [lindex $summary 2]
        set continuation [lindex $summary 3]
        if {$continuation ne ""} {
            if {[dict get $record expires] <= [clock seconds]} {error "summary job expired before completion"}
            dict set identifier scanState $continuation
            dict set record operation $operation
            dict set record identifier $identifier
            dict set record progress [list examinedBytes number [dict get $continuation examined]  sourceBytes number [dict get $continuation sourceBytes]]
            ns_mutex lock ${:mutex}
            try {::nsmcp::logJobTiming record $sliceStarted; nsv_set ${:store} $handle $record} finally {ns_mutex unlock ${:mutex}}
            ns_job queue -detached ${:queue} [list [self] run $handle]
            return
        }
        set updated {}; set budget 24
        foreach {key type value} $data {
            if {$key eq "groups"} {
                set groups {}
                foreach {index groupType fields} $value {
                    set samples {}; set category {}
                    foreach {field fieldType item} $fields {
                        if {$field eq "category"} {set category $item}
                        if {$field eq "requestSamples"} {
                            foreach {n sampleType sampleFields} $item {
                                set sample {}
                                foreach {k t v} $sampleFields {dict set sample $k $v}
                                lappend samples $sample
                            }
                        }
                    }
                    if {$category eq "duplicate-parameter"} {
                        set correlation [list available boolean false reason string {Access analytics is not configured.}]
                        set selected {}
                        if {${:analytics} ne ""} {
                            if {$budget <= 0} {
                                set correlation [list available boolean false reason string {The 24-request correlation budget was exhausted.}]
                            } else {
                                set selected [lrange $samples 0 [expr {min(11,$budget-1)}]]
                                incr budget -[llength $selected]
                                set correlation [list available boolean false reason string {The retained access cache could not be queried.}]
                                if {![catch {${:analytics} correlateWarnings $selected ${:redactor}} result]} {set correlation [lindex $result 2]}
                            }
                        }
                        lappend correlation omittedSamples number [expr {[llength $samples]-[llength $selected]}]
                        lappend fields accessCorrelation object $correlation
                    }
                    lappend groups $index $groupType $fields
                }
                set value $groups
            }
            lappend updated $key $type $value
        }
        set data $updated
    } elseif {$operation eq "routingSummary"} {
        if {[dict get $record expires]<=[clock seconds]} {error "routing scan expired before completion"}
        set permissions {diagnostics.logs.read diagnostics.runtime.read}
        if {[dict get $record requiresPeers]} {lappend permissions diagnostics.logs.peers.read}
        set context [::nsmcp::RequestContext new -principal [dict get $record principal]  -server [dict get $record server] -targets [list [dict get $record server]] -permissions $permissions]
        try {
            set step [[dict get $identifier tool] scanStep $context $identifier]
        } finally {$context destroy}
        set data [lindex [lindex $step 0] 2]
        dict set record progress [lindex $step 2]
        set continuation [lindex $step 1]
        if {$continuation ne ""} {
            dict set record operation $operation
            dict set record identifier $continuation
            ns_mutex lock ${:mutex}
            try {::nsmcp::logJobTiming record $sliceStarted; nsv_set ${:store} $handle $record} finally {ns_mutex unlock ${:mutex}}
            ns_job queue -detached ${:queue} [list [self] run $handle]
            return
        }
    } elseif {$operation eq "accessSummary"} {
        if {${:analytics} eq ""} {error "access analytics is not configured"}
        if {![${:analytics} info has type ::nsmcp::UnifiedAccessAnalytics]} {${:analytics} ingest [dict get $identifier from]}
        set summary [${:analytics} summary $identifier]
        # Jobs queued before a live reload have no interval handle yet.
        if {![dict exists $record windowHandle]} {
            dict set record windowHandle [ns_crypto::randombytes -encoding hex 32]
            dict set record window [dict create from [dict get $identifier from] to [dict get $identifier to]]
        }
        dict set summary windowHandle [dict get $record windowHandle]
        set from [clock format [dict get $summary from] -timezone UTC -format {%Y-%m-%d %H:%M:%S}]
        set to [clock format [dict get $summary to] -timezone UTC -format {%Y-%m-%d %H:%M:%S}]
        dict set summary intervalUTC "$from to $to UTC"
        set data [::nsmcp::accessSummaryTriples $summary]
    } else {
        if {$operation eq "requestContexts"} {
            set context [${:correlation} requestContexts [dict get $identifier identifiers] [dict get $identifier limit]]
            set ids {}; set n 0
            foreach id [dict get $context requestIdentifiers] {lappend ids $n string $id; incr n}
            set data [list server string [ns_info server] requestIdentifiers array $ids]
        } else {
            set context [${:correlation} requestContext $identifier]
            set data [list server string [ns_info server] requestIdentifier string $identifier]
        }
        lappend data system object [:summary [dict get $context system] mappings]
        set access {}; set index 0
        dict for {source snapshot} [dict get $context access] {
            lappend access $index object [:summary $snapshot mappings]
            incr index
        }
        lappend data access array $access
        set searchSnapshots [list [dict get $context system] {*}[dict values [dict get $context access]]]
    }
    if {[info exists searchSnapshots]} {
        set incomplete false; set examined 0; set total 0
        foreach snapshot $searchSnapshots {
            incr examined [dict get $snapshot cursor]
            incr total [dict get $snapshot sourceBytes]
            if {[dict get $snapshot scanIncomplete] && ![dict get $snapshot cacheFull]
                && (![dict exists $snapshot limitReached] || ![dict get $snapshot limitReached])} {set incomplete true}
        }
        if {$incomplete} {
            if {[dict get $record expires] <= [clock seconds]} {error "log search expired before completion"}
            dict set record progress [list examinedBytes number $examined sourceBytes number $total]
            ns_mutex lock ${:mutex}
            try {::nsmcp::logJobTiming record $sliceStarted; nsv_set ${:store} $handle $record} finally {ns_mutex unlock ${:mutex}}
            ns_job queue -detached ${:queue} [list [self] run $handle]
            return
        }
    }
    dict set record status complete
    dict set record data $data
    dict set record mappings $mappings
} on error {message options} {
    if {$operation eq "accessFileSummary" && [dict exists $identifier scanState]} {::nsmcp::accessScanCleanup [dict get $identifier scanState]}
    if {$operation eq "accessFileSummary"} {
        ns_mutex lock ${:mutex}
        try {
            set latest [nsv_get ${:store} $handle]
            if {[dict exists $latest progress]} {dict set record progress [dict get $latest progress]}
        } finally {ns_mutex unlock ${:mutex}}
    }
    if {$operation eq "accessFileSummary" && [dict exists $record progress]} {
        set fields {}
        foreach {key type value} [dict get $record progress] {
            if {$key eq "phase"} {set value failed}
            if {$key eq "updatedAt"} {set value [clock seconds]}
            lappend fields $key $type $value
        }
        dict set record progress $fields
    }
    dict set record status failed
    # No source paths, log contents, or exception details in client errors.
    ns_log error "nsmcp: background log operation failed: $message"
}
::nsmcp::logJobTiming record $sliceStarted true
if {[dict get $record status] eq "complete" && [dict exists $record processingTime]} {
    set data [dict get $record data]
    lappend data processingTime object [dict get $record processingTime]
    dict set record data $data
}
# Release potentially large continuation state on success or failure.
dict unset record identifier
dict unset record operation
ns_mutex lock ${:mutex}
try {nsv_set ${:store} $handle $record} finally {ns_mutex unlock ${:mutex}}

XQL Not present:

Generic, PostgreSQL, Oracle