From e9f07cf1cb57fda6e767f9c1db84cf0ce863c26d Mon Sep 17 00:00:00 2001 From: Qiwei Yang Date: Wed, 8 Jan 2025 16:53:28 +0800 Subject: [PATCH] add debug message host call (#264) --- .../VMInvocations/HostCall/HostCalls.swift | 105 ++++++++++++++++++ .../AccumulateContext.swift | 2 + .../IsAuthorizedContext.swift | 7 +- .../OnTransferContext.swift | 2 + .../InvocationContexts/RefineContext.swift | 27 +++-- .../VMInvocations/LogTests.swift | 52 +++++++++ 6 files changed, 181 insertions(+), 14 deletions(-) create mode 100644 Blockchain/Tests/BlockchainTests/VMInvocations/LogTests.swift diff --git a/Blockchain/Sources/Blockchain/VMInvocations/HostCall/HostCalls.swift b/Blockchain/Sources/Blockchain/VMInvocations/HostCall/HostCalls.swift index cc10ff5d..d5616ce0 100644 --- a/Blockchain/Sources/Blockchain/VMInvocations/HostCall/HostCalls.swift +++ b/Blockchain/Sources/Blockchain/VMInvocations/HostCall/HostCalls.swift @@ -1,8 +1,11 @@ import Codec import Foundation import PolkaVM +import TracingUtils import Utils +private let logger = Logger(label: "HostCalls") + // MARK: - General /// Get gas remaining @@ -977,3 +980,105 @@ public class Expunge: HostCall { context.pvms[reg7] = nil } } + +/// A host call for passing a debugging message from the service/authorizer to the hosting environment for logging to the node operator. +public class Log: HostCall { + public static var identifier: UInt8 { 100 } + + public enum Level: UInt32, Codable { + case error = 0 + case debug = 1 + case info = 2 + case warn = 3 + case trace = 4 + + var description: String { + switch self { + case .error: "ERROR" + case .debug: "DEBUG" + case .info: "INFO" + case .warn: "WARN" + case .trace: "TRACE" + } + } + } + + public struct Details: Codable { + public let time: String + public let level: Level + public let target: Data? + public let message: Data + public let core: CoreIndex? + public let service: ServiceIndex? + + public var json: JSON { + JSON.dictionary([ + "time": .string(time), + "level": .string(level.description), + "message": .string(String(data: message, encoding: .utf8) ?? "invalid string"), + "target": target != nil ? .string(String(data: target!, encoding: .utf8) ?? "invalid string") : .null, + "service": service != nil ? .string(String(service!)) : .null, + "core": core != nil ? .string(String(core!)) : .null, + ]) + } + + public var str: String { + var result = time + " \(level.description)" + if let core { + result += " @\(core)" + } + if let service { + result += " #\(service)" + } + if let target { + result += " \(String(data: target, encoding: .utf8) ?? "invalid string")" + } + result += " \(String(data: message, encoding: .utf8) ?? "invalid string")" + + return result + } + } + + public var core: CoreIndex? + public var service: ServiceIndex? + + public init(core: CoreIndex? = nil, service: ServiceIndex? = nil) { + self.core = core + self.service = service + } + + public func _callImpl(config _: ProtocolConfigRef, state: VMState) async throws { + let regs: [UInt32] = state.readRegisters(in: 7 ..< 12) + let level = regs[0] + let target = regs[1] == 0 && regs[2] == 0 ? nil : try state.readMemory(address: regs[1], length: Int(regs[2])) + let message = try state.readMemory(address: regs[3], length: Int(regs[4])) + + let dateFormatter = DateFormatter() + dateFormatter.dateFormat = "yyyy-MM-dd HH-mm-ss" + let time = dateFormatter.string(from: Date()) + + let details = Details( + time: time, + level: Level(rawValue: level) ?? .debug, + target: target, + message: message, + core: core, + service: service + ) + + switch level { + case 0: + logger.error(Logger.Message(stringLiteral: details.str)) + case 1: + logger.warning(Logger.Message(stringLiteral: details.str)) + case 2: + logger.info(Logger.Message(stringLiteral: details.str)) + case 3: + logger.debug(Logger.Message(stringLiteral: details.str)) + case 4: + logger.trace(Logger.Message(stringLiteral: details.str)) + default: + logger.error("Invalid log level: \(level)") + } + } +} diff --git a/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/AccumulateContext.swift b/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/AccumulateContext.swift index 90039a4e..af17db85 100644 --- a/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/AccumulateContext.swift +++ b/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/AccumulateContext.swift @@ -61,6 +61,8 @@ public class AccumulateContext: InvocationContext { return await Solicit(x: &context.x, timeslot: timeslot).call(config: config, state: state) case Forget.identifier: return await Forget(x: &context.x, timeslot: timeslot).call(config: config, state: state) + case Log.identifier: + return await Log(service: context.x.serviceIndex).call(config: config, state: state) default: state.consumeGas(Gas(10)) state.writeRegister(Registers.Index(raw: 0), HostCallResultCode.WHAT.rawValue) diff --git a/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/IsAuthorizedContext.swift b/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/IsAuthorizedContext.swift index e92733fe..970c9842 100644 --- a/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/IsAuthorizedContext.swift +++ b/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/IsAuthorizedContext.swift @@ -15,9 +15,12 @@ public class IsAuthorizedContext: InvocationContext { } public func dispatch(index: UInt32, state: VMState) async -> ExecOutcome { - if index == GasFn.identifier { + switch UInt8(index) { + case GasFn.identifier: return await GasFn().call(config: config, state: state) - } else { + case Log.identifier: + return await Log().call(config: config, state: state) + default: state.consumeGas(Gas(10)) state.writeRegister(Registers.Index(raw: 7), HostCallResultCode.WHAT.rawValue) return .continued diff --git a/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/OnTransferContext.swift b/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/OnTransferContext.swift index 99fd1689..54612f83 100644 --- a/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/OnTransferContext.swift +++ b/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/OnTransferContext.swift @@ -35,6 +35,8 @@ public class OnTransferContext: InvocationContext { case Info.identifier: return await Info(serviceIndex: context.index, accounts: context.accounts) .call(config: config, state: state) + case Log.identifier: + return await Log(service: index).call(config: config, state: state) default: state.consumeGas(Gas(10)) state.writeRegister(Registers.Index(raw: 7), HostCallResultCode.WHAT.rawValue) diff --git a/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/RefineContext.swift b/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/RefineContext.swift index da7ea091..46181c9e 100644 --- a/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/RefineContext.swift +++ b/Blockchain/Sources/Blockchain/VMInvocations/InvocationContexts/RefineContext.swift @@ -45,9 +45,10 @@ public class RefineContext: InvocationContext { public func dispatch(index: UInt32, state: VMState) async -> ExecOutcome { logger.debug("dispatching host-call: \(index)") - if index == GasFn.identifier { + switch UInt8(index) { + case GasFn.identifier: return await GasFn().call(config: config, state: state) - } else if index == HistoricalLookup.identifier { + case HistoricalLookup.identifier: return await HistoricalLookup( context: context, service: service, @@ -55,25 +56,27 @@ public class RefineContext: InvocationContext { lookupAnchorTimeslot: lookupAnchorTimeslot ) .call(config: config, state: state) - } else if index == Import.identifier { + case Import.identifier: return await Import(context: context, importSegments: importSegments).call(config: config, state: state) - } else if index == Export.identifier { + case Export.identifier: return await Export(context: &context, exportSegmentOffset: exportSegmentOffset).call(config: config, state: state) - } else if index == Machine.identifier { + case Machine.identifier: return await Machine(context: &context).call(config: config, state: state) - } else if index == Peek.identifier { + case Peek.identifier: return await Peek(context: context).call(config: config, state: state) - } else if index == Zero.identifier { + case Zero.identifier: return await Zero(context: &context).call(config: config, state: state) - } else if index == Poke.identifier { + case Poke.identifier: return await Poke(context: &context).call(config: config, state: state) - } else if index == VoidFn.identifier { + case VoidFn.identifier: return await VoidFn(context: &context).call(config: config, state: state) - } else if index == Invoke.identifier { + case Invoke.identifier: return await Invoke(context: &context).call(config: config, state: state) - } else if index == Expunge.identifier { + case Expunge.identifier: return await Expunge(context: &context).call(config: config, state: state) - } else { + case Log.identifier: + return await Log(service: service).call(config: config, state: state) + default: state.consumeGas(Gas(10)) state.writeRegister(Registers.Index(raw: 7), HostCallResultCode.WHAT.rawValue) return .continued diff --git a/Blockchain/Tests/BlockchainTests/VMInvocations/LogTests.swift b/Blockchain/Tests/BlockchainTests/VMInvocations/LogTests.swift new file mode 100644 index 00000000..b62a600c --- /dev/null +++ b/Blockchain/Tests/BlockchainTests/VMInvocations/LogTests.swift @@ -0,0 +1,52 @@ +import Foundation +import Testing +import Utils + +@testable import Blockchain + +struct LogTests { + @Test func testLogDetailJSON() async throws { + let logDetials = Log.Details( + time: "2023-04-01 12:00:00", + level: .error, + target: Data("target".utf8), + message: Data("message".utf8), + core: nil, + service: 1 + ) + let json = logDetials.json + #expect(json["time"]?.string == "2023-04-01 12:00:00") + #expect(json["level"]?.string == "ERROR") + #expect(json["target"]?.string == "target") + #expect(json["message"]?.string == "message") + #expect(json["service"]?.string == "1") + #expect(json["core"] == .null) + } + + @Test func testLogDetailString() async throws { + let logDetials = Log.Details( + time: "2023-04-01 12:00:00", + level: .trace, + target: Data("target".utf8), + message: Data("message".utf8), + core: nil, + service: nil + ) + let str = logDetials.str + #expect(str == "2023-04-01 12:00:00 TRACE target message") + } + + @Test func testLogDetailInvalidString() async throws { + let invalidData = Data([0xFF, 0xFE, 0xFD]) + let logDetails = Log.Details( + time: "2023-04-01 12:00:00", + level: .warn, + target: invalidData, + message: invalidData, + core: nil, + service: nil + ) + let str = logDetails.str + #expect(str == "2023-04-01 12:00:00 WARN invalid string invalid string") + } +}