## Archive for the ‘Tech’ Category

### Robot Testing With Emacs

I have written about assess previously ; it is a tool which provides predicates, macros and functions to support testing for Emacs. It is actually agnostic to the test environment, although has specialised support for ERT.

My new release of assess (v0.3.2) includes one significant change, and two new features. I have updated the call capture functionality — the first version stored all the call data in a global variable, which was quick and easy, but clearly not a log term solution. It now uses closures instead which means that several functions can be captured at once. This also allows the first new feature, which is the ability to capture calls to hooks, with the function assess-call-capture-hook, which takes a hook and a lambda, and returns any calls to the hook when the lambda is evaluated. As an example usage, from assess-call-tests.el:

 (should (equal '(nil nil) (assess-call-capture-hook 'assess-call-test-hook (lambda () (run-hooks 'assess-call-test-hook) (run-hooks 'assess-call-test-hook)))))

This is good functionality and should be very useful. The API could be improved a bit; a macro version would avoid the explicit lambda, for example. And returning a list of nil means this function also works with hooks with args, but is a bit ugly for hooks without (which are the majority).

The second area that I wanted to address has come about because of my hacking into the Emacs undo system. This is hard to test automatically; I have often found myself writing things like this test from simple-test.el.

 (should (with-temp-buffer (setq buffer-undo-list nil) (insert "hello") (member (current-buffer) undo-auto--undoably-changed-buffers)))

This is okay, but it’s painful to write; I am trying to robotize Emacs, and it’s not easy. Some times it’s hard to work out exactly what set of functions you need to call. It would be much easier just to type a key sequence and have Emacs run this for you.

Fortunately, Emacs has special support for this in the form of keyboard macros; you can remember, store and save any set of keypresses and run them, rerun them, automate them or, most importantly, save them to a file as a lisp expression. This example, for instance, comes from viper-test.el.

 (kmacro-call-macro nil nil nil [left ;; Delete "c" backspace left left left ;; Delete "a" backspace ;; C-/ or undo 67108911])

This is okay, but it’s still not ideal. I have had to add comments to make the test clear by hand. It’s not easy to read, and what is that 67108911 about? It comes from somewhere in Emacs and is stable into the future. But, you only have my word for it that this is undo. It would be all too easy to get this wrong, to have the wrong comment. Tests need to be readable.

Fortunately, Emacs provides a nice solution, in the form of edmacro — this is a major-mode for editing macros after they have been created. It also defines a human readable version of a macro. We can parse this and then execute it directly. This example comes from simple-test.el.

 (execute-kbd-macro (read-kbd-macro " C-c C-o ;; latex-insert-block RET ;; newline C-/ ;; undo "))

The advantage of this is that I didn’t actually write this string; I recorded the macro, the edited it and copied the contents of the edmacro buffer.

This is still not easy enough, though; I want an easier way of editing the macro as it appears in the test. This is, unfortunately, difficult as the edit-kbd-macro is not easy to invoke programmatically — it absolutely hard-codes user interaction (I did even try invoking edit-kbd-macro using a keyboard macro!). So, I have given up with that approach in the short term. Instead, I have written a function assess-robot-execute-macro that combines read-kbd-macro and execute-kbd-macro, but also sets the macro as the last macro, making it easy to edit. I’ve also added a keybinding to edmacro to copy the macro to the kill-ring. And here is a test using it:

 (should (assess= "hello" (assess-robot-with-switched-buffer-string (assess-robot-execute-kmacro " hello ;; self-insert-command * 5 "))))

This also demonstrates the final quirk. Keyboard macros work in which ever buffer is selected — not the one which is current. We cannot use with-temp-buffer to select on temporarily and run the macro in it. So I have added macros to display a buffer temporarily instead.

As with many parts of assess, the back end is quite convoluted and complex, as many parts of Emacs were not written with testing in mind (that is they predate the whole idea of unit testing by many years!). But, I hope that the API that assess provides is simple, clear and flexible.

Assess is available at github and MELPA.

Feedback is, as always, welcome.

## Bibliography

### Emacs Testing with Assess

Assess is my new package supporting testing in Emacs. It has grown out of my frustration with the existing framework while building the lentic package .

For quite a while, the only testing framework in Emacs has been ERT (the Emacs Regression Testing tool) which is part of core. More recently, there have been a number of new ones arriving. For example, buttercup and ecukes both provide behaviour driven testing, rather like Jasmine or Cucumber respectively. Both worth looking at — I’ve used Ecukes for testing Cask, and it’s nicely implemented and very usable. Assess is rather less radical than this though. It focuses on providing a general set of tools for testing, mostly in terms of some macros and predicates that should be useful.

