EmacsOrgTimestamps

Timestamp calculations in Emacs with org-mode

Today I had to do some profiling of how long each phase of a software install took. The tool I was using printed output like this:

11:40:58.096    95      exit 0
11:40:58.272    96      current version: 5.296
11:40:58.274    97      Password:
11:41:15.215    98      Password:
11:41:15.561    99      Connection to server closed.

The format is timestamp, line number, output.

First I wanted an easy way to calculate the offset between two timestamps. I had been reading the emacs calc manual and I noticed that calc supported hour-minute-second calculations. Thus, my first project was to figure out how to get calc-mode to actually work with time offsets. Here's the process I eventually figured out (<esc> means press the esc key):

Start calc-mode with <esc>x calc<enter>
Input the last timestamp in calc HMS format: 11@41'15.561"<enter>
Input the first timestamp in calc HMS format: 11@40'58.096"<enter>
Subtract the two with -<enter>

The result is then displayed in the calc window as 0@ 0' 17.465". That is, the two timestamps are 17.465 seconds apart - exactly the info I needed.

Ok so that gave me a timestamp offset. The next step was to add up selected offsets to determine how much of the total install time was taken by certain operations. That is, if one phase of the install took 5.2 seconds and another tool 10.3 seconds, I wanted to calculate that both of them combined took 10.5 of the total 60 seconds of an install. Also, some sort of table display of my data would be nice.

For this I turned to org-mode, a fantastic plain-text notetaking and project planning mode for emacs. Org-mode has a table editor with a basic spreadsheet so I figured I could probably use that to organize my findings. In particular the org-mode spreadsheet supports calling calc-mode functions so I thought I could probably write formulas using HMS notation. That turned out to be sort of true, in usual emacs fashion.

Here's the sequence for creating a table in org-mode:

Start org-mode by opening a new buffer with the extension .org via <ctrl>xf foo.org.
- This automatically loads org-mode.
- You could also just run <esc>x org-mode<enter> to launch org-mode on an existing buffer.
Create a table by starting a line with a vertical bar |
Create your header fields with time | comment<ctrl>c<enter>
- this will create a horizontal separator followed by a fresh input row.
Type in the timeset offset, followed by a bar, followed by a comment field and finally press <tab>
- that will automatically close the row and start a new one.
rinse, lather, repeat
after entering all lines of data, create another horizontal separator with <ctrl>c<enter>

The resulting table will look like this:

| time          | comment          |
|---------------+------------------|
| 0@ 0' 17.465" | install startup  |
| 2@ 1' 15.521" | package install  |
| 1@ 0' 12.221" | script execution |
| 0@ 2' 5.541"  | cleanup          |
|---------------+------------------|
|

Now let's use a calc formula to sum column 1 in HMS notation:

Press = after the vertical bar in the last row.
- This tells org-mode to enter column-formula mode.
Enter the following formula: vsum(@I..@II)<ctrl>c<ctrl>c
- i.e. sum up the first column between the first and second horizontal roles
- <ctrl>c<ctrl>c tells org-mode to evaluate the formula and close the row.

Here's the resulting table, with the times from column one tallied:

| time          | comment          |
|---------------+------------------|
| 0@ 0' 17.465" | install startup  |
| 2@ 1' 15.521" | package install  |
| 1@ 0' 12.221" | script execution |
| 0@ 2' 5.541"  | cleanup          |
|---------------+------------------|
| 3@ 3' 50.748" |                  |
#+TBLFM: $1=vsum(@I..@II)

(you can ignore the final line that starts with #, that's just where org-mode stores the formula)

The resulting table shows that the total time for all listed stages was 3 hours, 3 minutes, and 50.748 seconds. Just the data I was looking for. Thanks emacs!

Caveats

While this process worked well for me, there were some bumps along the way I should point out.

First, I initially found that emacs would hang in an infinite loop when I tried to calculate my formula to sum the values. After some digging I found this mailing list post which indicated this issue had been fixed in a particular version of org-mode. Sure enough, I was running an older org-mode. I updated to the latest 7.01 version and that fixed the problem. I should note I am using Aquamacs on Mac OS X so the upgrade process required a few small tweaks. I can describe those tweaks separately if anyone is interested.

Second, I have not been able to get any other HMS functions to work in org-mode. For example, I think you should be able to subtract HMS values in org-mode tables with formulas like this: :=A1-B1. However all my attempts to do this result in what appear to be more infinite loop hangs in emacs.