Introduce basic approach to concurrent log writing. #45

qnikst · 2018-10-01T23:29:32Z

Introduce two approaches for concurrent log writing
and basic utilities for working with concurrent logs.
Two approaches are needed in order to allow user to
chose between generality and speed, though approaches
were not benchmarked to check the hypothesys.

qnikst · 2018-10-01T23:30:48Z

I'm not sure about the best approach here, so I came with two, both seem to make sense and can be further extended. It's really hard to get into the trap of overgeneralization here :/

chshersh

Thank you very much, @qnikst! This looks sooo great! I highly appreciate your effort on this issue! I left some comments, but mostly they are questions. I'm totally okay with having different strategies for concurrency. The co-log library is very young, so it's okay to have different ways for doing things and figure out the best one later.

My another concern is about function like fileLogAction:

https://github.com/kowainik/co-log/blob/695a27fe0111918d2e810c9170a2388015595fd9/co-log/src/Colog/Actions.hs#L70-L72

I'm not sure it will work properly if multiple threads try to write concurrently to the same file using the same Handler. Though, I assume we could add one bracket-style combinator on top of the forkBackgroundLogger:

withBackgroundLogger :: Natural -> LogAction IO msg -> (LogAction IO msg -> IO r) -> IO r

chshersh · 2018-10-02T04:06:47Z

co-log/src/Colog/Concurrent.hs

@@ -0,0 +1,129 @@
+-- |
+-- Sometimes an application may need to dump logs asynchonously.


The documentation for this module is super cool!

chshersh · 2018-10-02T04:20:30Z

co-log/src/Colog/Concurrent.hs

+-- @
+--
+-- This code will run a background thread and process different
+-- loggers in that thread.


Maybe add some note like This can be useful if logging a single message requires some computation? Or general guideline when people might want to use concurrent logging. I personally aware only of the cases when people might not want to use concurrent logging due to some subtle concurrency issues. But it's still very useful.

Ok, will add a note and more comments about use-cases and warnings.

chshersh · 2018-10-02T04:24:41Z

co-log/src/Colog/Concurrent.hs

+-- $worker-thread
+-- Worker thread approach allows to create a single worker
+-- thread that will perform all logging. This approach allows
+-- user to use different loggers and change them on the flight.


and change them on the flight

That's a really cool feature — to be able to replace logging function with different one. Am I right that it's possible to do something like this: implement simple program that prints messages every second in some format A and listens input and after user gives some input to this program it instantly starts to print messages in format B?

Also, it's not that clear from existing documentation and code, how to replace current logging function with different one on the flight...

OK, I see a problem, will discuss.
But I think I'll discuss the direct passing of the log action, and leave Colog.Monad approach aside.

chshersh · 2018-10-02T04:26:26Z

co-log/src/Colog/Concurrent.hs

+-- @
+-- bracket ('mkBackgroundThread' 4096)
+--         ('killBackgroundThread')
+--         $ \thread -> 


Looks like thread variable in the documentation should be named as worker according to the code below

chshersh · 2018-10-02T04:32:57Z

co-log/src/Colog/Concurrent.hs

+-- write logs will be blocked.
+mkBackgroundThread :: Int -> IO (BackgroundWorker (IO ()))
+mkBackgroundThread capacity = do
+  queue <- newTBQueueIO (fromIntegral capacity)


I see that newTBQueueIO function takes Natural in stm-2.5.0.0. Maybe it's a good idea to have stm ^>= 2.5.0.0 in build-depends in that case and pass Natural to the mkBackgroundThread function as well? Also, probably it's not enough to have stm >= 2.4 because stm-2.4.5.1 contains very important bugfix for TBQueue:

Please release the fix to the "flushTBQueue" bug! haskell/stm#16

I even expect from GHC to give you warning about fromIntegral usage after you change type from Int to Natural because we have -Widentities warning enabled for co-log.

It's up to you. As far as I understand stm-2.5.0.0 will cut many older GHC's, in the case if you want to support 3 major versions then it's not an option. And I find it's easer to keep the same interface for all versions then doing CPP magic to provide the best option for each version.

chshersh · 2018-10-02T04:36:26Z

co-log/src/Colog/Concurrent.hs

+-- | Create a background worker with a given capacity.
+-- If capacity is reached, then the thread that tries to
+-- write logs will be blocked.
+mkBackgroundThread :: Int -> IO (BackgroundWorker (IO ()))


Input message as IO () looks interesting 🤔 I wonder how useful such simple LogAction could be:

idLogAction :: LogAction m (m ()) idLogAction = LogAction id

I'm not very good at CT to find what that object will be and derive a use-case for that based on that knowledge. Right now I don't see how it can be used :/

chshersh · 2018-10-02T04:39:01Z

co-log/src/Colog/Concurrent.hs

