(→ Stranded Between Parens)

The Lambda Island Blog

ClojureScript logging with goog.log

This post explores goog.log, and builds an idiomatic ClojureScript wrapper, with support for cljs-devtools, cross-platform logging (by being API-compatible with Pedestal Log), and logging in production.

This deep dive into GCL’s logging functionality was inspired by work done with Nextjournal, whose support greatly helped in putting this library together.

Clojure’s standard library isn’t as “batteries included” as, say, Python. This is because Clojure and ClojureScript are hosted languages. They rely on a host platform to provide the lower level runtime functionality, which also allows them to tap into the host language’s standard library and ecosystem. That’s your batteries right there.

On the JVM that means you get to use the thousands of classes from Java SE. In ClojureScript you can access browser or Node.js APIs, or you can make use of the many gems hidden in the Google Closure Library.

The Google Closure What?

Ok this one is always a little awkward to explain. These three things are different but related:

  1. The ClojureScript Compiler
  2. The Google Closure Compiler (GCC)
  3. The Google Closure Library (GCL)

The ClojureScript Compiler takes ClojureScript sources and turns them into JavaScript. Easy enough.

The Closure Compiler is a optimizing JavaScript-to-JavaScript compiler from Google. It’s really good at what it does, but in order to do its job your JavaScript has to be structured in a certain way, so that it’s amenable to static analysis.

Coincidentally the ClojureScript compiler generates JavaScript in the format that the Google Closure Compiler expects, and all ClojureScript tooling can invoke the Google Closure Compiler for you. You just need to tell it which optimization level you want (whitespace, simple, or advanced).

Finally the Google Closure Library is nothing but a big JavaScript library (or a collection of libraries, if you will), again written to be easily optimizable by the GCC. It’s the batteries! The nice thing is that ClojureScript already makes use of the GCL, so you can count on it being available.

GCL was originally written when developing GMail, and it powers a lot of Google products. Here’s how Google puts it:

The Closure Library is a broad, well-tested, modular, and cross-browser JavaScript library. You can pull just what you need from a large set of reusable UI widgets and controls, and from lower-level utilities for DOM manipulation, server communication, animation, data structures, unit testing, rich-text editing, and more.

The Closure Library is server-agnostic, and is intended for use with the Closure Compiler.

A Treasure Cave

There’s a lot of really usefull stuff in there, but unfortunately it’s not terribly discoverable or well documented. The best resource you’ll find on-line is the generated API documentation, which rarely explains the why or how. There’s an O’Reilly book from 2010 that covers both the GCC and the GCL. If you really want comprehensive documentation that is really your only option at the moment.

Which is unfortunate because there really is a ton of gold in there, but at least it’s open source so we can stumble through the sources trying to find the things we were looking for. That’s what I recently did for goog.log, the logging functionality provided by the GCL. In this blog post I’ll walk you through the various things you can do with goog.log, and create an idiomatic ClojureScript wrapper while I’m at it.

Getting started

Giving your library a Finnish name is all the rage these days, so I’m going with Glögi (am I doing this right?). There will be macros involved, which is always a bit mind-wrenching in ClojureScript, but we’ll use the macro sugar trick, so that consumers of the library don’t have to care.

For the main API I will mimic io.pedestal.log, with trace, info, debug, warn, and error macros, which take a sequence of key-value pairs.

Macros go in a .clj files, since macroexpansion happen during compilation, which is executed by Clojure (the ClojureScript compiler is written in Clojure).

;; src/lambdaisland/glogi.clj
(ns lambdaisland.glogi)

(defmacro trace [& _])
(defmacro info [& _])
(defmacro debug [& _])
(defmacro warn [& _])
(defmacro error [& _])

ClojureScript functions go into glogi.cljs. This is the actual ClojureScript library that we’ll require from other ClojureScript namespaces. By doing a :require-macros with the same namespace name the macros we defined in glogi.clj will become available as well.

;; src/lambdaisland/glogi.cljs
(ns lambdaisland.glogi
  (:require-macros [lambdaisland.glogi]))

(defn logger [name] ,,,)

Now you can require this like any other namespaces, and access both functions and macros.

;; src/lambdaisland/glogi/demo.cljs
(ns lambdaisland.glogi.demo
  (:require [lambdaisland.glogi :as log]))

