Strange errors in dev.log and webserver log

Hi guys,

I have encountered a strange error in one of my applications.

The details are the following:

The application is a very simple one, I have one model, Cards, it has
some pretty basic stuff, some after_save methods for saving uploaded
files to their places.

I have an UI where I can manage the Card records, with the default
methods, including ‘edit’

cards_controller.rb:

def edit

logger.info “Loading Card with ID: #{params[:id]}”

@card = Card.find( params[:id] )

end

Now each time I use the /cards/edit/3 (or any other valid id), I got
my card object properly loaded up onto the admin ui.

However - and here comes the strangeness - I see the following errors
in my dev and web logs:

development.log:

Processing CardsController#edit (for 192.168.2.6 at 2006-09-26 16:34:01)
[GET]
Session ID: 548258e6b4bb56506af5cb9859226509
Parameters: {“action”=>“edit”, “id”=>“5”, “controller”=>“cards”}
Loading Card with ID: 5
Card Load (0.003020) SELECT * FROM cards WHERE (cards.id = ‘5’)
LIMIT 1
Rendering within layouts/admin
Rendering cards/edit
Card Columns (0.004928) SHOW FIELDS FROM cards
Tag Load (0.001597) SELECT tags.* FROM tags INNER JOIN taggings ON
tags.id = taggings.tag_id WHERE (taggings.taggable_id = 5 AND
taggings.taggable_type = ‘Card’)
Tag Load (0.002008) SELECT * FROM tags
Tag Columns (0.003178) SHOW FIELDS FROM tags
Rendered cards/_form (0.02718)
Completed in 0.05205 (19 reqs/sec) | Rendering: 0.02855 (54%) | DB:
0.01755 (33%) | 200 OK [http://dev/cards/edit/5]

Processing IndexController#not_found (for 192.168.2.6 at 2006-09-26
16:34:01) [GET]
Session ID: 548258e6b4bb56506af5cb9859226509
Parameters: {“anything”=>[“images”, “fieldbg.gif”],
“action”=>“not_found”, “controller”=>“index”}
Rendering public/404.html
Completed in 0.00269 (371 reqs/sec) | Rendering: 0.00098 (36%) | DB:
0.00000 (0%) | 200 OK [http://dev/images/fieldbg.gif]

Processing CardsController#edit (for 192.168.2.6 at 2006-09-26 16:34:01)
[GET]
Session ID: 548258e6b4bb56506af5cb9859226509
Parameters: {“action”=>“edit”, “id”=>“undefined”,
“controller”=>“cards”}
Loading Card with ID: undefined
Card Load (0.002735) SELECT * FROM cards WHERE (cards.id =
‘undefined’) LIMIT 1

ActiveRecord::RecordNotFound (Couldn’t find Card with ID=undefined):
/usr/lib/ruby/gems/1.8/gems/activerecord-1.14.4/lib/active_record/base.rb:955:in
find_one' /usr/lib/ruby/gems/1.8/gems/activerecord-1.14.4/lib/active_record/base.rb:941:in find_from_ids’
/usr/lib/ruby/gems/1.8/gems/activerecord-1.14.4/lib/active_record/base.rb:382:in
find' .//app/controllers/cards_controller.rb:36:in edit’
/usr/lib/ruby/gems/1.8/gems/actionpack-1.12.5/lib/action_controller/base.rb:941:in
perform_action_without_filters' /usr/lib/ruby/gems/1.8/gems/actionpack-1.12.5/lib/action_controller/filters.rb:368:in perform_action_without_benchmark’
/usr/lib/ruby/gems/1.8/gems/actionpack-1.12.5/lib/action_controller/benchmarking.rb:69:in
perform_action_without_rescue' /usr/lib/ruby/1.8/benchmark.rb:293:in measure’
/usr/lib/ruby/gems/1.8/gems/actionpack-1.12.5/lib/action_controller/benchmarking.rb:69:in
perform_action_without_rescue' /usr/lib/ruby/gems/1.8/gems/actionpack-1.12.5/lib/action_controller/rescue.rb:82:in perform_action’
/usr/lib/ruby/gems/1.8/gems/actionpack-1.12.5/lib/action_controller/base.rb:408:in
process_without_filters' /usr/lib/ruby/gems/1.8/gems/actionpack-1.12.5/lib/action_controller/filters.rb:377:in process_without_session_management_support’
/usr/lib/ruby/gems/1.8/gems/actionpack-1.12.5/lib/action_controller/session_management.rb:117:in
process' /usr/lib/ruby/gems/1.8/gems/rails-1.1.6/lib/dispatcher.rb:38:in dispatch’
/usr/lib/ruby/gems/1.8/gems/rails-1.1.6/lib/webrick_server.rb:115:in
handle_dispatch' /usr/lib/ruby/gems/1.8/gems/rails-1.1.6/lib/webrick_server.rb:81:in service’
/usr/lib/ruby/1.8/webrick/httpserver.rb:104:in service' /usr/lib/ruby/1.8/webrick/httpserver.rb:65:in run’
/usr/lib/ruby/1.8/webrick/server.rb:173:in start_thread' /usr/lib/ruby/1.8/webrick/server.rb:162:in start_thread’
/usr/lib/ruby/1.8/webrick/server.rb:95:in start' /usr/lib/ruby/1.8/webrick/server.rb:92:in start’
/usr/lib/ruby/1.8/webrick/server.rb:23:in start' /usr/lib/ruby/1.8/webrick/server.rb:82:in start’
/usr/lib/ruby/gems/1.8/gems/rails-1.1.6/lib/webrick_server.rb:67:in
dispatch' /usr/lib/ruby/gems/1.8/gems/rails-1.1.6/lib/commands/servers/webrick.rb:59 /usr/lib/ruby/1.8/rubygems/custom_require.rb:21:in require’
/usr/lib/ruby/gems/1.8/gems/activesupport-1.3.1/lib/active_support/dependencies.rb:147:in
require' /usr/lib/ruby/gems/1.8/gems/rails-1.1.6/lib/commands/server.rb:30 /usr/lib/ruby/1.8/rubygems/custom_require.rb:21:in require’
/usr/lib/ruby/gems/1.8/gems/activesupport-1.3.1/lib/active_support/dependencies.rb:147:in
`require’
script/server:3

Rendering
/usr/lib/ruby/gems/1.8/gems/actionpack-1.12.5/lib/action_controller/templates/rescues/layout.rhtml
(500 Internal Error)

Webrick log:

192.168.2.6 - - [26/Sep/2006:16:34:01 CEST] “GET /cards/edit/5
HTTP/1.1” 200 3981
http://dev:3000/admin → /cards/edit/5

192.168.2.6 - - [26/Sep/2006:16:34:01 CEST] “GET /cards/edit/undefined
HTTP/1.1” 500 7649
http://dev:3000/cards/edit/5 → /cards/edit/undefined

As you can see, the first request loads up properly, the page with the
admin ui is fine, no errors whatsoever, but before the request
completes, there is another /cards/edit/undefined request somehow,
which throws an exception … and gets an internal server error.

However, the page doesn’t shows this, everything loads up properly, I
can save everything properly, everything working as it should.

Any clue what might be causing this?

I have attached the appropriate files for further reference.

Thanks for your help in advance,
András


András Tarsoly
[email protected]

Oh I forgot the system specs:

acts_as_taggable plugin latest, Rails 1.1.6, Ruby 1.8.4, FreeBSD 6.1,
running Webrick and MySQL 5.1

Regards,
András

András Tarsoly
[email protected]