+-- Logger is executed in the other thread entirely, so if
+-- logger takes any thread related context it will be
+-- read from the other thread.
+runInBackgroundThread :: BackgroundWorker (IO ()) -> LogAction IO msg -> LogAction IO msg


It's possible to have the result type of runInBackgroundThread function to be MonadIO m => LogAction m msg but I wonder how useful it can be. Whole current API is built on top of the plain IO and the only sensible generalisation that I know involves MonadUnliftIO but I'm not sure it's a good idea to bring MonadUnliftIO now.

It can be useful, because that way you may provide useful capabilities there. But I'm uneasy with that change, currently, there are a number of different approaches that allow such generalizations:

MonadUnliftIO and unliftio ecosystem in general

monad-control that is still widely used

MTL-heavy libraries that are using MTL as final tagless system

a family of the effects systems.

direct handle approach

Making a preference to the one system other the others may be a bad thing, as it increases dependencies set and makes people used to other systems uneasy when using your library.

And IO on it's own is very powerful and composable type, in general with any of the approaches mentioned above you can write LogAction IO msg and "unlift" your system to those. So basically you need unlift :: SomeConstraints m => LogAction m msg -> LogAction IO msg that will be called in the parent thread.

Okay, I can just add liftLogIO :: MonadIO m => LogAction IO msg -> LogAction m msg to co-log-core to make life of users easier. So they have some way accessible without extra dependencies introduced.

chshersh · 2018-10-02T04:41:17Z

co-log/src/Colog/Concurrent.hs

+-- takes a 'LogAction' that should describe how to write
+-- logs.
+--
+-- @capability@ - parameter tells how many in flight messages


This variable called capacity in multiple places, so probably it's a good idea to name it capacity here as well instead of capability.

chshersh · 2018-10-02T04:43:29Z

co-log/src/Colog/Concurrent.hs

+-- @capability@ - parameter tells how many in flight messages
+-- are allowed, if that value is reached then user's thread
+-- that emits logs will be blocked until any message will be
+-- written.


I think alternative strategy is to drop all log messages after reaching the limit. But I agree with making current behavior the default one. Probably in production it's more important to lose some performance and hang for a while rather than losing important logs about what is actually going on within the running system.

I think I'll add some docs and expose more internal so users will be able to define such strategies on their own. I don't like dropping messages, it should be some very special use-case. If you have too many logs so you can't dump them, it means that your environment has some severe problems that should be solved anyway.

chshersh · 2018-10-02T04:45:48Z

co-log/src/Colog/Concurrent.hs

+  queue <- newTBQueueIO (fromIntegral capacity)
+  tid <- forkIO $ forever $ do
+    msg <- atomically $ readTBQueue queue
+    unLogAction logAction msg


Btw, just general question. Would you appreciate some fancy operator for unwrapping LogAction newtype? So instead of

unLogAction logAction msg

you could write something like:

logAction <| msg

Or probably have shorter alias for unLogAction to partially apply logAction in more convenient way?

toLogFun logAction :: msg -> m ()

that may be useful, but in internals, I like to use the full name. So it was not difficult for me to write unLogAction

qnikst · 2018-10-02T20:23:34Z

With any of those approaches withLogByteStringFile is fine as long as you reuse the same worker because logging is happening in the single thread. But, it's possible to craft bad examples, for example, if you use withLogByteStringFile directly and using background thread or two different workers, then you may have a problem. I think I'll have to add more documentation and rationale about that.

Just a bit of discussion while I'm trying to prepare myself for addressing the comments :). In general, we have two types of concurrency possible, I'll call them depth and width concurrency.

