This project is archived and is in readonly mode.

Fragment cache logging fails in 3.0 when fragment path contains printf chars, e.g. "%A"
Reported by Steve Purcell | September 7th, 2010 @ 11:36 AM
Given a (reasonable) fragment path such as:
views/localhost:3000/action?date=2010-08-23+15%3A30%3A00
Rails reports the following error:
Could not log "exist_fragment?.action_controller" event. ArgumentError: malformed format string - %A
Judging by the code in fragment.rb, it looks like the key is passed to the instrumenter as part of the payload -- should the key perhaps be escaped somehow before handing it to the instrumenter, or is it incorrect that the instrumenter is using the payload in a printf way?
Comments and changes to this ticket
-
David Trasbo September 7th, 2010 @ 12:37 PM
Could you please provide the code that causes this issue?
-
Steve Purcell September 7th, 2010 @ 01:27 PM
Sure.
Example view code would look like this:
cache(:foo => "key with spaces") do ... render something ... end
where #cache is presumably ActionView::Helpers::CacheHelper#cache
-Steve
-
David Trasbo September 20th, 2010 @ 07:25 PM
- State changed from new to resolved
- Importance changed from to Low
This issue is gone in Rails master:
Warmup:
Started GET "/people" for 127.0.0.1 at 2010-09-20 20:21:45 +0200 Processing by PeopleController#index as HTML Exist fragment? views/localhost:3000/people?foo=key+with+spaces (0.1ms) Write fragment views/localhost:3000/people?foo=key+with+spaces (3.4ms) Rendered people/index.html.erb within layouts/application (6.6ms) Completed 200 OK in 10ms (Views: 9.8ms | ActiveRecord: 0.0ms) cache: [GET /javascripts/prototype.js?1285006555] miss cache: [GET /javascripts/dragdrop.js?1285006555] miss cache: [GET /javascripts/effects.js?1285006555] miss cache: [GET /javascripts/controls.js?1285006555] miss cache: [GET /javascripts/rails.js?1285006555] miss cache: [GET /javascripts/application.js?1285006555] miss cache: [GET /favicon.ico] miss cache: [GET /people] miss
After warmup:
Started GET "/people" for 127.0.0.1 at 2010-09-20 20:22:21 +0200 Processing by PeopleController#index as HTML Exist fragment? views/localhost:3000/people?foo=key+with+spaces (0.2ms) Read fragment views/localhost:3000/people?foo=key+with+spaces (0.0ms) Rendered people/index.html.erb within layouts/application (2.9ms) Completed 200 OK in 6ms (Views: 5.9ms | ActiveRecord: 0.0ms) cache: [GET /javascripts/prototype.js?1285006555] miss cache: [GET /javascripts/effects.js?1285006555] miss cache: [GET /javascripts/dragdrop.js?1285006555] miss cache: [GET /javascripts/controls.js?1285006555] miss cache: [GET /javascripts/rails.js?1285006555] miss cache: [GET /javascripts/application.js?1285006555] miss cache: [GET /favicon.ico] miss
-
Steve Purcell September 20th, 2010 @ 08:41 PM
Hmm, I think that the example given should have used "key:with:colons" rather than "key with spaces", since it looks like the problematic "%3A" was the result of url-escaping colons, not spaces -- sorry.
David: in the light of that mistake on my part, you might want to double-check that it's indeed working fine in Rails Master.
-
David Trasbo September 20th, 2010 @ 08:44 PM
- State changed from resolved to open
Steve,
Ah, ok. No problem. Reopening this and putting it on my follow-up list. Will most likely have a look at this again tomorrow.
-
David Trasbo September 21st, 2010 @ 06:10 AM
You're right, Steve! Was able to duplicate this issue on master:
Warmup:
Started GET "/people" for 127.0.0.1 at 2010-09-21 07:07:24 +0200 Processing by PeopleController#index as HTML Could not log "exist_fragment?.action_controller" event. ArgumentError: too few arguments Could not log "write_fragment.action_controller" event. ArgumentError: too few arguments Rendered people/index.html.erb within layouts/application (6.8ms) Completed 200 OK in 10ms (Views: 9.8ms | ActiveRecord: 0.0ms) cache: [GET /javascripts/prototype.js?1285045419] miss cache: [GET /javascripts/effects.js?1285045419] miss cache: [GET /javascripts/dragdrop.js?1285045419] miss cache: [GET /javascripts/controls.js?1285045419] miss cache: [GET /javascripts/rails.js?1285045419] miss cache: [GET /javascripts/application.js?1285045419] miss cache: [GET /favicon.ico] miss cache: [GET /people] miss
After warmup:
Started GET "/people" for 127.0.0.1 at 2010-09-21 07:07:41 +0200 Processing by PeopleController#index as HTML Could not log "exist_fragment?.action_controller" event. ArgumentError: too few arguments Could not log "read_fragment.action_controller" event. ArgumentError: too few arguments Rendered people/index.html.erb within layouts/application (3.3ms) Completed 200 OK in 7ms (Views: 6.2ms | ActiveRecord: 0.0ms) cache: [GET /javascripts/dragdrop.js?1285045419] miss cache: [GET /javascripts/effects.js?1285045419] miss cache: [GET /javascripts/prototype.js?1285045419] miss cache: [GET /javascripts/controls.js?1285045419] miss cache: [GET /javascripts/rails.js?1285045419] miss cache: [GET /javascripts/application.js?1285045419] miss
I might investigate how to solve this later today.
-
Marjan Krekoten' September 21st, 2010 @ 09:23 AM
- Assigned user set to Santiago Pastorino
-
David Trasbo September 22nd, 2010 @ 03:04 PM
Marjon,
+1 for the fix, but -1 for the tests. I think you should make a separate test for percentage signs, to make sure people know they're there for a reason.
-
-
Marjan Krekoten' September 22nd, 2010 @ 09:20 PM
- no changes were found...
-
Repository September 25th, 2010 @ 10:07 AM
- State changed from open to resolved
(from [8639c10a40604cee2f3d412470c2960712fdc809]) Fix logging when cache key contains % sign [#5570 state:resolved]
Signed-off-by: José Valim jose.valim@gmail.com
http://github.com/rails/rails/commit/8639c10a40604cee2f3d412470c296... -
Skully April 24th, 2011 @ 03:26 PM
Not sure if i should open a new ticket but with rails 3.0.7 i am getting the following error:
Could not log "read_fragment.action_controller" event. ArgumentError: malformed format string - %F
with the following code:
cache({:element => graph.cache_key, :lang => I18n.locale.to_s})
Graph is a normal model.
-
Steve Purcell April 24th, 2011 @ 04:49 PM
Indeed. I still get the same error messages too. They didn't ever go away for me with any particular Rails release, so I'm not convinced that the fix was complete.
-
Create your profile
Help contribute to this project by taking a few moments to create your personal profile. Create your profile »
<h2 style="font-size: 14px">Tickets have moved to Github</h2>
The new ticket tracker is available at <a href="https://github.com/rails/rails/issues">https://github.com/rails/rails/issues</a>
People watching this ticket
Attachments
Referenced by
-
5570 Fragment cache logging fails in 3.0 when fragment path contains printf chars, e.g. "%A" (from [8639c10a40604cee2f3d412470c2960712fdc809]) Fix log...