For example, a recurrent problem during the development of lentic was ensuring that no buffers were left around after a test. Particularly when a test fails, this can lead to unexpected failures in later tests. For this purpose, I have added a macro called assess-with-preserved-buffer-list. Any buffers at all created inside this macro will be removed after. Hence this:

 (assess-with-preserved-buffer-list (get-buffer-create "a") (get-buffer-create "b") (get-buffer-create "c"))

Which preserves the buffer state. a, b and c will be removed after the macro exits.

Assess also provides some handy predicates for testing. So, we can compare the contents of strings, buffer and files easily. For example:

 ;; Compare Two Strings (assess= "hello" "goodbye") ;; Compare the contents of Two Buffers (assess= (assess-buffer "assess.el") (assess-buffer "assess-previous.el")) ;; Compare the contents of Two files (assess= (assess-file "~/.emacs") (assess-file "~/.emacs"))

Again, this has all been done carefully to avoid changing state. The last example, should work whether ~/.emacs is open already or not, and will not result in new buffer creation.

As well as string comparison, we can also check that indentation is working correctly. This example, for instance, takes a indented string, un-indents and re-indents according to a specific mode, then checks that nothing has changed.

 (assess-roundtrip-indentation= 'emacs-lisp-mode "(assess-with-find-file\n \"~/.emacs\"\n (buffer-string))")

Likewise, we can check fontification with the assess-face-at= function. In this case, we are checking that three words get highlighted correctly.

 (assess-face-at= "(defun x ())\n(defmacro y ())\n(defun z ())" 'emacs-lisp-mode '("defun" "defmacro" "defun") 'font-lock-keyword-face)

Finally, in terms of test functions, I have recently added two new pieces of functionality. Call capturing was an idea I stole from buttercup — this is a non-interative equivalent to the function tracing, returning parameters and return values to a function call.

 (assess-call-capture '+ (lambda() (+ 1 1))) ;; => (((1 1) . 2))

And discover provides a drop in replacement for ert-run-tests-batch-and-exit except that it automatically finds and loads test files, based on a set of heuritstics. I’ve already started to use this instead of ert-runner, as it requires no configuration.

The final thing I wanted to address was better reporting. While everything described so far as test environment agnostic, I’ve only managed to advance reporting for ERT. All of the functions that I have written plug into ERT, so produce richer output. So instead of:

 F temp (ert-test-failed ((should (string= "a" "b")) :form (string= "a" "b") :value nil))

When comparing "a" and "b", this output is fine, but if the strings are more complex (say, for example, the a short piece of code that you expect to indent in a certain way), it is hard to work out what the differences are.

So, assess extends ERT so that that it now calls diff on the strings. We now get this explanation instead:

 F test-assess= (ert-test-failed ((should (assess= "a" "b")) :form (assess= "a" "b") :value nil :explanation "Strings: a and b Differ at:*** /tmp/a935uPW 2016-01-20 13:25:47.373076381 +0000 --- /tmp/b9357Zc 2016-01-20 13:25:47.437076381 +0000 *************** *** 1 **** ! a \\ No newline at end of file --- 1 ---- ! b \\ No newline at end of file "))

Verbose for sure, but very useful for identifying issues, especially white space related. By default, this uses the diff command, but this is also extensible, and has a simple fallback in its absence.

There is more functionality to assess than that shown here: it can create multiple temporary buffers in a single scope; it can create “related” temporary files, prevent conflicts if files are already open; it can re-indent the contents of files rather than buffers, and so on. I think assess is a nice addition to the testing capabilities of Emacs.

More is needed and some of this involve changes to Emacs core — packages which are noisy, enforce interactivity, and so forth. I would also like to add support for “robotized” tests running keyboard macros, tests for checking hooks, output to the message buffer, and testing for asynchronous call backs. But assess is quick, easy to use and makes testing of many features of Emacs much easier. I’ve started to use it in my own packages, and will eventually use it in all of them.

My plans for the future are to move assess to ELPA, and then eventually to Emacs core after 25.1, probably as ert-assess. I hope that along with my restructuring of the Emacs unit tests files, this will make testing of Emacs core simpler and more straight forward; if it does this should make the merge hassles (mostly to other people, sadly) caused by file moves worthwhile. Emacs will be easier to develop, and simpler to change.

Feedback is, as always, welcome.

## Bibliography

### Logging Concluded

My last blogpost was on logging with the SLF4J library, its inclusion in the OWL API, and its impact on Tawny-OWL. It raised quite a response, not least because it suggested that people ignore the advice of the authors of the library.

Perhaps, unsurprisingly, the general feeling was against my position — something that I expected given that this had already happened on the SLF4J mailing list. Now, of course, it does have to be said that there is a significant sampling bias here: anyone on the mailing list, or who reads and responds to a post about a logging API, is likely to be interested in logging rather than a passive user (or non-user) of such a library. None the less, I think it is worth reflecting on the reasons for the comments.

Of course, I am aware, that as many people pointed out, the problem is not huge (a three line error message) and my solution is messy. Well, I agree, the solution is messy, but it is the only method that SLF4J has support for. There are alternatives; for example, this commit from the OWL API provides another solution. I have not decided yet whether this is the right way to go or not.

Several people complained that including the nop dependency will silently turn off all logging. Actually, this is not true: in applications which have logging already, including a nop dependency, will trigger an error message; whether logging is turned off or not is hard to determine — it depends on the classpath ordering. I am, however, clearly making life harder for those who want logging on. Specifically, I am requiring that instead of using:

["uk.org.russet/tawny-owl "1.5.0"]

It will require this:

["uk.org.russet/tawny-owl "1.5.0" :exclusions ["org.slf4/slf4f-nop"]]

(or the equivalent for maven). So, harder, but not much harder.

The other two main suggestions are that I split my code into library and application, even though this is artificial (the “application” would currently contain no code). But this approach would require most of my downstream dependencies to also be split into two for the same reason; it was even suggested that the Clojure REPL or Leiningen that should do the work, and that they should be split into two. Introducing such complexity for a logging API is surely not good engineering.

Finally, there were many suggestions that I leave the decision to the “end user”. But, as I have said, while I like allowing the “end user” to have a choice, I do not believe in imposing it on them. Choose a default where it is at all possible and do not sit on the fence.

During this process, though, I have thought a lot about logging, and I have come to the conclusion that the core of the problem is that logging is heavily overloaded. Quite a few people were frankly amazed that I would not want to see logging, asserting that most people would want to see it.

Now, I use a web server, and use its logs all the time. Logs are critical for many reasons, and many tools like webalyser or fail2ban work over them. I would never want to turn these off. But, here, though, the logging is effectily a part of the application: apache logs are part of the adminstration user interface, as well as forming an ad hoc API to downstream tools; part of the plumbing in git parlance. Why would you want to switch this off? I would not.

In this case, though, if logging is part of the application, why on earth are people so keen on libraries logging — the application should not be deciding the location of the logs only, but also how and what is logged. Libraries should just not be logging at all; they should be taking callbacks, returning values and leaving the outcome of this to the application.

What about “error messages” though? Surely libraries can produce these? The OWL API (which is the library that makes use of SLF4J) is an example of this. Most of the logging message are errors: for example, this situation:

 if (loadCount.get() != importsLoadCount.get()) { LOGGER.warn( "Runtime Warning: Parsers should load imported ontologies using the makeImportLoadRequest method."); }

which is effectively a form of active documentation or this:

 try { return optional(new XZInputStream(new BufferedInputStream(new FileInputStream(file)))); } catch (IOException e) { LOGGER.error("File cannot be found or opened", e); failedOnStreams.set(true); return emptyOptional(); }

which is sort of an error but one that has actually been dealt with. These are mostly debugging statements that the authors think they may use again. That’s fine and an entirely reasonable use of a logging framework. Equally, and I feel entirely reasonably, I want this off by default.

The “error message” from SLF4J that started me down this path falls into the same category. It is not an error, or it would throw an exception (as it used to do in the past). It is a debugging statement that is there for a normal condition that the authors are, nonetheless, not entirely happy about. There are two reasonable defaults (be noisy, or be silent), and they do not know which to choose.

My previous trip into the field of logging was twenty years ago, when I wrote a fun Emacs packages for putting System.out.println statements into the code (then taking them out again); as one person said of me, I “simply lack the knowledge” of logging frameworks to comment. I am happy to accept that this is entirely correct. Despite this my conclusions are simple. I remain convinced that SLF4J should have the courage of its convictions; if there is an error, signal an error, otherwise remain silent. Until it does this, adding the nop dependency remains the right way forward for me. Take my advice with a distinct pinch of salt, certainly. At the same time, think how many people have been irritated by that error message and not taken the time to comment. If you are worried about these people, then using the nop dependency may be the right way forward for you to.

And there I shall leave the discussion and comment no more.

## Bibliography

### Why a Logging Framework should not Log

Shortly after the release of Tawny-OWL 1.5.0 , I noticed a strange message being printed to screen, which looks like this:

SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further
details.

What strangeness is this? I had never heard of SLF4J before, and could not see why this was happening; so I googled around, and found out. The reason is that I had switched versions of the OWL API , and this now uses the SLF4J API as a logging API. By default, it prints out this error message.

Slightly irritated by this, I tweeted

#slf4j I mean, who decided to print a message to tell me I am using a no-op logger. How is that no-op?

To which the author of SLF4J Ceki Gülcü kindly replied:

@phillord if you place slf4j-nop.jar on the class path the nop message should not appear.

But this seems unsatisfying to me. The reason for the message is that SLF4J is a facade, and needs a logging backend. It prints this error message when it cannot find one. The way to switch it off is to include the slf4j-nop dependency (which, ironically, does not contain the NOP logger — that’s in slf4j-api).

Normally, I would say that a library should not print to stderr in normal operation. But I can appreciate SLF4J logic here; it has to do something by default. For most libraries, my response would be “use a proper logger then!”, but, of course, SLF4J does not have that option — it cannot do this during bootstrap, and it either prints to stderr or just dumps all logs.

Okay, no worries, just include slf4j-nop in your project? Unfortunately, SLF4J say explicitly not to do this.

If you are packaging an application and you do not care about logging, then placing slf4j-nop.jar on the class path of your application will get rid of this warning message. Note that embedded components such as libraries or frameworks should not declare a dependency on any SLF4J binding but only depend on slf4j-api

Now, for a library/application/textual UI like Tawny-OWL , the distinction between “library” and “end-user” is not that clear, so this advice is not that useful. SLF4J justify this by saying:

When a library declares a compile-time dependency on a SLF4J binding, it imposes that binding on the end-user, thus negating SLF4J’s purpose.

Of course, imposing a binding of the end-user is a negative thing, but then is not forcing users to choose a binding also an imposition? It is made worse in my case, because I also get this message from ELK, another dependency of Tawny-OWL:

log4j:WARN No appenders could be found for logger
(org.semanticweb.elk.config.ConfigurationFactory).
log4j:WARN Please initialize the log4j system properly.

A similar error message for a similar reason. I now have to explicitly pacify the logging from two libraries in my project!

The curious thing about the whole situation is that everyone is behaving entirely reasonably. I can fully appreciate the logic of SLF4J, I can fully understand why the OWL API uses it, and I hope that others appreciate why I do not want print outs to stderr. It’s another one of those situations which show that software is difficult, and that often there are only compromises; whether something is a solution or a problem depends on where you sit.

For what it is worth, my own advice is that libraries and framework developers should always include the slf4j-nop if they use slf4j-api. If their end-users want logging, they can always use dependency exclusions to enable it.

I’d like to thank the members of the SLF4J users list, and Ceki for their helpful and polite responses to my questions. You can read the full thread on gmane. This article was, however, written without their endorsement.

• Update

## Bibliography

### Tawny-OWL 1.5

I am pleased to annouce the 1.5.0 release of Tawny-OWL, the fully programmatic ontology construction environment.

As with the 1.4.0 release, there has been quite a long gap between releases. The main change for this release has been the move to the OWL API version 4.

The next release of Tawny will include more extensions to the patterns.

Tawny 1.5.0 is now available on Clojars.

### Tawny-OWL 1.4

I am pleased to announce this 1.4.0 release of Tawny-OWL. It is with some surprise that I find that it is about 8 months since the last release, which is indicative of the relatively stable state of Tawny.

The main addition to this release has been further support for patterns, which now include what I am calling “facets”, as well as some general functions for grouping the entities created using a pattern with annotations. I have had a lot of discussion about the implementation of this feature and that it should be useful in practice.

The main motivation behind making this release now is the development of a Tawny Tutorial for ICBO 2015. The features are stable for the release are stable, so the release has not been rushed out the door, but I wanted to use them in the tutorial as they really simplify some aspects.

Tawny-OWL 1.4.0 is now available on Clojars.