+972 52-548-6969
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
Comments
So you can use sed/awk on the output? ;)
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.
They are both easily parsable, so the best answer is readability. The 2nd one is MUCH easier to read than the first.
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.
Because you want your formatting to break after 1000 requests or if any request takes more than 100 seconds? :)
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"
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.
Having the milliseconds right justified does the same thing for that column. A large time value will still preserve the column spacing.
Because despite the fact computers are involved in what we do there are humans on the other end of monitors.
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.
to use log parser?
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?
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'?
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
What happens at request 10,000?
Because you like FileHelpers :)
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?
Because you will only ever have 9999 requests?
You can sort the results more easily?
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?
;P
Xerxes,
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 ;) ?
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.
Jeremy,
DING DING DING
Comment preview