I recently wrote a cli tool using AsyncParsableCommand everywhere and sushichop/Puppy: A flexible logging library written in Swift as the logger. I noticed sometimes my last log was not running. This was due to puppy that uses Dispatch to dispatch to another queue.
I have not considered performance but to me it seams logical that a logger should be allowed to run some code async? But maybe this is not the case?
If my assumption that a logger should be able to run async is correct I propose to add a function to the LogHandler protocol.
Hi @doozMen, I've not looked deeper into the linked issue however the topic of an async log we have a well formed opinion about: it's not a good choice to make log async.
Async loggers generally should offload the "long work" away from the logged at location. Usually this ends up as "package up the message into a value, and enqueue it somewhere", to then be consumed and emitted by another thread. This can be made very efficient using lock-free queues etc.
One of the better examples of a good async logger is log4j's AsyncAppender: Log4j – Log4j 2 Lock-free Asynchronous Loggers for Low-Latency Logging Note what the benefits of such logging backend are: less impact on the application by lowering latency and by batching writes improving the overall throughput of such logger backend. This isn't as much about making the logging calls "async", but leveraging the concurrency of emitting log statements reap those benefits.
The fact that you'd be asking for an log(...) async signals to me that you'd be doing the asynchronous work (which I suspect ends up as network or file IO), on the calling task/thread. This is not what logger should be doing as you'd greatly impact the performance profile of the (potentially hot) code doing the logging.
I don't think adding async versions to the swift-log API would be the right thing to do, and we should probably have a look why you ended up asking for this -- it could point at a problem in Puppy.
I'll read the issue you linked to later in more detail, but from a quick skim it seems you've encountered the main() function exiting and you "losing" a log statement? That is expected to be honest, and you should structure your application to not exit "until it is safe to do so" so if your intent is to always flush all messages, there should be some form of await puppy.gracefulShutdown() or similar.
We are going to provide more guidance about such application lifecycle patterns -- and @FranzBusch has been working on a document leading towards such guidance, but that's the gist of it. I'm also going to be looking at async main semantics, but I don't think any of those change the async log story.
My issue was that the use of Dispatchqueue.global.async { } was hidden inside the log function.This made the logs as you describe offload the work to queue but puppy lacs to my understanding the await puppy.gracefulShutdown() which seams to me to be the underlying issue.
As for my question to have an async function to log. This was me looking for a way to express, like you describe, to send but don't wait in the current context. As I understand now this does not seam possible with the current async await.
What I like about async await is that it lets you express that there is async work going on in a function and that this cannot be hidden.
So the way I end up using the logs in my code is using async let but this becomes very verbose.
#!/usr/bin/env swift
import Foundation
let mainTask = Task {
let work = Task {
// do some work
await logger.logAsync("Log some small amount")
// continue
}
async let workResult: () = work.value
async let heavyLog: () = log.logAsync("large log ...")
await _ = [workResult, heavyLog]
}
await mainTask.value
await logger.logAsync("all work including async logs done")
So what I'm missing is indeed the await puppy.gracefulShutdown() and a way for a function to express that it is doing work that will finish without waiting.
func log() parallel
So unlike await you would need to call this function with queue
queue log()
Queue would be a special global or something that you could wait for.
\\ do some other work in main
await queue.finished
Which could or could not return a value.
I hope this clarifies my need? I just expressed my first naive intension with async/await. No clue if it is something that is logical to others too.
But thanks very much for both of your clear explanation of the problem. I think I can find a workaround now for puppy.
@doozMen
Sorry for the late response. I jumped here from my GitHub repository's issue
In short, did you encounter the main function process ending before the logging process was finished?
TBH, this was expected behavior for me as @ktoso said and I originally thought that the application should handle it😅
However, it is also true that I did not write this idea in the README...
Now, my understanding is that what you are asking for is a way to know that the logging process is complete. For example, you want a method to know about the above notification or to flush the log message, right?
I have just recently received a similar request, and I will add an optional feature of the library when I have time to spare.
I indeed want a way to know that the logging completed. So in short await puppy.isDone() like I did in my PR would be all that is needed.
I will close the PR I made and let you handle it then.
I hope @ktoso can convince the swift community of a way to express that a function runs async and ordered but that you do not want to wait for it in the current context.
Until then I work with the workaround FIFOQueue that I found on Github. But please @sushichop let me know if you have a solution so I do not have to point my work related code to my personal fork for to long.Thanks
