Logging proposal

[AdamClements]

Example:

(ns my.app)
(log-d "Hello, here is a map coll: " coll " and x: " x :exception err)

gives:

D/my.app (1234): Hello, here is a map coll: {:thing :other} and x: 45
D/my.app (1234):  ... Exception stacktrace

Other examples:

(log-d "This is tagged HELLO" :tag "HELLO")
(log-e :exception err)
(log-d "-- mark --")

The current logging setup really bothers me, this is my proposed alternative. Issues I have with the current implementation are:

• the logging methods as they stand are awkward to use - most common log commands need to wrap in a str or pr-str and it would be more idiomatic clojure to have a varargs function which can take any number of things that can be cast to a string and concatenate them.
• in a varargs function, it is highly un idiomatic to have the exception last in the list, most logging libraries I have seen put the optional exception first, but I've decided on end of list keyword arguments as you'll see
• I don't like (deflogfn "blah") - it tends to result in random naming, and generates a lot of functions that might not be required at all (all the different log levels). What about simply setting the tag to ns by default and exposing the version with tag if a different tag is required? Clojure namespaces tend to be a lot more concise than java package names anyway, so this seems reasonable to me. I have made it so that you can optionally pass in a :tag keyword argument if you want to set it explicitly for any reason.
• deflog pollutes the current namespace, my proposed solution doesn't. Plus macros that def things are generally a bad code smell.

I have left deflog for back compatibility and the two solutions work fine alongside one another (well, unless you try and use both in a namespace - due to the original issue of deflog polluting the namespace!), depending on the current back compatibility policy/upcoming version numbers though it might be best to remove it entirely if this solution does turn out to be preferable.

Potential future improvements:

• Debug logs should probably be compiled out of release builds completely - this means not doing any processing required to build the strings passed to the log function e.g. (log-d (generate-expensive-logging-info x)) shouldn't run the function. This means that the logging function itself should be a macro which checks release-build, however the release-build seems to be unbound in my debug builds, which is evaluating as truthy (???) and so my conditions weren't working. I don't know how this is handled in other places in the code? It might be that the variable just isn't bound in all the threads? Either way I have left this functionality out for now.

[alexander-yakushev]

I completely agree with you, Adam, that neko.log is just a filler rather than a substantial logging system. It was originally written by Daniel, I appended a few minor changes but never touched it significantly. Now perhaps is a good time to do it.

I like your proposal ideawise, but I find some of the implementation details questionable. Let me cover them step by step.

First, I don't like log-? functions being macros. If I understand correctly, the only reason for them to be is that namespace should be captured in compile-time. And it seems to be the only way to do it, so I probably have to deal with it.

Second, I would really just reuse existing d .. w functions to conform to the new calling interface. I find these log-? constructs awkward. They are only convenient when you :use a whole neko.log namespace, which is bad idea in the first place. Much better is to do something like this:

(ns foo.bar ...
  (:require [neko.log :as log]) ... )

(log/d "message")

That is much cleaner and follows Clojure guidelines (":require rather than :use").

Next, putting key-value arguments to the end along with varargs is clumsy, you said it yourself. I would put them in the beginning where they are easier to parse and belong better.

(log/e :tag "custom tag" :exception ex "Something really bad happened with " obj)

As for your last suggestion, it really should be done at some point. And the debug/release distinction is a beast that deserves a dedicated blogpost, so no wonder you had troubles with it, it is pretty voodoo:).