(log/warn :oh "no")

(log/logger "acme.widget.factory")

Our first logger

Alright, let’s see if we can get this thing to log something. Load the goog.log and goog.debug.Logger namespaces, create a Logger object, and call the warning function, passing it the logger and a message.

(ns lambdaisland.glogi ;;.cljs
  (:require [goog.log :as glog]
            [goog.debug.Logger :as Logger])
  (:require-macros [lambdaisland.glogi]))

(glog/warning (glog/getLogger "lambdaisland.glogi") "oh no!")

Now you may or may not have seen this log message pop up in your browser console:

[976.053s] [lambdaisland.glogi] oh no!

If you didn’t that’s probably because there are no “log handlers” installed yet. Like a lot of logging systems goog.log separates log producers and consumers. We may be producing log messages, but no one is consuming them.

goog.log comes with several possible consumers out of the box, the most straightforward one is the goog.debug.Console which logs, you guessed it, to the browser console. If you’re using Figwheel (which of course I recommend), then Figwheel will have enabled this console logger already, but otherwise you need to do it yourself, by instantiating it, and setting .setCapturing to true.

(ns lambdaisland.glogi
  (:require [goog.log :as glog]
            [goog.debug.Logger :as Logger]
            [goog.debug.Logger.Level :as Level]
            [goog.debug.Console :as Console])
  (:import [goog.debug Console FancyWindow DivConsole])
  (:require-macros [lambdaisland.glogi]))

(.setCapturing (Console.) true)

Alternatively you can use Console/autoInstall. This function will check for the presence of the string "Debug=true" in the URL (mind the case), so you can enable logging on demand.

(Console/autoInstall)

There are a few other options, you can log to a DOM element with DivConsole, or to a separate browser window with FancyWindow (make sure to allow pop-ups).

With present day browser consoles these aren’t that useful perhaps, although the FancyWindow one has some cool options to change the log level for each logger individually.

(.setCapturing
 (DivConsole.
  (js/document.getElementById "app"))
 true)

(.setEnabled (FancyWindow.) true)

I’ve wrapped all these options in helper functions, so a simple call to glogi/enable-console-logging! should be all you need.

Logger hierarchy

You may have noticed I gave the logger the same name as the namespace. This is a good practice to follow, because loggers are hierarchical. They inherit their log level from their parent logger, which is obtained by dropping the last segment from the dotted name. So the parent of the acme.widget.factory logger is the acme.widget logger.

(defn logger
  "Get a logger by name, and optionally set its level."
  ([name]
   (glog/getLogger name))
  ([name level]
   (glog/getLogger name level)))

(def child1-logger (logger "acme.widget.factory"))
(def child2-logger (logger "acme.widget.sales"))
(def parent-logger (logger "acme.widget" Level/FINE))
(def other-logger  (logger "acme.trinket" Level/WARNING))

(glog/info child1-logger "this gets logged")
(glog/info child2-logger "this too")
(glog/info other-logger "this doesn't")

;; [190607 16:50:02.49] [1175.643s] [acme.widget.factory] this gets logged
;; [190607 16:50:02.50] [1175.650s] [acme.widget.sales] this too

If a logger doesn’t have a log level set, and neither does any of its ancestors, then the log level of the “root logger” is used. You can access the root logger by using an empty string for the logger name.

(def root-logger (logger ""))

The log level is represented by a simple JavaScript object, which has a name and a value

(.-name Level/FINEST)
;; => "FINEST"

(.-value Level/FINEST)
;; => 300

There’s not much reason to create your own Level objects, instead there are a bunch of predefined constants you can use. For our own API it would be nice if we could simply reference these with a keyword, so I’ll set up a mapping for that.

Now the log and set-level functions are starting to feel a bit more like a ClojureScript API.

(def level
  {:off     Level/OFF
   :shout   Level/SHOUT
   :severe  Level/SEVERE
   :warning Level/WARNING
   :info    Level/INFO
   :config  Level/CONFIG
   :fine    Level/FINE
   :finer   Level/FINER
   :finest  Level/FINEST
   :all     Level/ALL

   ;; pedestal style
   :trace Level/FINE
   :debug Level/CONFIG
   :warn  Level/WARNING
   :error Level/SEVERE})

