How do you use an agent and core.async to properly log asynchronously in Clojure?

Question

In the following code, I am using a go loop that listens in on a channel and writes the values it reads to an agent. Then, in the same loop, the log-to-file function is supposed to write each item on the agent to a file. The output to the file is unusual, however, as an agent with [8 6 5 13] might have its contents spit to the file as 865n13. If i remove the log-to-file call from the logger function and call it separately, sometimes the file output is fine sometimes not. Could somebody just explain to me what is going on and possibly show me a safe way to do this that demonstrates consistent behavior? I am aware that not using an agent would probably be the best way to achieve consistent behavior. I just want to know, in the spirit of learning, what is and isn't possible to achieve with agents. Thanks in advace!

(defn log-to-file [file] (for [i (deref log)] (spit file (str "\n" i) :append true)))

(defn logger [file]
  (go 
   (loop []
     (when-let [v (<! print-chan)]
       (send log conj v)
       (log-to-file file)
       (recur)))))

;; testing it out

(def log (agent []))
(>!! print-chan 5)
(logger "resources/test.txt")
(deref log)

EDIT:

This is the code rewritten in light of the comments in the accepted answer below. I do not recommend using this code at all, or for that matter ever using an agent in a go loop with side-effects.

(def ch (chan))
(def a (agent []))

(defn double-async-print []
    (go-loop []
       (when-let [x (<! ch)]
         (send a conj x)
         (print (clojure.string/join "\n" @a)))
     (recur)))

(go (doseq [n (range 10)] (>! ch n)))

(double-async-print) 

    ;=>jsync 0.1.0-SNAPSHOT[stdout]:    
    00
    10
    1
    20
    1
    2
    30
    1
    2
    3
    40
    1
   ...

score 3 · Accepted Answer · edited May 23 '17 at 12:05

3

I suspect there are a number of things going on which are interacting to cause your confusion. It isn't the use of an agent inside a go-loop that is the problem per se.

send is asynchronous, so there is no guarantee that your call to deref in log-to-file will see the change at the time log-to-file is called inside the loop.

Also you are incorrectly using for with side-effecting code (file io with spit). It looks like you are trying to use it analogously to an imperative for-each loop in other languages. doseq is the correct clojure construct for processing a sequence for side-effects (see: Difference between doseq and for in Clojure).

You also do nothing to remove the content of the vector being built up in the agent so even if things were running synchronously you would for example get on adding :a, :b and :c one at time an output in the file like:

:a
:a
:b
:a
:b
:c

It is not clear from the question if that is the behavior you expect from your code.

An aside on clojure.string/join:

As a general point using spit as above is very inefficient even if you were correctly using doseq if you just wish to output a vector or other collection to a newline separated file. It is much better to use clojure.string/join e.g.

user>  (print (clojure.string/join "\n" [:a :b :c :d]))
:a
:b
:c
:d

You can use the pprint function to see what the string actually passed to print looked like with escaping (pprint is much more general that just this use and gives a nice visual format to all sorts of clojure data):

user> (clojure.pprint/pprint (clojure.string/join "\n" [:a :b :c :d]))
":a\n:b\n:c\n:d"

edited May 23 '17 at 12:05

Community

1
1

answered May 13 '14 at 14:22

Alex Stoddard

8,244
4
41
61

Thanks Alex, your answer is really helpful. I forgot that you should not use for with side-effecting code. and I will do the agent vector update after this. One last request though, would you edit your answer to show an example of how clojure.string/join would make the write more efficient? – kurofune May 13 '14 at 15:07
Can do. Incidentally the `for` should never have produced any side effect in a non-interactive environment because `for` produces a lazy-seq. I see from your other [question](http://stackoverflow.com/questions/23600387/how-do-you-write-to-a-log-file-in-clojure-using-core-async) that you are using LightTable. The LT inline evaluation is probably part of why it appeared to almost work. – Alex Stoddard May 13 '14 at 16:22
It also looks like you are trying to use the agent to force mutable state and imperative looping back into your code. This is very much an anti-pattern in clojure. Beyond just experimenting I can see no good reason for wanting or needing to mix two different asynchronous mechanisms within a single logic loop. – Alex Stoddard May 13 '14 at 16:25
Thank you for all of your feedback. I am just experimenting, but still at a stage where I don't know what is idiomatic for "real world" applications. I can't tell from your example how the clojure.string/join is writing to an outside file, though. Or are you saying that this is the inefficient part? – kurofune May 13 '14 at 22:48
You are right. I'm not showing writing to an external file, but print is equivalent to one write (underneath the hood it is calling append on a java.io.PrintWriter called *out* at the repl.) Building a single string for output in a StringBuffer (as used by clojure.string/join) is much better than iterating over a collection and calling str multiple times. – Alex Stoddard May 14 '14 at 16:23
Right on. I have rewritten the code in an edit in my above post. Please have a look and tell me if I am getting your points clearly. – kurofune May 15 '14 at 03:50
You got the points with doseq and the string join. I don't know if you got the point on `send` to an agent being asynchronous. Agents are entirely orthogonal to the mechanisms of core.async, the go block won't do anything to synchronize agent use. `send` is non-blocking and the function to update the agent (simply `conj` in your example) is run on a separate thread at an indeterminate time. The deref @a in the go loop even though it appears to happen after the `send` lexically may happen before the update chronologically. – Alex Stoddard May 15 '14 at 14:13
Okay, it's all coming together now. I get that the agent being asynchronous implies other threads and a chronological lack of guarantee. I should definitely study more though about blocking/non-blocking, etc. Thanks for all of your help. You'll probably see my next question up here soon ;) – kurofune May 15 '14 at 15:20

How do you use an agent and core.async to properly log asynchronously in Clojure?

1 Answers1