wvanbergen / request-log-analyzer

Create reports based on your log files. Supports Rails, Apache, MySQL, Delayed::Job, and other formats.
http://www.request-log-analyzer.com
MIT License
2.25k stars 191 forks source link

When Rails serves assets (in development), many empty "requests" are added to output #153

Open alexdowad opened 10 years ago

alexdowad commented 10 years ago

Before I say anything: this is an awesome tool! I just discovered it today.

My Rails 3 app serves static assets. Each request for a static asset creates lines like this in the log:

Started GET "/assets/jquery_ujs.js?body=1" for 127.0.0.1 at 2013-04-29 17:56:53 +0200
Served asset /jquery_ujs.js - 304 Not Modified (0ms)

request-log-analyzer catches the "Started" line and adds a Request. But it doesn't recognize the "Served" line. In the output, I get this:

Most requested
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
#.                                   ┃ 74 hits ┃ 74.7% ┃             

Needless to say, this is less than enlightening.

I'm thinking of adding something to file_format/rails3.rb to catch those "Served" lines and get the HTTP code and duration. Perhaps I could also make it set fake controller/action names, so that something more useful would appear in the output.

Does that sound like a good idea? Should I send a PR? Since this is your project, I'd like to hear what you would like.

wvanbergen commented 10 years ago

Should be relatively easy? Could you paste a snippet of log that includes a bunch of these requests alongside some normal requests that don't return 304? It's intended for the test suite, feel free to anonymize the data

alexdowad commented 10 years ago

When you say "normal requests", does that mean requests for dynamic pages, or for static assets?

wvanbergen commented 10 years ago

Ideally both: the more variation the better.

alexdowad commented 10 years ago

Hi, sorry for leaving this so long! This is from my dev logs:

Started GET "/office/login" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Processing by OfficeController#login as HTML
  Rendered office/login.html.haml within layouts/office (45.5ms)
Compiled office-views/todo-view.js  (142ms)  (pid 10169)
Compiled office.js  (18ms)  (pid 10169)
Completed 200 OK in 531ms (Views: 516.4ms | ActiveRecord: 0.0ms)

Started GET "/assets/table-widget.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /table-widget.css - 304 Not Modified (1ms)

Started GET "/assets/flash.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /flash.css - 304 Not Modified (2ms)

Started GET "/assets/homepage_sprites.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /homepage_sprites.css - 304 Not Modified (1ms)

Started GET "/assets/other_sprites.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /other_sprites.css - 304 Not Modified (2ms)

Started GET "/assets/jquery.timepicker.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /jquery.timepicker.css - 304 Not Modified (3ms)

Started GET "/assets/jquery.ui.core.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /jquery.ui.core.css - 304 Not Modified (2ms)

Started GET "/assets/jquery.ui.theme.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /jquery.ui.theme.css - 304 Not Modified (2ms)

Started GET "/assets/jquery.ui.autocomplete.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /jquery.ui.autocomplete.css - 304 Not Modified (1ms)

Started GET "/assets/jquery.ui.menu.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /jquery.ui.menu.css - 304 Not Modified (1ms)

Started GET "/assets/jquery.handsontable.full.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /jquery.handsontable.full.css - 304 Not Modified (3ms)

Started GET "/assets/bootstrap-datepicker.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap-datepicker.css - 304 Not Modified (3ms)

Started GET "/assets/bootstrap/reset.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/reset.css - 304 Not Modified (1ms)

Started GET "/assets/bootstrap/scaffolding.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/scaffolding.css - 304 Not Modified (2ms)

Started GET "/assets/bootstrap/type.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/type.css - 304 Not Modified (5ms)

Started GET "/assets/bootstrap/navs.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/navs.css - 304 Not Modified (1ms)

Started GET "/assets/bootstrap/buttons.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/buttons.css - 304 Not Modified (2ms)

Started GET "/assets/bootstrap/button-groups.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/button-groups.css - 304 Not Modified (1ms)

Started GET "/assets/bootstrap/dropdowns.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/dropdowns.css - 304 Not Modified (1ms)

Started GET "/assets/bootstrap/progress-bars.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/progress-bars.css - 304 Not Modified (1ms)

Started GET "/assets/bootstrap/popovers.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/popovers.css - 304 Not Modified (1ms)