So at this point I can rewrite your PR myself (and faking a Sign-off from you if you don't mind, so that you can later be contacted as the idea author) or if you want these commits to get in personally from you, I welcome you to do it. What do you think?

And thank you for submitting this PR and writing this long nice description for it!

[AdamClements]

I agree on the naming, I was just trying to stay consistent with the existing methods as far as possible. As for putting the keyword arguments at the start, seems reasonable, keyword args and varargs don't really mix well either way, but at least it should be more consistent this way around.

The logging needs to be macros so that debugging logging can be entirely removed in release mode along with the calculation of the parameters. It also has the nice side effect that if you try and log a variable which happens to have the value :exception or :tag, it won't mess anything up.

I think everything else is fine. I'm happy for you to do it yourself, otherwise I'll try and find the time this week to make the suggested changes.

Adam

[AdamClements]

I have rewritten the pull request to drop the legacy functions and renamed the functions to simply e, w, d, etc.

The generated code is also simpler and doesn't incur any runtime cost as the previous version did - it expands to the java call with no function call cost or runtime choice between user provided tag and namespace.

I have left the keyword arguments at the end as I disagree that it's clearer to have them at the front. It's idiomatic for keyword arguments to go at the end (though I realise combining keyword arguments and varargs isn't idiomatic at all, so that's a bit moot but I couldn't think of a better way to do it that still keeps the simplest cases simple). It also wasn't obvious to me how to neatly pull the keyword arguments off the front of the list.

What do you think to this version?

[AdamClements]

I have been playing about with the possibility of removing this namespace entirely and instead simply writing an appender for taoensso.timbre

(def logcat-appender
  {:doc (str "Appends to android logcat. Obviously only works if "
             "running within the android runtime, either on a device "
             "or an emulator")
   :min-level :debug
   :enabled? true
   :async? false
   :limit-per-msecs nil
   :prefix-fn :ns
   :fn (fn [{:keys [level prefix throwable message]}]
         (if throwable
           (condp = level
             :error (android.util.Log/e prefix message throwable)
             :info  (android.util.Log/i prefix message throwable)
             :warn  (android.util.Log/w prefix message throwable)
             :debug (android.util.Log/d prefix message throwable))

           (condp = level
             :error (android.util.Log/e prefix message)
             :info  (android.util.Log/i prefix message)
             :warn  (android.util.Log/w prefix message)
             :debug (android.util.Log/d prefix message))))})

This has a couple of issues with aot compiled namespaces - namely the following need to be excluded as they actually belong in separate projects and aren't direct dependencies but have been bundled with the projects for convenience:

                             "leiningen.hooks.clj-stacktrace-test"
                             "taoensso.timbre.appenders.irc"
                             "taoensso.timbre.appenders.socket"
                             "taoensso.timbre.appenders.postal"
                             "taoensso.timbre.appenders.mongo"
                             "taoensso.timbre.appenders.rotor"
                             "taoensso.timbre.tools.logging"

And there is one more issue where the logging library tries to pass in a hostname (which we aren't using anyway) which fires Android's network on main thread guard, but I have worked around that with:

(alter-var-root (var taoensso.timbre/get-hostname) (fn [old] (constantly "AndroidHost")))

After that, simply enable the logcat appender, disable the :standard-out appender and make use of all timbre has to offer in a standard way.

The advantage here is that you can log from cross platform components and still see the results in a terminal or a log. This also has a number of profiling macros and various other useful things. Plus once your app is deployed, you can simply switch to a remote appender or an email appender and receive logs without having to read the logcat output!

What do you think? I have brought the above points to the attention of the timbre people to see if they would be willing to break those appenders into separate jars and maybe think about doing something about the hostname problem.

[alexander-yakushev]

OK, first things first.

I've committed your modified namespace b96b5f8f. Since pull request was very messy after all the variations, I didn't merge it, but just spliced all the changes into a single commit and took the liberty of masquerading its author. Hope you don't get mad:).

I now agree that :exception and :tag are better when they are at the end. The only thing to be careful about if user does something like this:

(e "foo" :tag "bar" "baz")

Odd number of arguments when trying to cast to a map will raise a confusing exception. I covered that point.

Now to your last proposal. I don't think it is a good idea to bundle such a complex logging library to Neko. I personally didn't grasp what the appender is and what is it for. It takes time to grok. Of course, it will be very nice if we can use this "timbre" library on Android. But users should learn it first and then use on Android, rather than being forced to from the beginning.

So I will try to roll out a primitive custom solution for eliding logs in release builds. But I welcome you to explore the timbre solution further and maybe blog somewhere about this discoveries. How does it sound?

[AdamClements]

Well you wouldn't need to grok the appender to use it - that was the entire implementation. To use it you'd just use the timbre library and do (error "This is an error") sorts of things.

The main advantage would be the cross platform re-use and the additional profiling and tracing macros (which allow you to do things like log the results of all the s-expressions making up a call). But yeah, adding it as a dependency to neko might be a bit much and I guess the user still has the option of pulling it in if they want.

So yes, all looks good to me, closing the pull request.