depth concurrency, is a way to provide a concurrency between the application thread and logger thread. With this kind of concurrency, the application thread is doing a bit of job (usually CPU bound) and then send prepared messages to the logger, then logger is doing a heavier job of serializing a message and sending that to the sink (usually I/O bound). With this kind of concurrency we increase a throughput of the application and balance our bounds, this if very relevant if you log your data to some external application over the network. This is what my PR was about. There are some tradeoffs on that path:
a. memory usage (if the worker is very slow and the communication channel is unbound then we can get too many messages on the channel). (This is solved in the PR by providing configurable capacity)
b. persistence - some actions may care that the logs they emit are actually persisted before they continue. With the concurrent approach, you may lose all the messages that are kept on the channel. This is not solved though can be solved by the user as we provide all required internals. (I'd tell that this use-case is bad and the user should use other techniques in that case, but this use-case exists).
width concurrency - in case if you mappend many actions you may want to run them concurrently, something that parallel strategies may shine at if logActions were pure. This is completely unsolved in my PR and left to the user.

qnikst · 2018-10-02T22:54:16Z

@chshersh, please take another look, I've reworked my branch, fixed few concurrency issues and improved documentation.

chshersh

The example documentation is super cool! I really liked the ASCII schema ❤️ I have some comments to the Haddock, but mostly looks great 👍

chshersh · 2018-10-03T07:38:01Z

co-log/src/Colog/Concurrent/Internal.hs

+
+-- | A wrapper type that carries capacity. The internal
+-- type may be differrent for the different GHC versions.
+#if MIN_VERSION_base_noprelude(4,12,0)


Probably here you should specify MIN_VERSION_stm_(2,5,0). Currently Travis CI is failing for cabal-install and GHC 8.4.3.

chshersh · 2018-10-03T07:39:01Z

co-log/src/Colog/Concurrent.hs

+-- affected or not.
+--
+--   1. Unbounded memory usage - if there is no backpressure mechanism
+--   the the user threads, they may generate more logs that can be


Double the. Probably a typo

chshersh · 2018-10-03T07:39:37Z

co-log/src/Colog/Concurrent.hs

+--
+--   1. Unbounded memory usage - if there is no backpressure mechanism
+--   the the user threads, they may generate more logs that can be
+--   written in the same about of time. In those cases messages will


Maybe here you wanted to say in the same amount of time?

chshersh · 2018-10-03T07:45:32Z

co-log/src/Colog/Concurrent.hs

+--      $ 'Colog.Monad.usingLoggerT' $ __do__
+--         'Colog.Monad.logMsg' "Starting application..."
+--   where
+--     logger = 'Colog.Action.withLogByteStringFile' "/var/log/myapp/log"


I see that this line wasn't rendered properly with Haddock (because of weird Haddock markup syntax). Probably replacing every / with \/ should help.

chshersh · 2018-10-03T07:54:14Z

co-log/src/Colog/Concurrent.hs

+-- main =
+--   'withBackgroundLogger'
+--      'defCapacity'
+--      (Aeson.encode `'cmap'` logger)


Somehow cmap doesn't render properly with Haddock 🤔

I found this blog post with common suggestions for Haddock extremely useful!

https://artyom.me/haddock-mistakes

But there's no such case for this situation...

\``Core.Action.cmap`\`

seems to work

chshersh · 2018-10-03T07:55:54Z

co-log/src/Colog/Concurrent.hs

+           (killBackgroundLogger)
+           (action . convertToLogAction)
+
+-- | Default capacity size.


Maybe say in the documentation that it's equal to 4096? Because on Hackage you can't see the source code without clicking Source link. This might be useful piece of information. We only need to not forget to update it after the value changes.

chshersh · 2018-10-03T07:59:54Z

co-log/src/Colog/Concurrent.hs

+-- $background-logger
+--
+-- Background logger is specialized version of the 'BackgroundWorker' process.
+-- Instead of running any jobu it will accept @msg@ type


jobu probably a typo

Introduce two approaches for concurrent log writing and basic utilities for working with concurrent logs. Two approaches are needed in order to allow user to chose between generality and speed, though approaches were not benchmarked to check the hypothesys.

qnikst · 2018-10-03T18:23:24Z

I hope I've fixed CI and typos.

chshersh

This looks super cool!

qnikst mentioned this pull request Oct 1, 2018

Implement combinator that makes IO action concurrent #10

Closed

chshersh requested review from chshersh and vrom911 October 2, 2018 03:38

chshersh assigned qnikst Oct 2, 2018

chshersh added enhancement New feature or request log-action Everything related to LogAction data type labels Oct 2, 2018

chshersh added this to In progress in #2: Hacktoberfest (October, 2018) via automation Oct 2, 2018

chshersh reviewed Oct 2, 2018

View reviewed changes

chshersh added the package:co-log For: co-log label Oct 2, 2018

chshersh reviewed Oct 3, 2018

View reviewed changes

chshersh approved these changes Oct 4, 2018

View reviewed changes

#2: Hacktoberfest (October, 2018) automation moved this from In progress to Reviewer approved Oct 4, 2018

chshersh added the Hacktoberfest https://hacktoberfest.digitalocean.com/ label Oct 4, 2018

chshersh merged commit f19aa28 into co-log:master Oct 4, 2018

#2: Hacktoberfest (October, 2018) automation moved this from Reviewer approved to Done: PR's Oct 4, 2018

chshersh removed this from Done: PR's in #2: Hacktoberfest (October, 2018) Sep 29, 2021

		@@ -0,0 +1,129 @@
		-- \|
		-- Sometimes an application may need to dump logs asynchonously.

Introduce basic approach to concurrent log writing. #45

Introduce basic approach to concurrent log writing. #45

Conversation

qnikst commented Oct 1, 2018

qnikst commented Oct 1, 2018

chshersh left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

qnikst Oct 2, 2018 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

qnikst commented Oct 2, 2018

qnikst commented Oct 2, 2018

chshersh left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

qnikst commented Oct 3, 2018

chshersh left a comment

Choose a reason for hiding this comment

qnikst Oct 2, 2018 •

edited