Started GET "/assets/bootstrap/tooltip.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/tooltip.css - 304 Not Modified (1ms)

Started GET "/assets/bootstrap/close.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/close.css - 304 Not Modified (2ms)

Started GET "/assets/bootstrap/modals.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /bootstrap/modals.css - 304 Not Modified (2ms)

Started GET "/assets/office.css?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /office.css - 304 Not Modified (27ms)

Started GET "/assets/jquery.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /jquery.js - 304 Not Modified (3ms)

Started GET "/assets/jquery.timepicker.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:37 +0200
Served asset /jquery.timepicker.js - 304 Not Modified (66ms)

Started GET "/assets/jquery.watermark.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /jquery.watermark.js - 304 Not Modified (1ms)

Started GET "/assets/jquery.ui.core.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /jquery.ui.core.js - 304 Not Modified (2ms)

Started GET "/assets/jquery.ui.widget.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /jquery.ui.widget.js - 304 Not Modified (4ms)

Started GET "/assets/jquery.ui.position.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /jquery.ui.position.js - 304 Not Modified (2ms)

Started GET "/assets/jquery.ui.menu.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /jquery.ui.menu.js - 304 Not Modified (1ms)

Started GET "/assets/jquery.ui.autocomplete.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /jquery.ui.autocomplete.js - 304 Not Modified (1ms)

Started GET "/assets/jquery.iframe-transport.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /jquery.iframe-transport.js - 304 Not Modified (2ms)

Started GET "/assets/jquery.fileupload.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /jquery.fileupload.js - 304 Not Modified (1ms)

Started GET "/assets/jquery.fileDownload.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /jquery.fileDownload.js - 304 Not Modified (3ms)

Started GET "/assets/jquery.zoomit.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /jquery.zoomit.js - 304 Not Modified (1ms)

Started GET "/assets/jquery.handsontable.full.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /jquery.handsontable.full.js - 304 Not Modified (2ms)

Started GET "/assets/numeral.en-gb.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /numeral.en-gb.js - 304 Not Modified (2ms)

Started GET "/assets/bootstrap/bootstrap-tab.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /bootstrap/bootstrap-tab.js - 304 Not Modified (2ms)

Started GET "/assets/bootstrap/bootstrap-dropdown.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /bootstrap/bootstrap-dropdown.js - 304 Not Modified (1ms)

Started GET "/assets/bootstrap/bootstrap-tooltip.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /bootstrap/bootstrap-tooltip.js - 304 Not Modified (1ms)

Started GET "/assets/bootstrap/bootstrap-popover.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /bootstrap/bootstrap-popover.js - 304 Not Modified (1ms)

Started GET "/assets/bootstrap/bootstrap-modal.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /bootstrap/bootstrap-modal.js - 304 Not Modified (1ms)

Started GET "/assets/bootstrap-datepicker.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /bootstrap-datepicker.js - 304 Not Modified (1ms)

Started GET "/assets/gmaps-marker-clusterer-plus.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /gmaps-marker-clusterer-plus.js - 304 Not Modified (2ms)

Started GET "/assets/hamlcoffee.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /hamlcoffee.js - 304 Not Modified (2ms)

Started GET "/assets/ckeditor/ckeditor.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /ckeditor/ckeditor.js - 304 Not Modified (3ms)

Started GET "/assets/utilities.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /utilities.js - 304 Not Modified (1ms)

Started GET "/assets/office-views.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /office-views.js - 304 Not Modified (1ms)

Started GET "/assets/office-views/widgets.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /office-views/widgets.js - 304 Not Modified (1ms)

Started GET "/assets/office.js?body=1" for 127.0.0.1 at 2014-03-16 19:28:38 +0200
Served asset /office.js - 304 Not Modified (101ms)

Started POST "/office/login" for 127.0.0.1 at 2014-03-16 19:28:51 +0200
Processing by OfficeController#login as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"hXWXnh+TYftyqSQcT/oI7gdO93/tsKMQaaw1ZDfiExA=", "login_email"=>"abc@gmail.com", "login_password"=>"[FILTERED]", "commit"=>"Login"}
Redirected to http://localhost:3000/office
Completed 302 Found in 203ms (ActiveRecord: 33.9ms)