logary icon indicating copy to clipboard operation
logary copied to clipboard

how to flow execution context with middleware/messageFactory ?

Open lust4life opened this issue 7 years ago • 8 comments

write some middleware try to get something set by CallContext.LogicalSetData and Thread.CurrentPrincipal.Identity ..., and config them with logary use withMiddleware

middleware or messageFactory are called when send Message to targets. this is run by Hopac , is this the reason execution context is not captured ,so CallContext are not flow to them ?

is there any way to get these info ? i can create Message and set data i needed in my application code and pass it to the logger (through Logger.logSimple), this can work, but can not use Global Middleware set in logary at config time, and the api (LogEvent , Log) expose to csharp in CSharp.fs, these method accept a transform param (Func<Message, Message>), they have the same problem.

maybe this is not a problem in f#, but can we support something , make middleware/messageFactory called in the application code level, generate the message , and use Hopac just send the message to target, don't delay the middleware invoke time in the hopac ?

or any other suggestion ?

lust4life avatar May 14 '17 13:05 lust4life

That's a good question. The reason of Func is to defer execution as long as possible. Global static fields is generally not my cup of tea, but an easy way to fix it would be to allow loggers to initialise on the caller; the problem being that it's yet unknown at that point whether the message needs to be evaluated; because as you state yourself, you can always create the message at the call site.

If you're interested in these rather structural changes, perhaps consider working with me to complete the new version of logary that makes it much clearer where and when things are being evaluated?

PR: https://github.com/logary/logary/pull/219

haf avatar May 14 '17 14:05 haf

ok, i will check it later.

and maybe i misunderstanding someting,

seems its here to make middleware/facotry invoke in an hopac thread. i will test it later.

type PromisedLogger(name, requestedLogger : Job<Logger>) =
  let promised = memo requestedLogger

  /// Create a new `Logger` with the given name and `Job<Logger>` – nice to
  /// use for creating loggers that need to be immediately available.
  static member create (PointName contents as name) logger =
    if logger = null then nullArg "logger"
    if contents = null then nullArg "name"
    PromisedLogger(name, logger) :> Logger

  // interface implementations;

  interface Named with
    member x.name = name

  interface Logger with
    member x.logWithAck logLevel messageFactory =
      Promise.read promised
      |> Alt.afterJob (fun logger -> logger.logWithAck logLevel messageFactory)

    member x.log logLevel messageFactory =
      Promise.read promised
      |> Alt.afterJob (fun logger -> logger.logWithAck logLevel messageFactory)
      |> Alt.afterFun (fun _ -> ())

    member x.level =
      Verbose

lust4life avatar May 15 '17 15:05 lust4life

// Middleware at: // - LogaryConf (goes on all loggers) (through engine,and compose at call-site) // - TargetConf (goes on specific target) (composes in engine when sending msg to target) // - individual loggers (through engine,and compose at call-site)

https://github.com/logary/logary/blob/feature/live-wpc-reconfigure/src/Logary/Registry.fs#L181-L184

#219 will fix this issue. after that we can set some unique id for a request at a website through a global middleware. all log message generate through a web request, will have this ctx unique id. can offer some help like this : CorrelationManager.ActivityId

lust4life avatar Dec 05 '17 06:12 lust4life

This is what Logger.apply is used for.

haf avatar Dec 05 '17 13:12 haf

But yes, for statically resolved loggers, middleware is used on a per-process basis.

haf avatar Dec 05 '17 13:12 haf

yes , logger.apply can set it by manually, but this needs to use the same logger through the whole request.

https://github.com/SuaveIO/suave/issues/579 situation like this can not get work automatically. and solution like this can not work.

lust4life avatar Dec 05 '17 14:12 lust4life

 ftestCaseJob "log with scope" (job {
    let! (logm, out, error)  = Utils.buildLogManager ()
    let loggername = PointName.parse "logger.test"
    let lg = logm.getLogger loggername

    let s1 = logm.beginScope (lazy(box "scope-1"))
    do! lg.infoWithAck (eventX "1")
    do! logm.flushPending ()
    let outStr = clearStream out
    Expect.stringContains outStr "scope-1" "shoule have scope-1 as its scope"

    let s2 = logm.beginScope (lazy(box ("scope-2",2)))
    let newLogger = logm.getLogger (PointName.parse "logger.test.another")
    do! newLogger.infoWithAck (eventX "2")
    do! logm.flushPending ()
    let outStr = clearStream out
    Expect.stringContains outStr "scope-1" "shoule have scope-1 as its scope as well"
    Expect.stringContains outStr """["scope-2", 2]""" "shoule have scope-2 as its scope"

    do s2.Dispose ()
    do! newLogger.infoWithAck (eventX "scope 2 dispose")
    do! logm.flushPending ()
    let outStr = clearStream out
    Expect.stringContains outStr "scope-1" "shoule have scope-1 as its scope"
    Expect.isFalse (outStr.Contains("scope-2")) "shoule not have scope-2 as its scope"

    do s1.Dispose ()
    do! newLogger.infoWithAck (eventX "scope 1 dispose")
    do! logm.flushPending ()
    let outStr = clearStream out
    Expect.isNotRegexMatch outStr (new Regex("scope-\d")) "shoule not have scope value"

    do! logm.shutdown ()
})

#291 add LogScope (use AsyncLocal) to support this. different logger can get work automatically now (when using async with TPL),

lust4life avatar Apr 05 '18 16:04 lust4life

Related to #293 ?

haf avatar Apr 06 '18 10:04 haf