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
   ...

Answer 1

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"