Preserve structured logging metadata in @Resumable functions (#165)

* Preserve logging metadata in resumable functions

* Allow x64 Julia on Apple Silicon CI runners

---------

Co-authored-by: Stefan Krastanov <stefan@krastanov.org>

Author: Krastanov-agent

.github/workflows/ci.yml

@@ -50,6 +50,7 @@ jobs:
         with:
           version: ${{ matrix.version }}
           arch: ${{ matrix.arch }}
+          force-arch: true
       - uses: julia-actions/cache@v3
       - uses: julia-actions/julia-buildpkg@v1
       - uses: julia-actions/julia-runtest@v1

CHANGELOG.md

@@ -1,5 +1,10 @@
 # News
 
+## v1.0.7 - 2026-07-17
+
+- Preserve standard logging macro metadata names, including `_group`, `event`,
+  and shorthand fields, when logging from an `@resumable` function.
+
 ## v1.0.6 - 2026-04-23
 
 - (internal) switch to a reimplementation of `gensym` that is not replayable by JET.jl (see https://github.com/aviatesk/JET.jl/issues/814)

Project.toml

@@ -5,7 +5,7 @@ license = "MIT"
 desc = "C# sharp style generators a.k.a. semi-coroutines for Julia."
 authors = ["Ben Lauwens and volunteer maintainers"]
 repo = "https://github.com/JuliaDynamics/ResumableFunctions.jl.git"
-version = "1.0.6"
+version = "1.0.7"
 
 [deps]
 Logging = "56ddb016-857b-54e1-b83d-db4d58db5568"

src/utils.jl

@@ -349,6 +349,45 @@ function scoping(s::Symbol, scope; new = false)
   return lookup_rhs!(s, scope)
 end
 
+const _logging_macros = (
+  Symbol("@debug"),
+  Symbol("@info"),
+  Symbol("@warn"),
+  Symbol("@error"),
+  Symbol("@logmsg"),
+)
+
+function _is_logging_macro(name)
+  name in _logging_macros
+end
+
+function _is_logging_macro(name::Expr)
+  name.head === :. || return false
+  macro_name = name.args[end]
+  macro_name = macro_name isa QuoteNode ? macro_name.value : macro_name
+  macro_name in _logging_macros
+end
+
+function _logging_macro_name(name)
+  return name
+end
+
+function _logging_macro_name(name::Expr)
+  macro_name = name.args[end]
+  return macro_name isa QuoteNode ? macro_name.value : macro_name
+end
+
+function scope_logging_macro_arg(expr, scope; metadata = false)
+  if expr isa Expr && expr.head === :(=)
+    expr.args[2] = scoping(expr.args[2], scope)
+    return expr
+  end
+  if metadata && expr isa Symbol
+    return Expr(:(=), expr, scoping(expr, scope))
+  end
+  scoping(expr, scope)
+end
+
 function scope_generator_inner(expr, scope)
   for i in 2:length(expr.args)
     !(expr.args[i] isa Expr && expr.args[i].head === :(=)) &&
@@ -487,6 +526,15 @@ function scoping(expr::Expr, scope)
     return expr
   end
   if expr.head === :macrocall
+    if _is_logging_macro(expr.args[1])
+      metadata_start = _logging_macro_name(expr.args[1]) === Symbol("@logmsg") ? 5 : 4
+      for i in 2:length(expr.args)
+        expr.args[i] = scope_logging_macro_arg(
+          expr.args[i], scope; metadata = i >= metadata_start
+        )
+      end
+      return expr
+    end
     for i in 2:length(expr.args)
       expr.args[i] = scoping(expr.args[i], scope)
     end

test/Project.toml

@@ -3,6 +3,7 @@ Aqua = "4c88cf16-eb10-579e-8560-4a9242c79595"
 Documenter = "e30172f5-a6a5-5a46-863b-614d45cd2de4"
 ExplicitImports = "7d51a73a-1435-4ff3-83d9-f097790105c7"
 JET = "c3a54625-cd67-489e-a8e7-0a5a0ff4e31b"
+Logging = "56ddb016-857b-54e1-b83d-db4d58db5568"
 MacroTools = "1914dd2f-81c6-5fcd-8719-6d5c9610ff09"
 REPL = "3fa0cd96-eef1-5676-8a61-b3b8758bbffb"
 SafeTestsets = "1bc83da4-3b8d-516f-aca4-4fe02f6d838f"

test/runtests.jl

@@ -37,6 +37,7 @@ println("Starting tests with $(Threads.nthreads()) threads out of `Sys.CPU_THREA
 @doset "selfreferencing_functional"
 @doset "coverage_preservation"
 @doset "performance"
+@doset "logging"
 VERSION >= v"1.8" && @doset "doctests"
 VERSION >= v"1.8" && @doset "aqua"
 isempty(VERSION.prerelease) && VERSION >= v"1.12" && @doset "jet"

test/test_logging.jl

@@ -0,0 +1,93 @@
+using Logging
+using ResumableFunctions
+using Test
+
+mutable struct CaptureLogger <: AbstractLogger
+  records::Vector{NamedTuple}
+end
+
+Logging.min_enabled_level(::CaptureLogger) = Logging.Debug
+Logging.shouldlog(::CaptureLogger, _level, _module, _group, _id) = true
+Logging.catch_exceptions(::CaptureLogger) = false
+
+function Logging.handle_message(
+  logger::CaptureLogger,
+  level,
+  message,
+  _module,
+  group,
+  id,
+  file,
+  line;
+  kwargs...,
+)
+  push!(logger.records, (; level, message, group, metadata=(; kwargs...)))
+end
+
+@resumable function logging_generator()
+  round = 3
+  pair_id = 7
+  attempts = 2
+  @debug(
+    "Logging from a resumable function",
+    _group=:protocol,
+    event=:round_started,
+    round=round,
+    pair_id,
+    attempts,
+  )
+  @yield round
+end
+
+@resumable function qualified_logging_generator()
+  value = 4
+  Logging.@info(
+    "Qualified logging macro",
+    _group=:qualified,
+    event=:qualified_record,
+    value,
+  )
+  @logmsg(
+    Logging.Warn,
+    "Logging with an explicit level",
+    _group=:logmsg,
+    event=:logmsg_record,
+    value,
+  )
+  @yield value
+end
+
+@testset "structured logging metadata" begin
+  logger = CaptureLogger(NamedTuple[])
+  values = Logging.with_logger(logger) do
+    collect(logging_generator())
+  end
+
+  @test values == [3]
+  @test length(logger.records) == 1
+  record = only(logger.records)
+  @test record.level == Logging.Debug
+  @test record.message == "Logging from a resumable function"
+  @test record.group == :protocol
+  @test record.metadata == (
+    event=:round_started,
+    round=3,
+    pair_id=7,
+    attempts=2,
+  )
+
+  empty!(logger.records)
+  values = Logging.with_logger(logger) do
+    collect(qualified_logging_generator())
+  end
+
+  @test values == [4]
+  @test length(logger.records) == 2
+  qualified_record, logmsg_record = logger.records
+  @test qualified_record.level == Logging.Info
+  @test qualified_record.group == :qualified
+  @test qualified_record.metadata == (event=:qualified_record, value=4)
+  @test logmsg_record.level == Logging.Warn
+  @test logmsg_record.group == :logmsg
+  @test logmsg_record.metadata == (event=:logmsg_record, value=4)
+end