Ayende @ Rahien

My name is Oren Eini
Founder of Hibernating Rhinos LTD and RavenDB.
You can reach me by phone or email:


+972 52-548-6969

, @ Q c

Posts: 6,124 | Comments: 45,470

filter by tags archive

Those small touches

time to read 2 min | 331 words

Can you tell me why I changed Raven’s server log format from this:

Request #1: GET / - 00:00:00.0038469
Request #2: GET /raven/index.html - 00:00:00.0066264
Request #3: GET /raven/css/rdb.css - 00:00:00.0137499
Request #5: GET /raven/js/jquery-1.4.2.min.js - 00:00:00.0136234
Request #4: GET /raven/css/smoothness/jquery-ui-1.8rc2.custom.css - 00:00:00.0135178
Request #6: GET /raven/js/jquery-ui.js - 00:00:00.0163169
Request #9: GET /raven/js/raven-ui.js - 00:00:00.0017103
Request #7: GET /raven/js/jquery-jtemplates.js - 00:00:00.0026158
Request #8: GET /raven/js/jquery.RavenDB.js - 00:00:00.0026884
Request #10: GET /raven/JSONTemplates/quickStats.html - 00:00:00.0003281
Request #12: GET /raven/images/header_bg.png - 00:00:00.0002728
Request #15: GET /raven/images/ajax-loader.gif - 00:00:00.0004883
Request #14: GET /raven/images/footer_bg.png - 00:00:00.0008783
Request #13: GET /raven/images/logo.png - 00:00:00.0011801
Request #11: GET /stats - 00:00:00.0183869

To this:

Request #   1: GET -     4 ms - 302 - /
Request #   2: GET -     7 ms - 200 - /raven/index.html
Request #   3: GET -     3 ms - 200 - /raven/css/rdb.css
Request #   4: GET -     4 ms - 200 - /raven/css/smoothness/jquery-ui-1.8rc2.custom.css
Request #   5: GET -     8 ms - 200 - /raven/js/jquery-1.4.2.min.js
Request #   8: GET -     5 ms - 200 - /raven/js/jquery.RavenDB.js
Request #   7: GET -     7 ms - 200 - /raven/js/jquery-jtemplates.js
Request #   9: GET -     2 ms - 200 - /raven/js/raven-ui.js
Request #   6: GET -    11 ms - 200 - /raven/js/jquery-ui.js
Request #  10: GET -     0 ms - 200 - /raven/JSONTemplates/quickStats.html
Request #  12: GET -     0 ms - 200 - /raven/images/header_bg.png
Request #  14: GET -     0 ms - 200 - /raven/images/ajax-loader.gif
Request #  15: GET -     0 ms - 200 - /raven/images/footer_bg.png
Request #  13: GET -     1 ms - 200 - /raven/images/logo.png
Request #  11: GET -    31 ms - 200 - /stats



So you can use sed/awk on the output? ;)

Clayton Boucher

Much easier to parse while reading, yet still easy to parse using automated tools.


For excel and rapid looks.


Easier to slam into a tool, but more importantly, the time per call is so much easier to see in the second format making it much easier to eyeball it an say "Wait...that's not right". Having the HTTP Response Codes also helps this too.


Time is human readable in the second format;

Plus you've added the http response code, wich is very important.

Jeff Lewis

They are both easily parsable, so the best answer is readability. The 2nd one is MUCH easier to read than the first.

Joseph Gutierrez

You can also tell the response code. Nice!


probably so you can open straight into excel.


You split the hash and the number, so you can reorder the list?

All the other changes just look visual :)


You like tabs and dashes? just kidding; its clearly nicer.

Chris Wright

Because you want your formatting to break after 1000 requests or if any request takes more than 100 seconds? :)

Christos Karras

Instead of being "for excel", I would say it's "to get rid of Excel" (or other automated tools): the format is directly human-readable and "higlights" extreme values, so you don't have to paste the log into Excel and do a "text to columns"

  1. Because having the path information earlier in the string makes the rest of the data fall outside easily scanned columns. Putting the path at the end allows for an arbitrarily long path that still presents information nicely.

  2. Having the milliseconds right justified does the same thing for that column. A large time value will still preserve the column spacing.

Stuart Cam

Because despite the fact computers are involved in what we do there are humans on the other end of monitors.

Jarek Kowalski

Isn't 4-character padding for request number a little bit too small?

It seems that after 10000 requests your log won't be pretty anymore in terms of both appearance and ease of parsing.


It is easier to read/parse. But more importantly it displays HTTP codes so you can see what is being cached by the server.


to see the response time easier? and see which values are max?

Demis Bellot

I'm going to go with the added readability and perhaps replay-ability. This data may end up finding its way as an input into a load tester so you can benchmark captured 'normal traffic'?

Peter Short

parsing is much simpler in 2. no need to use regex to break into its parts, just substring it. also the new time values are at a realistically useful degree of precision


Because you like FileHelpers :)

Frank Quednau

20 comments and counting on a different log file format...wow.

ayende, I think you should push the question asking even further, there is a vast untapped potential of answers in the depths of the IP-hive to just about any subject.


So that you can use the ALT key to select/cut/copy/paste in blocks?

Rik Hemsley

Because you will only ever have 9999 requests?

Paul Robson

You can sort the results more easily?

Xerxes Battiwalla

I'm going to go out on a limb and guess that you're trying to break a record for the number of blog-posts in a week?


Ayende Rahien


Not even close. I have a month where I blogged 150 posts. That is 40 posts per week.


To use the new rectangular-selection tool in VS 2010 ;) ?

Jeremy Wiebe

Um, you read Release It! ? :-)

Based on my reading of Release It! I'd say it's to aid a human in visually scanning it. The human eye is great at scanning columnar text and detecting patterns/differences. I guess this new format would be somewhat easier to parse programmatically, but I'll bet it was for humans more than machines that you changed it. Also, the time format is much easier to consume in the second sample.

Comment preview

Comments have been closed on this topic.


  1. RavenDB 3.5 whirl wind tour: You want all the data, you can’t handle all the data - 2 days from now
  2. The design of RavenDB 4.0: Making Lucene reliable - 3 days from now
  3. RavenDB 3.5 whirl wind tour: I’ll find who is taking my I/O bandwidth and they SHALL pay - 4 days from now
  4. The design of RavenDB 4.0: Physically segregating collections - 5 days from now
  5. RavenDB 3.5 Whirlwind tour: I need to be free to explore my data - 6 days from now

And 14 more posts are pending...

There are posts all the way to May 30, 2016


  1. RavenDB 3.5 whirl wind tour (14):
    29 Apr 2016 - A large cluster goes into a bar and order N^2 drinks
  2. The design of RavenDB 4.0 (13):
    28 Apr 2016 - The implications of the blittable format
  3. Tasks for the new comer (2):
    15 Apr 2016 - Quartz.NET with RavenDB
  4. Code through the looking glass (5):
    18 Mar 2016 - And a linear search to rule them
  5. Find the bug (8):
    29 Feb 2016 - When you can't rely on your own identity
View all series



Main feed Feed Stats
Comments feed   Comments Feed Stats