(defn log
  "Output a log message to the given logger, optionally with an exception to be
  logged."
  ([name lvl message]
   (log name lvl message nil))
  ([name lvl message exception]
   (glog/log (logger name) (level lvl) message exception)))

(defn set-level
  "Set the level (a keyword) of the given logger, identified by name."
  [name lvl]
  (assert (contains? level lvl))
  (.setLevel (logger name) (level lvl)))

(set-level "acme.widgets" :debug)
(log "acme.widgets" :debug "There's a problem with the widgets.")
;; [190610 16:55:03.99] [674.672s] [acme.widgets] There's a problem with the widgets.

Macro Magic

Now we can finish our library by adding the macros which all call down to this log function. As mentioned this API is largely inspired by io.pedestal.log. The idea here is that log messages are just events, and so they should be machine readable as well as human readable.

These logging macros all take a sequence of key value pairs, which get logged in the form as a map.

;; glogi.clj

(defn- log-expr [form level keyvals]
  (let [keyvals-map (apply array-map keyvals)
        formatter (::formatter keyvals-map 'pr-str)]
    `(log ~(::logger keyvals-map (str *ns*))
          ~level
          (~formatter
           ~(-> keyvals-map
                (dissoc ::logger)
                (assoc :line (:line (meta form)))))
          ~(:exception keyvals-map))))

(defmacro trace [& keyvals]
  (log-expr &form :trace keyvals))

(defmacro debug [& keyvals]
  (log-expr &form :debug keyvals))

(defmacro info [& keyvals]
  (log-expr &form :info keyvals))

(defmacro warn [& keyvals]
  (log-expr &form :warn keyvals))

(defmacro error [& keyvals]
  (log-expr &form :error keyvals))

If you’re not used to macros then this probably looks pretty dense, with the backtick and all the tildes (in this context called “unquote”). The cool thing is that by using macros we can extract the current namespace and line number, using *ns* and (:line (meta &form)) respectively. So now log messages automatically use a logger based on the namespace. This way loggers respect namespace hierarchy, and so you can enable or disable logging for a subtree of namespaces by changing the log level of a single shared parent logger.

(ns lambdaisland.glogi.demo
  (:require [lambdaisland.glogi :as glogi]))

(glogi/enable-console-logging!)

(glogi/warn :msg "oh no!")
;; [190610 17:24:50.61] [2461.288s] [lambdaisland.glogi.demo] {:msg "oh no!", :line 6}

I’ve incorporated a few other features borrowed from Pedestal.log. You can pass an exception in with the :exception key, and it will be passed down to goog.log with the optional exception argument, so that you get a proper stack trace in the console.

You can pass in a custom formatter or use a different logger name as well with :lambdaisland.glogi/formatter (defaults to identity) and :lambdaisland.glogi/logger (defaults to the name of the current namespace).

The cool thing is that now in CLJC (cross-platform) code you can do this.

(ns my.project
  (:require [#?(:clj io.pedestal.log
                :cljs lambdaisland.glogi) :as log]))

(log/info :this "works everywhere!")

Registering a handler

At the top of the post I pointed out that goog.log separates log produces from log consumers. These consumers are known in goog.log as handlers, they are functions that receive log events to handle. So Console or FancyWindow will all install a handler that takes care of actually displaying the log messages.

You can do cool things with this, you could for instance send them back to the server, or capture all messages arriving while inside a certain function, to analyze later.

Handler are scoped similar to levels, meaning each logger inherits its handlers from its chain of ancestors. Typically you add handlers to the root logger, but you could also add them to only a subset of loggers, like all the ones that start with the name of your project.

(defn add-handler
  "Add a log handler to the given logger, or to the root logger if no logger is
  specified. The handler is a function which receives a map as its argument."
  ([handler-fn]
   (add-handler "" handler-fn))
  ([name handler-fn]
   (.addHandler (logger name)
                (fn [^LogRecord record]
                  (handler-fn {:sequenceNumber (.-sequenceNumber_ record)
                               :time           (.-time_ record)
                               :level          (keyword (str/lower-case (.-name (.-level_ record))))
                               :message        (.-msg_ record)
                               :logger-name    (.-loggerName_ record)
                               :exception      (.-exception_ record)})))))

Using with cljs-devtools

Kudos to Martin Kavalar of Nextjournal for coming up with the LogBuffer trick.

People using devtools might have been a bit underwhelmed by the result, because goog.debug.Logger will automatically stringify the message argument, so when you try to log data structures they are simply logged as strings, meaning you lose the nice formatting and interactive navigation that cljs-devtools provides.

To work around this we need to step away from goog.debug.Console, since that one uses its own string formatter under the hood, and we need to convince goog.debug.Logger to not call js/String on its message argument.

Digging around the sources you’ll see that if you enable the goog.debug.LogBuffer, then the message argument is used as-is. To turn the log buffer on, you need to set its capacity. We’ll just set it to 2 (the lowest version that works). This will cause the LogRecord instances to be reused, which is fine, since we convert them immediately in a ClojureScript data structure.

(when-not (LogBuffer/isBufferingEnabled)
  (set! LogBuffer/CAPACITY 2))

Now you can use glogi/add-handler to register a function which prints the message to the console.

Have a look at lambdaisland.glogi.console, as there are a few more things to get right.

(require 'lambdaisland.glogi.console)

(console/install!)

This will log the raw values if devtools is enabled, and fall back to pr-str if it’s not, for instance when your browser doesn’t support custom formatters.

Logging in production

This is all fine and well, but chances are that once you try this in production your logs are gone, which may or may not be what you want.

There’s a constant used throughout the GCL code base called goog.DEBUG. For development builds this tends to be true, for production builds its false. Many pieces of debugging code are guarded with a if (goog.DEBUG) {}. This doesn’t just skip these parts at runtime, but it also causes the GCC to completely remove these pieces of code, at least when goog.DEBUG is false and you are using :advanced optimizations.

For logging there’s an extra step involved, goog.log has its own constant called goog.debug.LOGGING_ENABLED. This will be set to the value of goog.DEBUG unless it has already been set to something else. The same thing applies here: almost all logging functionality is stripped out of :advanced builds when LOGGING_ENABLED is false, so there’s also no chance of turning it back on again at runtime.

It’s handy though the LOGGING_ENABLED is a separate constant, since that means you can selectively keep logggin on, while removing other debugging code from the build.

To do this use the ClojureScript compiler option :closure-defines.

:closure-defines {goog.debug.LOGGING_ENABLED true}

If you’re using Figwheel in development then you’ll also have to make sure that in production builds you’re calling (glogi/enable-console-logging!), since this time Figwheel is no longer there to turn your logging on for you.

Closing thoughts & a challenge for you

Thanks to a request from a client I ended up diving deep into goog.log, and I was happily surprised by what I found. The documentation is a bit lacking, but the sources are clear, so after some browsing around I got a good picture of how this library is intended to be used.

At this point I have a challenge for you: browse through the long list of goog.* namespaces, pick one that piques your interest, and write your own blog post about it. I will happily link to it from here.

More blog posts

The Art of Tree Shaping with Clojure Zippers

This is a talk I did for the “Den of Clojure” meetup in Denver, Colorado. Enjoy!

Captions (subtitles) are available, and you can find the transcript below, as well as slides over here.

For comments and discussion please refer to this post on r/Clojure.

Test Wars: A New Hope

Yesterday was the first day for me on a new job, thanks to Clojurists Together I will be able to dedicate the coming three months to improving Kaocha, a next generation test runner for Clojure.

A number of projects applied for grants this quarter, some much more established than Kaocha. Clojurists Together has been asking people through their surveys if it would be cool to also fund “speculative” projects, and it seems people agreed.

I am extremely grateful for this opportunity. I hope to demonstrate in the coming months that Kaocha holds a lot of potential, and to deliver some of that potential in the form of a tool people love to use.

Two Years of Lambda Island, A Healthy Pace and Things to Come

It’s been just over two years since Lambda Island first launched, and just like last year I’d like to give you all an update about what’s been happening, where we are, and where things are going.

To recap: the first year was rough. I’d been self-employed for nearly a decade, but I’d always done stable contracting work, which provided a steady stream of income, and made it easy for me to unplug at the end of the day.

Lambda Island was, as the Dutch expression goes, “a different pair of sleeves”. I really underestimated what switching to a one-man product business in a niche market would mean, and within months I was struggling with symptoms of burnout, so most of year one was characterised by trying to keep things going and stay afloat financially, while looking after myself and trying to get back to a good place, physically and mentally.

D3 and ClojureScript

This is a guest post by Joanne Cheng (twitter), a freelance software engineer and visualization consultant based in Denver, Colorado. She has taught workshops and spoken at conferences about visualizing data with D3. Turns out ClojureScript and D3 are a great fit, in this post she’ll show you how to create your own visualization using the power of D3 and the elegance of ClojureScript.

I use D3.js for drawing custom data visualizations. I love using the library, but I wanted to try one of the several compile to JavaScript options, and I decided to look into ClojureScript. It ended up working out well for me, so I’m going to show you how I created a D3.js visualization using ClojureScript!

What we’re visualizing

Reloading Woes

Setting the Stage

When doing client work I put a lot of emphasis on tooling and workflow. By coaching people on their workflow, and by making sure the tooling is there to support it, a team can become many times more effective and productive.

An important part of that is having a good story for code reloading. Real world projects tend to have many dependencies and a large amount of code, making them slow to boot up, so we want to avoid having to restart the process.

The Bare Minimum, or Making Mayonnaise with Clojure

Making Mayonnaise

Imagine you have a grandfather who’s great at making mayonnaise. He’s been making mayonnaise since before the war, and the result is truly excellent. What’s more, he does this with a good old fashioned whisk. He’s kept his right arm in shape throughout decades just by beating those eggs and oil and vinegar.

Now he’s bought himself a handheld electric mixer after hearing his friend rave about hers, but after a few tries he gives up and goes back to his whisk. He says he just can’t get the same result. This seems slightly odd, so the next time you go over you ask him to show you how he uses the mixer.

Clojure Gotchas: "contains?" and Associative Collections

When learning a programming language we rarely read the reference documentation front to back. Instead someone might follow some tutorials, and look at sample code, until they’re confident enough to start a little project for practice.

From that point on the learning process is largely “just in time”, looking up exactly the things you need to perform the task at hand. As this goes on you might start to recognize some patterns, some internal logic that allows you to “intuit” how one part of the language works, based on experience with another part.

Developing this “intuition” — understanding this internal logic — is key to using a language effectively, but occasionally our intuition will be off. Some things are simply not obvious, unless someone has explained them to us. In this post I will look at something that frequently trips people up, and attempt to explain the underlying reasoning.

Dates in Clojure: Making Sense of the Mess

Update 2018-11-27: while most of this article is still relevant, I no longer recommend using JodaTime as the main date/time representation for new projects. Even existing projects that aren’t too invested in JodaTime/clj-time should consider migrating to java.time and clojure.java-time across the board.

Update 2 2019-05-29: Also check out the talk Cross Platform DateTime Awesomeness by Henry Widd, given at Clojure/north 2019

You can always count on human culture to make programming messy. To find out if a person is a programmer just have them say “encodings” or “timezones” and watch their face.

Clojure Gotchas: Surrogate Pairs

tl;dr: both Java and JavaScript have trouble dealing with unicode characters from Supplementary Planes, like emoji 😱💣.

Today I started working on the next feature of lambdaisland/uri, URI normalization. I worked test-first, you’ll get to see how that went in the next Lambda Island episode.

One of the design goals for this library is to have 100% parity between Clojure and ClojureScript. Learn once, use anywhere. The code is all written in .cljc files, so it can be treated as either Clojure or ClojureScript. Only where necessary am I using a small amount of reader conditionals.

Simple and Happy; is Clojure dying, and what has Ruby got to do with it?

The past week or so a lot of discussion and introspection has been happening in the Clojure community. Eric Normand responded to my one year Lambda Island post with some reflections on the size and growth of the community.

And then Zack Maril lamented on Twitter: “I’m calling it, clojure’s dying more than it is growing”. This sparked a mega-thread, which was still raging four days later. A parallel discussion thread formed on Reddit. Someone asked if their were any Clojure failure stories. They were pointed at this talk from RubyConf 2016, which seemed to hit a lot of people right in the feels, and sparked a subthread with a life of its own.

Meanwhile Ray, one of the hosts of the defn podcast reacted to the original tweet: “I’m calling it: Clojure is alive and well with excellent defaults for productive and sustainable software development.” This sparked another big thread.

Loading Clojure Libraries Directly From Github

Did you ever fix a bug in an open source library, and then had to wait until the maintainer released an updated version?

It’s happened to me many times, the latest one being Toucan. I had run into a limitation, and found out that there was already an open ticket. It wasn’t a big change so I decided to dive in and address it. Just a little yak shave so I could get on with my life.

Now this pull request needs to be reviewed, and merged, and eventually be released to Clojars, but ain’t nobody got time for that stuff. No sir-ee.

Lambda Island Turns One, The Story of a Rocky Ride

One year ago to date I launched Lambda Island, a service that offers high quality video tutorials on web development with Clojure and ClojureScript. It’s been quite a ride. In this post I want to look back at the past year, provide some insight into how this experience has been for me, and give you a glimpse of what the future has in store.

This story really starts in December 2015. After three years of doing contract work for Ticketsolve I decided it was time for a change. I have been self-employed for many years, but I knew that sooner or later I wanted to try my hand at selling a product, rather than selling my time.

In January and February I took some time for soul-searching, and recharging. I went to speak at RubyConf Australia, and got to hang out with some old friends around Australia and New Zealand. Once back in Berlin I got busy creating Lambda Island.

Writing Node.js scripts with ClojureScript

In the two most recent  Lambda Island episodes I covered in-depth how to create command line utilities based on Lumo, how to combine them with third party libraries, and how to deploy them to npmjs.com.

However there’s a different way to create tools with ClojureScript and distribute them through NPM, without relying on Lumo. In this blog post I want to quickly demostrate how to do just that.

To recap, Lumo is a ClojureScript environment based on Node.js, using bootstrapped (self-hosted) ClojureScript. This means the ClojureScript compiler, which is written in Clojure and runs on the JVM, is used to compile itself to JavaScript. This way the JVM is no longer needed, all you need is a JavaScript runtime to compile and run ClojureScript code, which in this case is provided by Node.js. On top of that Lumo uses nexe, so Lumo can be distributed as a single compact and fast executable binary.

Announcing lambdaisland/uri 1.0.0

I just released lambdaisland/uri, a pure Clojure/ClojureScript URI library. It is available on Github and Clojars.

This is a small piece of the code base that powers lambdaisland.com. It’s inspired by Ruby’s Addressable::URI, the most solid URI implementation I’ve seen to date, although it only offers a small part of the functionality that library offers.

It’s written in pure Clojure/ClojureScript, with only minimal use of .cljc reader conditionals to smooth over differences in regular expression syntax, and differences in core protocols. It does not rely on any URI functionality offered by the host, such as java.net.URL, so it’s usable across all current and future Clojure implementations (Clojure, ClojureScript, ClojureCLR).

re-frame Subscriptions Got Even Better

Up until recently, to use re-frame subscriptions in Reagent views, you had to use a form-2 component.

A form-2 component is a function that returns another function, which does the actual rendering of the component to hiccup. In contrast, a form-1 component renders the hiccup directly.

;; form-1
(defn todo-item [todo]
  [:div.view
   [todo-checkbox (:id todo) (:completed todo)]
   [:label {:unselectable "on"} title]
   [:button.destroy {:on-click #(dispatch [:todos/remove (:id todo)])}]])

;; form-2
(defn todo-item [todo]
  (fn [todo]
    [:div.view
     [todo-checkbox (:id todo) (:completed todo)]
     [:label {:unselectable "on"} title]
     [:button.destroy {:on-click #(dispatch [:todos/remove (:id todo)])}]]))

Game Development with Clojure/ClojureScript

This weekend it’s Ludum Dare again, the world’s longest running game jam. The idea is that, alone or with a team, you build a game in a weekend based on a certain theme.

We got a little team together here in Berlin, and so I’ve been reviewing what options there are for someone wanting to build a game in Clojure or Clojurescript.

The good news is there are plenty of options, as you’ll see from the list below. You can do desktop games, browser based games with canvas or webgl, and you can even create Unity 3D games, all from your comfortable Clojure parentheses.

Union Types with Clojure.Spec

Elm and other statically typed languages have a great feature called Union Types (also called Sum Types or Algebraic Data Types).

Here’s an example taken from Elm. Suppose your system used to represent users as integers, maybe just an auto-incrementing primary key, but then switched to UUIDs represented as strings.

To correctly model this situation, you need a way to create a type that can be either an integer or a string, that’s what union types give you.