Project without CI enabled logs an error

GitLab 8.2.rc1. Newly created project without CI enabled

 SQL (0.6ms)  UPDATE "ci_commits" SET "committed_at" = $1, "updated_at" = $2 WHERE "ci_commits"."id" = 3  [["committed_at", "2015-11-17 11:33:14.681096"], ["updated_at", "2015-11-17 11:33:14.682918"]]
   (1.7ms)  COMMIT
no implicit conversion of nil into String
/opt/gitlab/embedded/lib/ruby/2.1.0/psych.rb:370:in `parse'
/opt/gitlab/embedded/lib/ruby/2.1.0/psych.rb:370:in `parse_stream'
/opt/gitlab/embedded/lib/ruby/2.1.0/psych.rb:318:in `parse'
/opt/gitlab/embedded/lib/ruby/2.1.0/psych.rb:245:in `load'
/opt/gitlab/embedded/service/gitlab-rails/lib/ci/gitlab_ci_yaml_processor.rb:13:in `initialize'
/opt/gitlab/embedded/service/gitlab-rails/app/models/ci/commit.rb:191:in `new'
/opt/gitlab/embedded/service/gitlab-rails/app/models/ci/commit.rb:191:in `config_processor'
/opt/gitlab/embedded/service/gitlab-rails/app/models/ci/commit.rb:93:in `create_builds'
/opt/gitlab/embedded/service/gitlab-rails/app/services/ci/create_commit_service.rb:22:in `execute'
/opt/gitlab/embedded/service/gitlab-rails/app/models/project_services/gitlab_ci_service.rb:46:in `execute'
/opt/gitlab/embedded/service/gitlab-rails/app/workers/project_service_worker.rb:8:in `perform'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/processor.rb:75:in `execute_job'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/processor.rb:52:in `block (2 levels) in process'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/chain.rb:127:in `call'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/chain.rb:127:in `block in invoke'
/opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/sidekiq_middleware/memory_killer.rb:17:in `call'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidetiq-0.6.3/lib/sidetiq/middleware/history.rb:8:in `call'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/server/active_record.rb:6:in `call'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/server/retry_jobs.rb:74:in `call'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/server/logging.rb:11:in `block in call'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/logging.rb:22:in `with_context'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/server/logging.rb:7:in `call'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/chain.rb:132:in `call'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/middleware/chain.rb:132:in `invoke'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/processor.rb:51:in `block in process'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/processor.rb:98:in `stats'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-3.3.0/lib/sidekiq/processor.rb:50:in `process'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
/opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'

@ayufan Does this ring a bell?

This is ok. The exception is logged to production.log. Later we see:

2015-11-17_14:00:10.79885 2015-11-17T14:00:10.798Z 8506 TID-cg8ek ProjectServiceWorker JID-0016c7e21a19117a1045ca3c INFO: done: 0.113 sec

So it means that ProjectServiceWorker (the gitlab_ci_service) did succeed.

Status changed to closed

@ayufan While you do say it is ok, this will cause a lot of new raised issues with people providing this stack trace as the description of the problem. It will also lead some people in a different direction when trying to debug their server issues. Can we do something about this, catch the exception?

Status changed to reopened

@ayufan why is it OK to have exceptions in production.log? If this is an expected failure we should handle the exception.

mentioned in merge request !1827 (merged)

mentioned in commit 0383f84d

mentioned in commit 978f0bac

Status changed to closed

mentioned in merge request !14785