search

samchen2009 / ekanban

a kanban plugin for redmine
102 stars 42 forks source link

Redmine 500 error on create new Issues #67

Closed tec-the-dark closed 10 years ago

tec-the-dark commented 10 years ago

Hello samchen2009,

at the moment we are testing redmine + ekanban and some other plugins to replace bugzilla for ever :)

after setting up a test project which a kanban issue board, I can't create any new issue without a redmine 500 error. I use redmine 2.3.3 on ruby 1.9.3p448 + ekanban from actual git repository.

Redmine errro logfile shows this entrys:

NoMethodError (undefined method []' for nil:NilClass): lib/redmine/hook.rb:61:inblock (2 levels) in call_hook' lib/redmine/hook.rb:61:in each' lib/redmine/hook.rb:61:inblock in call_hook' lib/redmine/hook.rb:58:in tap' lib/redmine/hook.rb:58:incall_hook' lib/redmine/hook.rb:153:in call_hook' app/controllers/issues_controller.rb:142:increate'

Is there something wrong in my setup? Do you need any other informations?

regards tec

samchen2009 commented 10 years ago

It's wield as the error occurred at code below (plugins/ekanban/lib/ekanban/ekanban_hooks.rb), you could add "puts context" to confirm whether context is nil.

   def controller_issues_new_after_save(context={})
     card = KanbanCard.build(context[:issue], context[:journal])
     true
   end

If it's true, more log is needed to debug, you can also add some logs around app/controllers/issues_controller.rb:142

tec-the-dark commented 10 years ago

Sorry for the late reply, but it was a lot to do in the last days.....

I tried to apply the advice, but the logfile entries do not change. I'm not a Ruby programmer, so I could have understood and implemented incorrectly.

vim ekanban/lib/ekanban/ekanban_hooks.rb

  def controller_issues_new_after_save(context={})
        card = KanbanCard.build(context[:issue], context[:journal])
        true

        puts context
      end

complete logfile output:

NoMethodError (undefined method `[]' for nil:NilClass):
  lib/redmine/hook.rb:61:in `block (2 levels) in call_hook'
  lib/redmine/hook.rb:61:in `each'
  lib/redmine/hook.rb:61:in `block in call_hook'
  lib/redmine/hook.rb:58:in `tap'
  lib/redmine/hook.rb:58:in `call_hook'
  lib/redmine/hook.rb:153:in `call_hook'
  app/controllers/issues_controller.rb:142:in `create'

regards tec

samchen2009 commented 10 years ago

Hi tec,

You could do like this:

def controller_issues_new_after_save(context={}) puts context card = KanbanCard.build(context[:issue], context[:journal]) true end

tec-the-dark commented 10 years ago

hi samchen2009,

Now I get a lot of output in the apache error log.

[ 2013-11-19 11:32:06.0639 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout] commit"=>"Create", "action"=>"create", "controller"=>"issues", "project_id"=>"standard_soe"}, "action_dispatch.request.formats"=>[text/html]}, @request_method="POST", @filtered_parameters={"utf8"=>"✓", "authenticity_token"=>"W18qYe8XjDzuXiJdPBP6Qj8/mrFaOYrJxzI5vhF2lDg=", "issue"=>{"is_private"=>"0", "tracker_id"=>"1", "subject"=>"test issue 136", "description"=>"<p>test test test ...</p>\r\n", "status_id"=>"1", "priority_id"=>"2", "assigned_to_id"=>"52", "category_id"=>"1306", "parent_issue_id"=>"", "start_date"=>"2013-11-19", "due_date"=>"2013-11-30", "estimated_hours"=>"14", "done_ratio"=>"0", "custom_field_values"=>{"1"=>""}, "watcher_user_ids"=>["52"]}, "new_checklist"=>"", "commit"=>"Create", "action"=>"create", "controller"=>"issues", "project_id"=>"standard_soe"}, @method="POST", @fullpath="/projects/standard_soe/issues">, @_response=#<ActionDispatch::Response:0xb4675b88 @body=[], @header={}, @status=200, @sending_file=false, @blank=false, @cache_control={}, @etag=nil, @request=#<ActionDispatch::Request:0xb4675b9c @env={"SERVER_ADDR"=>"172.25.17.152", "DOCUMENT_ROOT"=>"/var/www/redmine/public/", "PASSENGER_USER"=>"", "PASSENGER_MAX_REQUESTS"=>"0", "REQUEST_URI"=>"/projects/standard_soe/issues", "REMOTE_ADDR"=>"172.25.17.77", "SERVER_PORT"=>"80", "PASSENGER_GROUP"=>"", "RAILS_ENV"=>"production", "PASSENGER_SPAWN_METHOD"=>"smart", "REQUEST_METHOD"=>"POST", "HTTP_ACCEPT_LANGUAGE"=>"de,en-us;q=0.7,en;q=0.3", "QUERY_STRING"=>"", "REMOTE_PORT"=>"40699", "SERVER_ADMIN"=>"webmaster@localhost", "CONTENT_TYPE"=>"multipart/form-data; boundary=---------------------------29956213369555", "PASSENGER_ENV"=>"production", "PASSENGER_RUBY"=>"/usr/local/rvm/wrappers/ruby-1.9.3-p448/ruby", "HTTP_COOKIE"=>"pma_navi_width=236; _redmine_session=BAh7DUkiDHVzZXJfaWQGOgZFRmk5SSIKY3RpbWUGOwBGbCsHMh6LUkkiCmF0aW1lBjsARmwrB%2Bchi1JJIg9zZXNzaW9uX2lkBjsARkkiJWI1NjlmNjM3MzA5NWMwZTFlZDg1MDA5YjQzNTdmMzg2BjsAVEkiEF9jc3JmX3Rva2VuBjsARkkiMVcxOHFZZThYakR6dVhpSmRQQlA2UWo4L21yRmFPWXJKeHpJNXZoRjJsRGc9BjsARkkiFHJlY2VudF9wcm9qZWN0cwY7AEZbBmkBgUkiCnF1ZXJ5BjsARnsJOg9wcm9qZWN0X2lkaQGBOgxmaWx0ZXJzewZJIg5zdGF0dXNfaWQGOwBGewc6DW9wZXJhdG9ySSIGbwY7AEY6C3ZhbHVlc1sGSSIABjsARjoNZ3JvdXBfYnkwOhFjb2x1bW5fbmFtZXMwSSIWaXNzdWVzX2luZGV4X3NvcnQGOwBGSSIMaWQ6ZGVzYwY7AEY%3D--2671b819b1482e0ad3501e39f851e99e42e77b99; phpMyAdmin=jhs971pc6aq6856neb2ee9mvps2k652o; pma_lang=de; pma_collation_connection=utf8_general_ci", "HTTP_DNT"=>"1", "PASSENGER_APP_ROOT"=>"/var/www/redmine", "PASSENGER_MIN_INSTANCES"=>"1", "PASSENGER_APP_GROUP_NAME"=>"/var/www/redmine", "PASSENGER_MAX_PRELOADER_IDLE_TIME"=>"-1", "SERVER_NAME"=>"172.25.17.152", "PASSENGER_LOAD_SHELL_ENVVARS"=>"true", "PASSENGER_STAT_THROTTLE_RATE"=>"0", "SERVER_PROTOCOL"=>"HTTP/1.1", "SCRIPT_NAME"=>"", "HTTP_REFERER"=>"http://172.25.17.152/projects/standard_soe/issues", "HTTP_HOST"=>"172.25.17.152", "PASSENGER_START_TIMEOUT"=>"90", "HTTP_ACCEPT"=>"text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8", "SCRIPT_URI"=>"http://172.25.17.152/projects/standard_soe/issues", "SCRIPT_URL"=>"/projects/standard_soe/issues", "PASSENGER_APP_TYPE"=>"rack", "PASSENGER_DEBUGGER"=>"false", "HTTP_USER_AGENT"=>"Mozilla/5.0 (Windows NT 6.1; WOW64; rv:24.0) Gecko/20100101 Firefox/24.0", "PATH_INFO"=>"/projects/standard_soe/issues", "SERVER_SOFTWARE"=>"Apache/2.2.15 (CentOS)", "PASSENGER_SHOW_VERSION_IN_HEADER"=>"true", "HTTP_CONNECTION"=>"keep-alive", "PASSENGER_STATUS_LINE"=>"false", "CONTENT_LENGTH"=>"2380", "PASSENGER_FRIENDLY_ERROR_PAGES"=>"true", "HTTP_ACCEPT_ENCODING"=>"gzip, deflate", "PASSENGER_RESTART_DIR"=>"", "PASSENGER_CONNECT_PASSWORD"=>"HX0SUVsLWhgQw9pKhBhpwvTxs8WChxTDo8dYl58YcW3", "rack.version"=>[1, 2], "rack.input"=>#<PhusionPassenger::Utils::TeeInput:0xb48f8068 @len=2380, @socket=nil, @tmp=#<StringIO:0xb48f7ff0>>, "rack.errors"=>#<IO:<STDERR>>, "rack.multithread"=>false, "rack.multiprocess"=>true, "rack.run_once"=>false, "rack.url_scheme"=>"http", "rack.hijack?"=>true, "rack.hijack"=>#<Proc:0xb48f7fa0@/usr/local/rvm/gems/ruby-1.9.3-p448/gems/passenger-4.0.20/lib/phusion_passenger/rack/thread_handler_extension.rb:69 (lambda)>, "ORIGINAL_FULLPATH"=>"/projects/standard_soe/issues", "action_dispatch.routes"=>#<ActionDispatch::Routing::RouteSet:0x95f7478>, "action_dispatch.parameter_filter"=>[:password], "action_dispatch.secret_token"=>"4a0ae44a74c36f59e35b7e6e4346e6427d6df8ceadaeca37886a795e0b203245ce37db89367569a9", "action_dispatch.show_exceptions"=>true, "action_dispatch.show_detailed_exceptions"=>false, "action_dispatch.logger"=>#<Logger:0x962b6d8 @progname=nil, @level=3, @default_formatter=#<Logger::Formatter:0x962b64c @datetime_format=nil>, @formatter=#<Logger::SimpleFormatter:0x962b278 @datetime_format=nil>, @logdev=#<Logger::LogDevice:0x962b5d4 @shift_size=1048576, @shift_age=7, @filename="/var/log/redmine/production.log", @dev=#<File:/var/log/redmine/production.log>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x962b4d0 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x962b3e0>>>>, "action_dispatch.backtrace_cleaner"=>#<Rails::BacktraceCleaner:0xbd0a3f8 @filters=[#<Proc:0xbbb0200@/usr/local/rvm/gems/ruby-1.9.3-p448/gems/railties-3.2.15/lib/rails/backtrace_cleaner.rb:10>, #<Proc:0xbbb0534@/usr/local/rvm/gems/ruby-1.9.3-p448/gems/railties-3.2.15/lib/rails/backtrace_cleaner.rb:11>, #<Proc:0xbbb0548@/usr/local/rvm/gems/ruby-1.9.3-p448/gems/railties-3.2.15/lib/rails/backtrace_cleaner.rb:12>, #<Proc:0xb872818@/usr/local/rvm/gems/ruby-1.9.3-p448/gems/railties-3.2.15/lib/rails/backtrace_cleaner.rb:26>], @silencers=[#<Proc:0xb8734c0@/usr/local/rvm/gems/ruby-1.9.3-p448/gems/railties-3.2.15/lib/rails/backtrace_cleaner.rb:15>]>, "rack-cache.cache_key"=>Rack::Cache::Key, "rack-cache.verbose"=>false, "rack-cache.storage"=>#<Rack::Cache::Storage:0xa50f848 @metastores={"rails:/"=>#<ActionDispatch::RailsMetaStore:0xb4551b8 @store=#<ActiveSupport::Cache::FileStore:0x98574e8 @options={}, @cache_path="/var/www/redmine-2.4.0/tmp/cache/", @thread_local_key=:active_support_cache_file_store_local_cache_79870580, @middleware=#<ActiveSupport::Cache::Strategy::LocalCache::Middleware:0x96bde98 @name="ActiveSupport::Cache::Strategy::LocalCache", @thread_local_key=:active_support_cache_file_store_local_cache_79870580, @app=#<Rack::Runtime:0x8c63790 @app=#<Rack::MethodOverride:0x8c63880 @app=#<ActionDispatch::RequestId:0x8c64424 @app=#<Rails::Rack::Logger:0x8c64884 @app=#<ActionDispatch::ShowExceptions:0x8c654f0 @app=#<ActionDispatch::DebugExceptions:0x9a91358 @app=#<ActionDispatch::RemoteIp:0x9a92eb0 @app=#<ActionDispatch::Callbacks:0x9a934f0 @app=#<ActiveRecord::ConnectionAdapters::ConnectionManagement:0x9a93694 @app=#<ActiveRecord::QueryCache:0x9a93798 @app=#<ActionDispatch::Cookies:0x9a94760 @app=#<ActionDispatch::Session::CookieStore:0x92375f4 @secrets=["7379b86ac1cdc526e76606887e6dcf286a60c830ef80fdf1cee1d0e5f472"], @coder=#<Rack::Session::Cookie::Base64::Marshal:0x97676dc>, @app=#<ActionDispatch::Flash:0x9237be4 @app=#<RedmineDmsf::NoParse:0x9238490 @app=#<ActionDispatch::ParamsParser:0x9509804 @app=#<ActionDispatch::Head:0x9509ae8 @app=#<Rack::ConditionalGet:0x9509b60 @app=#<Rack::ETag:0x9509c14 @app=#<ActionDispatch::BestStandardsSupport:0x9509f20 @app=#<Rack::OpenID:0x950a880 @app=#<ActionDispatch::Routing::RouteSet:0x95f7478>, @store=#<OpenID::Store::Memory:0x9364c60 @associations={}, @nonces={}>>, @header="IE=Edge,chrome=1">, @cache_control="max-age=0, private, must-revalidate", @no_cache_control="no-cache">>>, @parsers={application/xml=>:xml_simple, application/json=>:json}>, @urls=["/dmsf/webdav"]>>, @default_options={:path=>"/", :domain=>nil, :expire_after=>nil, :secure=>false, :httponly=>true, :defer=>false, :renew=>false, :secret=>"7379b86ac1cdc526e76606887e6dcf286a60c830ef80fdf1cee1d0e5f472", :coder=>#<Rack::Session::Cookie::Base64::Marshal:0x97676dc>}, @key="_redmine_session", @cookie_only=true>>>>>, @check_ip=true, @proxies=/
[ 2013-11-19 11:32:06.0639 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout]       ^127\.0\.0\.1$                | # localhost
[ 2013-11-19 11:32:06.0639 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout]       ^(10                          | # private IP 10.x.x.x
[ 2013-11-19 11:32:06.0639 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout]         172\.(1[6-9]|2[0-9]|3[0-1]) | # private IP in the range 172.16.0.0 .. 172.31.255.255
[ 2013-11-19 11:32:06.0639 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout]         192\.168                      # private IP 192.168.x.x
[ 2013-11-19 11:32:06.0639 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout]        )\.
[ 2013-11-19 11:32:06.0639 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout]     /x>>, @exceptions_app=#<ActionDispatch::Pu
[ 2013-11-19 11:32:06.0640 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout] blicExceptions:0xa1e7670 @public_path="/var/www/redmine-2.4.0/public">>, @taggers=[]>>>, @header_name="X-Runtime">>>>}, @entitystores={"rails:/"=>#<ActionDispatch::RailsEntityStore:0xb8ec85c @store=#<ActiveSupport::Cache::FileStore:0x98574e8 @options={}, @cache_path="/var/www/redmine-2.4.0/tmp/cache/", @thread_local_key=:active_support_cache_file_store_local_cache_79870580, @middleware=#<ActiveSupport::Cache::Strategy::LocalCache::Middleware:0x96bde98 @name="ActiveSupport::Cache::Strategy::LocalCache", @thread_local_key=:active_support_cache_file_store_local_cache_79870580, @app=#<Rack::Runtime:0x8c63790 @app=#<Rack::MethodOverride:0x8c63880 @app=#<ActionDispatch::RequestId:0x8c64424 @app=#<Rails::Rack::Logger:0x8c64884 @app=#<ActionDispatch::ShowExceptions:0x8c654f0 @app=#<ActionDispatch::DebugExceptions:0x9a91358 @app=#<ActionDispatch::RemoteIp:0x9a92eb0 @app=#<ActionDispatch::Callbacks:0x9a934f0 @app=#<ActiveRecord::ConnectionAdapters::ConnectionManagement:0x9a93694 @app=#<ActiveRecord::QueryCache:0x9a93798 @app=#<ActionDispatch::Cookies:0x9a94760 @app=#<ActionDispatch::Session::CookieStore:0x92375f4 @secrets=["7379b86ac1cdc526e76606887e6dcf286a60c830ef80fdf1cee1d0e5f472"], @coder=#<Rack::Session::Cookie::Base64::Marshal:0x97676dc>, @app=#<ActionDispatch::Flash:0x9237be4 @app=#<RedmineDmsf::NoParse:0x9238490 @app=#<ActionDispatch::ParamsParser:0x9509804 @app=#<ActionDispatch::Head:0x9509ae8 @app=#<Rack::ConditionalGet:0x9509b60 @app=#<Rack::ETag:0x9509c14 @app=#<ActionDispatch::BestStandardsSupport:0x9509f20 @app=#<Rack::OpenID:0x950a880 @app=#<ActionDispatch::Routing::RouteSet:0x95f7478>, @store=#<OpenID::Store::Memory:0x9364c60 @associations={}, @nonces={}>>, @header="IE=Edge,chrome=1">, @cache_control="max-age=0, private, must-revalidate", @no_cache_control="no-cache">>>, @parsers={application/xml=>:xml_simple, application/json=>:json}>, @urls=["/dmsf/webdav"]>>, @default_options={:path=>"/", :domain=>nil, :expire_after=>nil, :secure=>false, :httponly=>true, :defer=>false, :renew=>false, :secret=>"7379b86ac1cdc526e76606887e6dcf286a60c830ef80fdf1cee1d0e5f472", :coder=>#<Rack::Session::Cookie::Base64::Marshal:0x97676dc>}, @key="_redmine_session", @cookie_only=true>>>>>, @check_ip=true, @proxies=/
[ 2013-11-19 11:32:06.0640 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout]       ^127\.0\.0\.1$                | # localhost
[ 2013-11-19 11:32:06.0640 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout]       ^(10                          | # private IP 10.x.x.x
[ 2013-11-19 11:32:06.0640 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout]         172\.(1[6-9]|2[0-9]|3[0-1]) | # private IP in the range 172.16.0.0 .. 172.31.255.255
[ 2013-11-19 11:32:06.0640 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout]         192\.168                      # private IP 192.168.x.x
[ 2013-11-19 11:32:06.0640 18220/b5175b70 Pool2/Implementation.cpp:1274 ]: [App 18277 stdout]        )\.

btw. the redmine log is the same as before.

I hope this helps to find the issue.

regards tec

tec-the-dark commented 10 years ago

In the meantime, we tested Redmine 2.4.0, because of a issue that could have something to do with it.

Defect #15044: Patch for giving controller_issues_edit_after_save api hook the correct context

But the result was the same as befor. :(

samchen2009 commented 10 years ago

Ah, from the log, context passed to ekanban is fine, so ekanban may not be the cause, you may need to check whether other plugins you installed introduce this issue? You can 'grep' to check whether some of them have function "controller_issues_new_after_save" and uninstall it to have a try.

tec-the-dark commented 10 years ago

wow that was easy :) thank you samchen2009

the culprit was the plugin: "redmine_issue_checklist"

regards tec