diff --git a/reactor-plc/threads.lua b/reactor-plc/threads.lua index c38a5a3..50e16c6 100644 --- a/reactor-plc/threads.lua +++ b/reactor-plc/threads.lua @@ -41,7 +41,7 @@ function threads.thread__main(smem) -- execute thread function public.exec() databus.tx_rt_status("main", true) - log.debug("main thread start") + log.debug("OS: main thread start") -- send status updates at 2Hz (every 10 server ticks) (every loop tick) -- send link requests at 0.5Hz (every 40 server ticks) (every 8 loop ticks) @@ -236,7 +236,7 @@ function threads.thread__main(smem) -- check for termination request if event == "terminate" or ppm.should_terminate() then - log.info("terminate requested, main thread exiting") + log.info("OS: terminate requested, main thread exiting") -- rps handles reactor shutdown plc_state.shutdown = true break @@ -260,7 +260,7 @@ function threads.thread__main(smem) -- if not, we need to restart the clock -- this thread cannot be slept because it will miss events (namely "terminate" otherwise) if not plc_state.shutdown then - log.info("main thread restarting now...") + log.info("OS: main thread restarting now...") end end end @@ -281,7 +281,7 @@ function threads.thread__rps(smem) -- execute thread function public.exec() databus.tx_rt_status("rps", true) - log.debug("rps thread start") + log.debug("OS: rps thread start") -- load in from shared memory local networked = smem.networked @@ -326,7 +326,7 @@ function threads.thread__rps(smem) -- check safety (SCRAM occurs if tripped) local rps_tripped, rps_status_string, rps_first = rps.check(not plc_state.no_reactor) if rps_tripped and rps_first then - println_ts("[RPS] SCRAM! safety trip: " .. rps_status_string) + println_ts("RPS: SCRAM'd on safety trip (" .. rps_status_string .. ")") if networked then plc_comms.send_rps_alarm(rps_status_string) end end @@ -339,15 +339,17 @@ function threads.thread__rps(smem) -- received a command if msg.message == MQ__RPS_CMD.SCRAM then -- SCRAM + log.info("RPS: OS requested SCRAM") rps.scram() elseif msg.message == MQ__RPS_CMD.DEGRADED_SCRAM then -- lost peripheral(s) + log.info("RPS: received PLC degraded alert") rps.trip_fault() elseif msg.message == MQ__RPS_CMD.TRIP_TIMEOUT then -- watchdog tripped + println_ts("RPS: supervisor timeout") + log.warning("RPS: received supervisor timeout alert") rps.trip_timeout() - println_ts("supervisor timeout") - log.warning("supervisor timeout") end elseif msg.qtype == mqueue.TYPE.DATA then -- received data @@ -363,17 +365,17 @@ function threads.thread__rps(smem) -- check for termination request if plc_state.shutdown then -- safe exit - log.info("rps thread shutdown initiated") + log.info("OS: rps thread shutdown initiated") if rps.scram() then println_ts("exiting, reactor disabled") - log.info("rps thread reactor SCRAM OK") + log.info("OS: rps thread reactor SCRAM OK") else println_ts("exiting, reactor failed to disable") - log.error("rps thread failed to SCRAM reactor on exit") + log.error("OS: rps thread failed to SCRAM reactor on exit") end - log.info("rps thread exiting") + log.info("OS: rps thread exiting") break end @@ -396,7 +398,7 @@ function threads.thread__rps(smem) if not plc_state.shutdown then smem.plc_sys.rps.scram() - log.info("rps thread restarting in 5 seconds...") + log.info("OS: rps thread restarting in 5 seconds...") util.psleep(5) end end @@ -415,7 +417,7 @@ function threads.thread__comms_tx(smem) -- execute thread function public.exec() databus.tx_rt_status("comms_tx", true) - log.debug("comms tx thread start") + log.debug("OS: comms tx thread start") -- load in from shared memory local plc_state = smem.plc_state @@ -453,7 +455,7 @@ function threads.thread__comms_tx(smem) -- check for termination request if plc_state.shutdown then - log.info("comms tx thread exiting") + log.info("OS: comms tx thread exiting") break end @@ -475,7 +477,7 @@ function threads.thread__comms_tx(smem) databus.tx_rt_status("comms_tx", false) if not plc_state.shutdown then - log.info("comms tx thread restarting in 5 seconds...") + log.info("OS: comms tx thread restarting in 5 seconds...") util.psleep(5) end end @@ -497,7 +499,7 @@ function threads.thread__comms_rx(smem) -- execute thread function public.exec() databus.tx_rt_status("comms_rx", true) - log.debug("comms rx thread start") + log.debug("OS: comms rx thread start") -- load in from shared memory local plc_state = smem.plc_state @@ -535,7 +537,7 @@ function threads.thread__comms_rx(smem) -- check for termination request if plc_state.shutdown then - log.info("comms rx thread exiting") + log.info("OS: comms rx thread exiting") break end @@ -557,7 +559,7 @@ function threads.thread__comms_rx(smem) databus.tx_rt_status("comms_rx", false) if not plc_state.shutdown then - log.info("comms rx thread restarting in 5 seconds...") + log.info("OS: comms rx thread restarting in 5 seconds...") util.psleep(5) end end @@ -576,7 +578,7 @@ function threads.thread__setpoint_control(smem) -- execute thread function public.exec() databus.tx_rt_status("spctl", true) - log.debug("setpoint control thread start") + log.debug("OS: setpoint control thread start") -- load in from shared memory local plc_state = smem.plc_state @@ -666,7 +668,7 @@ function threads.thread__setpoint_control(smem) -- check for termination request if plc_state.shutdown then - log.info("setpoint control thread exiting") + log.info("OS: setpoint control thread exiting") break end @@ -688,7 +690,7 @@ function threads.thread__setpoint_control(smem) databus.tx_rt_status("spctl", false) if not plc_state.shutdown then - log.info("setpoint control thread restarting in 5 seconds...") + log.info("OS: setpoint control thread restarting in 5 seconds...") util.psleep(5) end end diff --git a/scada-common/comms.lua b/scada-common/comms.lua index 18f2d48..17fbee8 100644 --- a/scada-common/comms.lua +++ b/scada-common/comms.lua @@ -205,7 +205,7 @@ function comms.scada_packet() if (type(max_distance) == "number") and (type(distance) == "number") and (distance > max_distance) then -- outside of maximum allowable transmission distance - -- log.debug("comms.scada_packet.receive(): discarding packet with distance " .. distance .. " (outside trusted range)") + -- log.debug("COMMS: comms.scada_packet.receive(): discarding packet with distance " .. distance .. " (outside trusted range)") else if type(self.raw) == "table" then if #self.raw == 5 then @@ -326,7 +326,7 @@ function comms.authd_packet() if (type(max_distance) == "number") and ((type(distance) ~= "number") or (distance > max_distance)) then -- outside of maximum allowable transmission distance - -- log.debug("comms.authd_packet.receive(): discarding packet with distance " .. distance .. " (outside trusted range)") + -- log.debug("COMMS: comms.authd_packet.receive(): discarding packet with distance " .. distance .. " (outside trusted range)") else if type(self.raw) == "table" then if #self.raw == 4 then @@ -412,7 +412,7 @@ function comms.modbus_packet() self.raw = { self.txn_id, self.unit_id, self.func_code } for i = 1, self.length do insert(self.raw, data[i]) end else - log.error("comms.modbus_packet.make(): data not a table") + log.error("COMMS: modbus_packet.make(): data not a table") end end @@ -435,11 +435,11 @@ function comms.modbus_packet() return size_ok and valid else - log.debug("attempted MODBUS_TCP parse of incorrect protocol " .. frame.protocol(), true) + log.debug("COMMS: attempted MODBUS_TCP parse of incorrect protocol " .. frame.protocol(), true) return false end else - log.debug("nil frame encountered", true) + log.debug("COMMS: nil frame encountered", true) return false end end @@ -498,7 +498,7 @@ function comms.rplc_packet() self.raw = { self.id, self.type } for i = 1, #data do insert(self.raw, data[i]) end else - log.error("comms.rplc_packet.make(): data not a table") + log.error("COMMS: rplc_packet.make(): data not a table") end end @@ -521,11 +521,11 @@ function comms.rplc_packet() return ok else - log.debug("attempted RPLC parse of incorrect protocol " .. frame.protocol(), true) + log.debug("COMMS: attempted RPLC parse of incorrect protocol " .. frame.protocol(), true) return false end else - log.debug("nil frame encountered", true) + log.debug("COMMS: nil frame encountered", true) return false end end @@ -580,7 +580,7 @@ function comms.mgmt_packet() self.raw = { self.type } for i = 1, #data do insert(self.raw, data[i]) end else - log.error("comms.mgmt_packet.make(): data not a table") + log.error("COMMS: mgmt_packet.make(): data not a table") end end @@ -601,11 +601,11 @@ function comms.mgmt_packet() return ok else - log.debug("attempted SCADA_MGMT parse of incorrect protocol " .. frame.protocol(), true) + log.debug("COMMS: attempted SCADA_MGMT parse of incorrect protocol " .. frame.protocol(), true) return false end else - log.debug("nil frame encountered", true) + log.debug("COMMS: nil frame encountered", true) return false end end @@ -659,7 +659,7 @@ function comms.crdn_packet() self.raw = { self.type } for i = 1, #data do insert(self.raw, data[i]) end else - log.error("comms.crdn_packet.make(): data not a table") + log.error("COMMS: crdn_packet.make(): data not a table") end end @@ -680,11 +680,11 @@ function comms.crdn_packet() return ok else - log.debug("attempted SCADA_CRDN parse of incorrect protocol " .. frame.protocol(), true) + log.debug("COMMS: attempted SCADA_CRDN parse of incorrect protocol " .. frame.protocol(), true) return false end else - log.debug("nil frame encountered", true) + log.debug("COMMS: nil frame encountered", true) return false end end diff --git a/scada-common/network.lua b/scada-common/network.lua index f7213bd..1891f5e 100644 --- a/scada-common/network.lua +++ b/scada-common/network.lua @@ -49,7 +49,7 @@ function network.init_mac(passkey) c_eng.hmac.setKey(c_eng.key) local init_time = util.time_ms() - start - log.info("network.init_mac completed in " .. init_time .. "ms") + log.info("NET: network.init_mac completed in " .. init_time .. "ms") return init_time end @@ -71,7 +71,7 @@ local function compute_hmac(message) local hash = c_eng.hmac.asHex() - -- log.debug("compute_hmac(): hmac-md5 = " .. util.strval(hash) .. " (took " .. (util.time_ms() - start) .. "ms)") + -- log.debug("NET: compute_hmac(): hmac-md5 = " .. util.strval(hash) .. " (took " .. (util.time_ms() - start) .. "ms)") return hash end @@ -190,13 +190,13 @@ function network.nic(modem) ---@cast tx_packet authd_packet tx_packet.make(packet, compute_hmac) - -- log.debug("network.modem.transmit: data processing took " .. (util.time_ms() - start) .. "ms") + -- log.debug("NET: network.modem.transmit: data processing took " .. (util.time_ms() - start) .. "ms") end ---@diagnostic disable-next-line: need-check-nil modem.transmit(dest_channel, local_channel, tx_packet.raw_sendable()) else - log.debug("network.transmit tx dropped, link is down") + log.debug("NET: network.transmit tx dropped, link is down") end end @@ -227,10 +227,10 @@ function network.nic(modem) local computed_hmac = compute_hmac(textutils.serialize(s_packet.raw_header(), { allow_repetitions = true, compact = true })) if a_packet.mac() == computed_hmac then - -- log.debug("network.modem.receive: HMAC verified in " .. (util.time_ms() - start) .. "ms") + -- log.debug("NET: network.modem.receive: HMAC verified in " .. (util.time_ms() - start) .. "ms") s_packet.stamp_authenticated() else - -- log.debug("network.modem.receive: HMAC failed verification in " .. (util.time_ms() - start) .. "ms") + -- log.debug("NET: network.modem.receive: HMAC failed verification in " .. (util.time_ms() - start) .. "ms") end end end