Note that there are some explanatory texts on larger screens.

plurals
  1. POStange random crashes with Rails 3.1 in production
    text
    copied!<p>I see some stange random crashes with my brand new Rails 3.1 rc5 application running in production mode. The backend is nginx with 3 thin instances.</p> <pre><code>[Exception] users#show (NoMethodError) "undefined method `text?' for nil:NilClass" undefined method `text?' for nil:NilClass  activerecord (3.1.0.rc5) lib/active_record/validations/uniqueness.rb:57:in `build_relation' </code></pre> <p>I turned on log: debug. However the only information is "Internal Server Error" Anyone seen this before? Identity map is turned om...</p> <p>If I restart the thin, Rails will run without problems for a few hours.</p> <p><strong>Update1:</strong> Looks like it is pretty much all my controller actions that generate this error randomly. This morning I got an email with the error above. If I follow the link, the page is generated with no problems.</p> <p>I was wondering if this issue somehow could be related to problems loading the User from a cookie?</p> <pre><code>class ApplicationController &lt; ActionController::Base protect_from_forgery layout "content_with_sidebar" before_filter :system rescue_from CanCan::AccessDenied do |exception| flash[:warning] = "Ingen adgang!" redirect_to root_url end def system if current_user unless current_user.email_verified == "t" flash[:warning] = 'Please activate your account.' end current_user.last_seen = Time.now current_user.save # &lt;--- line 18 @new_messages = Message.new_messages(current_user).count end end helper_method :current_user private def current_user if cookies[:auth_token] @current_user ||= User.find_by_auth_token!(cookies[:auth_token]) end end end </code></pre> <p><strong>Code Example from Users#Show</strong></p> <pre><code>class UsersController &lt; ApplicationController before_filter :ensure_current_user_url, :only =&gt; :show load_and_authorize_resource def ensure_current_user_url @user = User.find(params[:id].downcase) redirect_to @user, :status =&gt; :moved_permanently unless @user.friendly_id_status.best? end def show if params[:do] == "guestbook" @comment = @user.comments.new @comments = @user.comments.includes(:author).order("created_at DESC").all(:limit =&gt; 5) else @recent_comments = @user.comments(:order =&gt; "created_at DESC") end @arts = @user.arts.order("created_at desc").includes([:author, :category]).page(params[:page]).per(24) render :layout =&gt; "content_with_sidebar_whitebox" end </code></pre> <p><strong>Update2</strong> This is the information I got with the debug added.</p> <pre><code>************** username ************** ["id", "username", "email", "email_verified", "birthday", "firstname", "lastname", "phone", "website", "profile", "last_seen", "administrator", "cached_slug", "password_salt", "crypted_password", "avatar", "avatar_cache", "comments_count", "arts_count", "auth_token", "account_activation_token", "account_activation_sent_at", "password_reset_token", "password_reset_sent_at", "created_at", "updated_at", "cheapest", "most_expensive"] ************** email ************** ["id", "username", "email", "email_verified", "birthday", "firstname", "lastname", "phone", "website", "profile", "last_seen", "administrator", "cached_slug", "password_salt", "crypted_password", "avatar", "avatar_cache", "comments_count", "arts_count", "auth_token", "account_activation_token", "account_activation_sent_at", "password_reset_token", "password_reset_sent_at", "created_at", "updated_at", "cheapest", "most_expensive"] </code></pre> <p>This is a full stack trace from a crash this morning. </p> <pre><code>Started GET "/messages" for filtered-ip at 2011-08-15 12:13:17 -0400 Processing by MessagesController#index as HTML User Load (1.5ms) SELECT "users".* FROM "users" WHERE "users"."auth_token" = '380e8b776cb8e3c5fd7d8b777b6d2073' ORDER BY last_seen desc LIMIT 1 (0.3ms) BEGIN (0.9ms) SELECT 1 FROM "users" WHERE ("users"."username" = 'samia-dk' AND "users"."id" != 483) LIMIT 1 (0.9ms) SELECT 1 FROM "users" WHERE ("users"."email" = 'mail@filtered.dk' AND "users"."id" != 483) LIMIT 1 (0.4ms) ROLLBACK Completed 500 Internal Server Error in 14ms Rendered /usr/local/rvm/gems/ruby-1.9.2-p290-dev@myblog5/gems/exception_notification_rails3-1.2.0/lib/exception_notifier/views/exception_notifier/_request.text.erb (0.8ms) Rendered /usr/local/rvm/gems/ruby-1.9.2-p290-dev@myblog5/gems/exception_notification_rails3-1.2.0/lib/exception_notifier/views/exception_notifier/_title.text.erb (0.4ms) Rendered /usr/local/rvm/gems/ruby-1.9.2-p290-dev@myblog5/gems/exception_notification_rails3-1.2.0/lib/exception_notifier/views/exception_notifier/_session.text.erb (0.9ms) Rendered /usr/local/rvm/gems/ruby-1.9.2-p290-dev@myblog5/gems/exception_notification_rails3-1.2.0/lib/exception_notifier/views/exception_notifier/_title.text.erb (0.1ms) Rendered /usr/local/rvm/gems/ruby-1.9.2-p290-dev@myblog5/gems/exception_notification_rails3-1.2.0/lib/exception_notifier/views/exception_notifier/_environment.text.erb (55.3ms) Rendered /usr/local/rvm/gems/ruby-1.9.2-p290-dev@myblog5/gems/exception_notification_rails3-1.2.0/lib/exception_notifier/views/exception_notifier/_title.text.erb (0.3ms) Rendered /usr/local/rvm/gems/ruby-1.9.2-p290-dev@myblog5/gems/exception_notification_rails3-1.2.0/lib/exception_notifier/views/exception_notifier/_backtrace.text.erb (1.7ms) Rendered /usr/local/rvm/gems/ruby-1.9.2-p290-dev@myblog5/gems/exception_notification_rails3-1.2.0/lib/exception_notifier/views/exception_notifier/_title.text.erb (0.2ms) Rendered /usr/local/rvm/gems/ruby-1.9.2-p290-dev@myblog5/gems/exception_notification_rails3-1.2.0/lib/exception_notifier/views/exception_notifier/exception_notification.text.erb (71.8ms) Sent mail to some@mail.com (3072ms) Date: Mon, 15 Aug 2011 12:13:18 -0400 From: Exception Notifier &lt;robot@myblog.dk&gt; To: some@mail.com Message-ID: &lt;4e49459e3709a_792610c8826e4@li267-196.mail&gt; Subject: [Exception] messages#index (NoMethodError) "undefined method `text?' for nil:NilClass" Mime-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit A NoMethodError occurred in messages#index: undefined method `text?' for nil:NilClass config/initializers/some_debug.rb:6:in `build_relation' ------------------------------- Request: ------------------------------- * URL : http://www.myblog.dk/messages * IP address: filtered * Parameters: {"action"=&gt;"index", "controller"=&gt;"messages"} * Rails root: /home/atmorell/Dropbox/myblog5 ------------------------------- Session: ------------------------------- * session id: nil * data: {"_csrf_token"=&gt;"filtered=", "user_credentials"=&gt;true, "user_credentials_id"=&gt;483} ------------------------------- Environment: ------------------------------- * GATEWAY_INTERFACE : CGI/1.2 * HTTP_ACCEPT : text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 * HTTP_ACCEPT_CHARSET : ISO-8859-1,utf-8;q=0.7,*;q=0.7 * HTTP_ACCEPT_ENCODING : gzip, deflate * HTTP_ACCEPT_LANGUAGE : en,da;q=0.7,en-us;q=0.3 * HTTP_CONNECTION : close * HTTP_COOKIE : __utma=52641074.268317442.1313423882.1313423882.1313423882.1; __utmb=52641074.53.10.1313423882; __utmc=52641074; __utmz=52641074.1313423882.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none); _myblog_session5=ed471364634fcd3b44c7bb0eae758b14; user_credentials=true%3A%3A483; auth_token=filtered * HTTP_HOST : www.myblog.dk * HTTP_REFERER : http://www.myblog.dk/messages/new * HTTP_USER_AGENT : Mozilla/5.0 (Windows NT 6.1; WOW64; rv:5.0) Gecko/20100101 Firefox/5.0 * HTTP_VERSION : HTTP/1.0 * PATH_INFO : /messages * QUERY_STRING : * REMOTE_ADDR : filtered-ip * REQUEST_METHOD : GET * REQUEST_PATH : /messages * REQUEST_URI : /messages * SCRIPT_NAME : * SERVER_NAME : www.myblog.dk * SERVER_PORT : 80 * SERVER_PROTOCOL : HTTP/1.1 * SERVER_SOFTWARE : thin 1.2.11 codename Bat-Shit Crazy * action_controller.instance : messages#index * action_dispatch.cookies : #&lt;ActionDispatch::Cookies::CookieJar:0x00000008766b98&gt; * action_dispatch.parameter_filter : [:password, /RAW_POST_DATA/] * action_dispatch.remote_ip : filtered-ip * action_dispatch.request.content_type : * action_dispatch.request.formats : [text/html] * action_dispatch.request.parameters : {"action"=&gt;"index", "controller"=&gt;"messages"} * action_dispatch.request.path_parameters : {:action=&gt;"index", :controller=&gt;"messages"} * action_dispatch.request.query_parameters : {} * action_dispatch.request.request_parameters: {} * action_dispatch.routes : #&lt;ActionDispatch::Routing::RouteSet:0x00000002eaf658&gt; * action_dispatch.secret_token : 93479c2e63bdb766a51f18397345cdc9a8b22ee009334171207f6b0bc2e71105d1f849de46e34965febc3b178cea662e89986e73d8922ec4915c44dca6ae4000 * action_dispatch.show_exceptions : true * async.callback : #&lt;Method: Thin::Connection#post_process&gt; * async.close : #&lt;EventMachine::DefaultDeferrable:0x000000087809a8&gt; * exception_notifier.options : {:email_prefix=&gt;"[Exception] ", :sender_address=&gt;"\"Exception Notifier\" &lt;robot@myblog.dk&gt;", :exception_recipients=&gt;["some@mail.com"], :ignore_exceptions=&gt;[ActiveRecord::RecordNotFound, AbstractController::ActionNotFound, ActionController::RoutingError]} * rack-cache.allow_reload : false * rack-cache.allow_revalidate : false * rack-cache.cache_key : Rack::Cache::Key * rack-cache.default_ttl : 0 * rack-cache.entitystore : rails:/ * rack-cache.metastore : rails:/ * rack-cache.private_headers : ["Authorization", "Cookie"] * rack-cache.storage : #&lt;Rack::Cache::Storage:0x000000029e9b50&gt; * rack-cache.verbose : true * rack.errors : #&lt;IO:0x00000000c27860&gt; * rack.input : #&lt;StringIO:0x00000008784c10&gt; * rack.multiprocess : false * rack.multithread : false * rack.request.cookie_hash : {"__utma"=&gt;"52641074.268317442.1313423882.1313423882.1313423882.1", "__utmb"=&gt;"52641074.53.10.1313423882", "__utmc"=&gt;"52641074", "__utmz"=&gt;"52641074.1313423882.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none)", "_myblog_session5"=&gt;"ed471364634fcd3b44c7bb0eae758b14", "user_credentials"=&gt;"true::483", "auth_token"=&gt;"filtered"} * rack.request.cookie_string : __utma=52641074.268317442.1313423882.1313423882.1313423882.1; __utmb=52641074.53.10.1313423882; __utmc=52641074; __utmz=52641074.1313423882.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none); _myblog_session5=ed471364634fcd3b44c7bb0eae758b14; user_credentials=true%3A%3A483; auth_token=filtered * rack.request.query_hash : {} * rack.request.query_string : * rack.run_once : false * rack.session : {"_csrf_token"=&gt;"jlK/filtered=", "user_credentials"=&gt;true, "user_credentials_id"=&gt;483} * rack.session.options : {:key=&gt;"_myblog_session5", :path=&gt;"/", :domain=&gt;nil, :expire_after=&gt;nil, :secure=&gt;false, :httponly=&gt;true, :defer=&gt;false, :renew=&gt;false, :id=&gt;"ed471364634fcd3b44c7bb0eae758b14"} * rack.session.record : #&lt;ActiveRecord::SessionStore::Session:0x000000087762f0&gt; * rack.url_scheme : http * rack.version : [1, 0] * Process: 1938 * Server : li267-196 ------------------------------- Backtrace: ------------------------------- config/initializers/some_debug.rb:6:in `build_relation' activerecord (3.1.0.rc5) lib/active_record/validations/uniqueness.rb:25:in `validate_each' activemodel (3.1.0.rc5) lib/active_model/validator.rb:153:in `block in validate' activemodel (3.1.0.rc5) lib/active_model/validator.rb:150:in `each' activemodel (3.1.0.rc5) lib/active_model/validator.rb:150:in `validate' activesupport (3.1.0.rc5) lib/active_support/callbacks.rb:302:in `_callback_before_483' activesupport (3.1.0.rc5) lib/active_support/callbacks.rb:622:in `_run_validate_callbacks' activesupport (3.1.0.rc5) lib/active_support/callbacks.rb:81:in `run_callbacks' activemodel (3.1.0.rc5) lib/active_model/validations.rb:212:in `run_validations!' activemodel (3.1.0.rc5) lib/active_model/validations/callbacks.rb:53:in `block in run_validations!' activesupport (3.1.0.rc5) lib/active_support/callbacks.rb:401:in `_run_validation_callbacks' activesupport (3.1.0.rc5) lib/active_support/callbacks.rb:81:in `run_callbacks' activemodel (3.1.0.rc5) lib/active_model/validations/callbacks.rb:53:in `run_validations!' activemodel (3.1.0.rc5) lib/active_model/validations.rb:179:in `valid?' activerecord (3.1.0.rc5) lib/active_record/validations.rb:69:in `valid?' activerecord (3.1.0.rc5) lib/active_record/validations.rb:77:in `perform_validations' activerecord (3.1.0.rc5) lib/active_record/validations.rb:50:in `save' activerecord (3.1.0.rc5) lib/active_record/attribute_methods/dirty.rb:22:in `save' activerecord (3.1.0.rc5) lib/active_record/transactions.rb:241:in `block (2 levels) in save' activerecord (3.1.0.rc5) lib/active_record/transactions.rb:295:in `block in with_transaction_returning_status' activerecord (3.1.0.rc5) lib/active_record/connection_adapters/abstract/database_statements.rb:183:in `transaction' activerecord (3.1.0.rc5) lib/active_record/transactions.rb:208:in `transaction' activerecord (3.1.0.rc5) lib/active_record/transactions.rb:293:in `with_transaction_returning_status' activerecord (3.1.0.rc5) lib/active_record/transactions.rb:241:in `block in save' activerecord (3.1.0.rc5) lib/active_record/transactions.rb:252:in `rollback_active_record_state!' activerecord (3.1.0.rc5) lib/active_record/transactions.rb:240:in `save' app/controllers/application_controller.rb:18:in `system' activesupport (3.1.0.rc5) lib/active_support/callbacks.rb:430:in `_run__163591495713425608__process_action__3187008165500041637__callbacks' activesupport (3.1.0.rc5) lib/active_support/callbacks.rb:386:in `_run_process_action_callbacks' activesupport (3.1.0.rc5) lib/active_support/callbacks.rb:81:in `run_callbacks' actionpack (3.1.0.rc5) lib/abstract_controller/callbacks.rb:17:in `process_action' actionpack (3.1.0.rc5) lib/action_controller/metal/rescue.rb:17:in `process_action' actionpack (3.1.0.rc5) lib/action_controller/metal/instrumentation.rb:30:in `block in process_action' activesupport (3.1.0.rc5) lib/active_support/notifications.rb:55:in `block in instrument' activesupport (3.1.0.rc5) lib/active_support/notifications/instrumenter.rb:21:in `instrument' activesupport (3.1.0.rc5) lib/active_support/notifications.rb:55:in `instrument' actionpack (3.1.0.rc5) lib/action_controller/metal/instrumentation.rb:29:in `process_action' actionpack (3.1.0.rc5) lib/action_controller/metal/params_wrapper.rb:202:in `process_action' activerecord (3.1.0.rc5) lib/active_record/railties/controller_runtime.rb:18:in `process_action' actionpack (3.1.0.rc5) lib/abstract_controller/base.rb:121:in `process' actionpack (3.1.0.rc5) lib/abstract_controller/rendering.rb:45:in `process' actionpack (3.1.0.rc5) lib/action_controller/metal.rb:193:in `dispatch' actionpack (3.1.0.rc5) lib/action_controller/metal/rack_delegation.rb:14:in `dispatch' actionpack (3.1.0.rc5) lib/action_controller/metal.rb:236:in `block in action' actionpack (3.1.0.rc5) lib/action_dispatch/routing/route_set.rb:65:in `call' actionpack (3.1.0.rc5) lib/action_dispatch/routing/route_set.rb:65:in `dispatch' actionpack (3.1.0.rc5) lib/action_dispatch/routing/route_set.rb:29:in `call' rack-mount (0.8.2) lib/rack/mount/route_set.rb:152:in `block in call' rack-mount (0.8.2) lib/rack/mount/code_generation.rb:96:in `block in recognize' rack-mount (0.8.2) lib/rack/mount/code_generation.rb:68:in `optimized_each' rack-mount (0.8.2) lib/rack/mount/code_generation.rb:95:in `recognize' rack-mount (0.8.2) lib/rack/mount/route_set.rb:141:in `call' actionpack (3.1.0.rc5) lib/action_dispatch/routing/route_set.rb:531:in `call' oa-core (0.2.6) lib/omniauth/strategy.rb:44:in `call!' oa-core (0.2.6) lib/omniauth/strategy.rb:30:in `call' oa-core (0.2.6) lib/omniauth/strategy.rb:44:in `call!' oa-core (0.2.6) lib/omniauth/strategy.rb:30:in `call' oa-core (0.2.6) lib/omniauth/strategy.rb:44:in `call!' oa-core (0.2.6) lib/omniauth/strategy.rb:30:in `call' oa-core (0.2.6) lib/omniauth/builder.rb:30:in `call' exception_notification_rails3 (1.2.0) lib/exception_notifier.rb:34:in `call' actionpack (3.1.0.rc5) lib/action_dispatch/middleware/best_standards_support.rb:17:in `call' rack (1.3.2) lib/rack/etag.rb:23:in `call' rack (1.3.2) lib/rack/conditionalget.rb:25:in `call' actionpack (3.1.0.rc5) lib/action_dispatch/middleware/head.rb:14:in `call' actionpack (3.1.0.rc5) lib/action_dispatch/middleware/params_parser.rb:21:in `call' actionpack (3.1.0.rc5) lib/action_dispatch/middleware/flash.rb:243:in `call' rack (1.3.2) lib/rack/session/abstract/id.rb:195:in `context' rack (1.3.2) lib/rack/session/abstract/id.rb:190:in `call' actionpack (3.1.0.rc5) lib/action_dispatch/middleware/cookies.rb:326:in `call' activerecord (3.1.0.rc5) lib/active_record/query_cache.rb:62:in `call' activerecord (3.1.0.rc5) lib/active_record/connection_adapters/abstract/connection_pool.rb:466:in `call' actionpack (3.1.0.rc5) lib/action_dispatch/middleware/callbacks.rb:29:in `block in call' activesupport (3.1.0.rc5) lib/active_support/callbacks.rb:392:in `_run_call_callbacks' activesupport (3.1.0.rc5) lib/active_support/callbacks.rb:81:in `run_callbacks' actionpack (3.1.0.rc5) lib/action_dispatch/middleware/callbacks.rb:28:in `call' rack (1.3.2) lib/rack/sendfile.rb:101:in `call' actionpack (3.1.0.rc5) lib/action_dispatch/middleware/remote_ip.rb:48:in `call' actionpack (3.1.0.rc5) lib/action_dispatch/middleware/show_exceptions.rb:47:in `call' railties (3.1.0.rc5) lib/rails/rack/logger.rb:13:in `call' rack (1.3.2) lib/rack/methodoverride.rb:24:in `call' rack (1.3.2) lib/rack/runtime.rb:17:in `call' activesupport (3.1.0.rc5) lib/active_support/cache/strategy/local_cache.rb:72:in `call' rack (1.3.2) lib/rack/lock.rb:15:in `call' actionpack (3.1.0.rc5) lib/action_dispatch/middleware/static.rb:53:in `call' rack-cache (1.0.2) lib/rack/cache/context.rb:132:in `forward' rack-cache (1.0.2) lib/rack/cache/context.rb:243:in `fetch' rack-cache (1.0.2) lib/rack/cache/context.rb:181:in `lookup' rack-cache (1.0.2) lib/rack/cache/context.rb:65:in `call!' rack-cache (1.0.2) lib/rack/cache/context.rb:50:in `call' railties (3.1.0.rc5) lib/rails/engine.rb:455:in `call' railties (3.1.0.rc5) lib/rails/railtie/configurable.rb:30:in `method_missing' thin (1.2.11) lib/thin/connection.rb:84:in `block in pre_process' thin (1.2.11) lib/thin/connection.rb:82:in `catch' thin (1.2.11) lib/thin/connection.rb:82:in `pre_process' thin (1.2.11) lib/thin/connection.rb:57:in `process' thin (1.2.11) lib/thin/connection.rb:42:in `receive_data' eventmachine (0.12.10) lib/eventmachine.rb:256:in `run_machine' eventmachine (0.12.10) lib/eventmachine.rb:256:in `run' thin (1.2.11) lib/thin/backends/base.rb:61:in `start' thin (1.2.11) lib/thin/server.rb:159:in `start' thin (1.2.11) lib/thin/controllers/controller.rb:86:in `start' thin (1.2.11) lib/thin/runner.rb:185:in `run_command' thin (1.2.11) lib/thin/runner.rb:151:in `run!' thin (1.2.11) bin/thin:6:in `&lt;top (required)&gt;' /usr/local/rvm/gems/ruby-1.9.2-p290-dev@myblog5/bin/thin:19:in `load' /usr/local/rvm/gems/ruby-1.9.2-p290-dev@myblog5/bin/thin:19:in `&lt;main&gt;' NoMethodError (undefined method `text?' for nil:NilClass): config/initializers/some_debug.rb:6:in `build_relation' app/controllers/application_controller.rb:18:in `system' </code></pre> <p>User.rb</p> <pre><code> # -*- encoding : utf-8 -*- class User &lt; ActiveRecord::Base attr_accessible :username, :email, :birthday, :firstname, :lastname, :phone, :website, :profile, :avatar, :password, :avatar_cache, :name, :last_seen, :arts_count, :cheapest, :most_expensive #, :email_verified, :crypted_password, :password_salt, :administrator, :id # Virtual attributes attr_accessor :password, :password_confirmation belongs_to :cheapest, :class_name =&gt; "Art", :foreign_key =&gt; :cheapest belongs_to :most_expensive, :class_name =&gt; "Art", :foreign_key =&gt; :most_expensive has_many :blogs, :dependent =&gt; :destroy has_many :arts, :dependent =&gt; :destroy has_many :authentications, :dependent =&gt; :destroy has_friendly_id :username, :use_slug =&gt; true has_many :comments, :as =&gt; :commentable, :validate =&gt; :false mount_uploader :avatar, AvatarUploader before_save :encrypt_password before_create { generate_token(:auth_token) } after_create { send_account_activation } validates_uniqueness_of :username, :email validates_presence_of :username, :email validate :password_length_without_authentications validates_format_of :username, :with =&gt; /^[-a-z\d_]+$/, :message =&gt; "kun små bogstaver, tal og bindestreger. f.eks. galleri-toke" validates_length_of :username, :maximum=&gt;30, :message=&gt;"Dit brugernavn må max være 30 karakter." validates_length_of :username, :minimum=&gt;3, :message=&gt;"Dit brugernavn skal minimum være 3 karakter." validates_format_of :email, :with =&gt; /\A([^@\s]+)@((?:[-a-z0-9]+\.)+[a-z]{2,})\Z/i default_scope :order =&gt; "last_seen desc" #, :conditions =&gt; "username NOT LIKE 'robot'" scope :with_arts, where("arts_count &gt; 0") ... </code></pre> <p>Each time the user refreshed the page I update the last_seen column and save the logged_in user. For some reason the saving breaks. I have not been able to reproduce this on my development server.</p>
 

Querying!

 
Guidance

SQuiL has stopped working due to an internal error.

If you are curious you may find further information in the browser console, which is accessible through the devtools (F12).

Reload