Skip to content
Snippets Groups Projects
New issue look: Off

Merge in progress for hours

    • Closed Issue created by username-removed-304201 @funzie19

    I updated last week to the latest omnibus installer version of GitLab. Today one of my developers accepted a merge request which has been stuck in progress for about 4 hours now. I see the process in the Busy tab on the "Background Jobs" section. It lists 25 thread but 0 of them busy.

    Designs

      Child items ...

      2. Activity

      • username-removed-386624
        username-removed-386624 @connorshea ·
        Developer

        Can we have more information?

        Also, I'm pretty sure this is a duplicate.

      • username-removed-304201
        username-removed-304201 @funzie19 ·
        Author

        I have been looking at the logs but have not see anything, below is a screenshot of the Background Jobs page. Let me know if there is anything you want me to run or modify in order to get better logs.

        Screenshot_from_2016-05-31_14-46-30

      • username-removed-304201
        username-removed-304201 @funzie19 ·
        Author

        Also, is there any way to stop the merge request?

      • username-removed-284857
        username-removed-284857 @mohit2 ·

        I am also facing the same in one of our MRs, I created another MR between same source and destination branches, which merged easily, my old MR is in that state for atleast a day now.

      • username-removed-304201
        username-removed-304201 @funzie19 ·
        Author

        It happen again today, the merge request that was stuck earlier on the week was marked as closed after about 1.5 days. Here is some the output in the sidekiq.log

        2016-06-02_16:44:57.44428 2016-06-02T16:44:57.443Z 8047 TID-1o5a28 ProjectServiceWorker JID-a8954a16cc7a09c084d9198e INFO: done: 1.161 sec
2016-06-02_16:46:27.85011 2016-06-02T16:46:27.848Z 8047 TID-ash6o ActionMailer::DeliveryJob JID-53caef23bba66783078aaa4a INFO: start
2016-06-02_16:46:28.06819 2016-06-02T16:46:28.068Z 8047 TID-1o4yjs ProjectWebHookWorker JID-0da3cbd7c3128e8abc34d1f3 INFO: start
2016-06-02_16:46:28.41650 2016-06-02T16:46:28.416Z 8047 TID-ash6o ActionMailer::DeliveryJob JID-53caef23bba66783078aaa4a INFO: done: 0.567 sec
2016-06-02_16:46:31.67484 2016-06-02T16:46:31.674Z 8047 TID-1o4yjs ProjectWebHookWorker JID-0da3cbd7c3128e8abc34d1f3 INFO: done: 3.607 sec
2016-06-02_16:46:34.99510 2016-06-02T16:46:34.993Z 8047 TID-1o583o MergeWorker JID-03986a6df01a178d7aae735f INFO: start
2016-06-02_16:46:36.36308 2016-06-02T16:46:36.360Z 8047 TID-1785po WARN: sending SIGTERM to PID 8047
2016-06-02_16:46:36.37308 2016-06-02T16:46:36.372Z 8047 TID-avh9s INFO: Shutting down
2016-06-02_16:46:36.37310 2016-06-02T16:46:36.360Z 8047 TID-1785po WARN: waiting 30 seconds before sending SIGKILL to PID 8047
2016-06-02_16:46:36.38340 2016-06-02T16:46:36.383Z 8047 TID-at72w INFO: Scheduler exiting...
2016-06-02_16:46:36.39307 2016-06-02T16:46:36.384Z 8047 TID-avh9s INFO: Terminating quiet workers
2016-06-02_16:46:36.39310 2016-06-02T16:46:36.388Z 8047 TID-1o52rg INFO: Scheduler exiting...
2016-06-02_16:46:36.89037 2016-06-02T16:46:36.890Z 8047 TID-avh9s INFO: Pausing to allow workers to finish...
2016-06-02_16:46:39.90220 2016-06-02T16:46:39.901Z 8047 TID-avh9s WARN: Terminating 1 busy worker threads
2016-06-02_16:46:39.90300 2016-06-02T16:46:39.902Z 8047 TID-avh9s WARN: Work still in progress [#<struct Sidekiq::BasicFetch::UnitOfWork queue="queue:default", job="{\"class\":\"MergeWorker\",\"args\":[3780,27,{\"utf8\":\"✓\",\"authenticity_token\":\"REMOVED BY ME\",\"commit_message\":\"Merge branch 'facebook_changes' into 'facebook_changes'\\r\\n\\r\\n#12345 - removing most fql calls from the facebook api\\r\\n\\r\\n\\r\\n\\r\\nSee merge request !2601\",\"merge_when_build_succeeds\":\"\",\"button\":\"\",\"controller\":\"projects/merge_requests\",\"action\":\"merge\",\"namespace_id\":\"sproutloud\",\"project_id\":\"demo.com\",\"id\":\"2601\"}],\"retry\":true,\"queue\":\"default\",\"jid\":\"03986a6df01a178d7aae735f\",\"created_at\":1464885994.979444,\"enqueued_at\":1464885994.9801576}">]
2016-06-02_16:46:39.90347 2016-06-02T16:46:39.903Z 8047 TID-avh9s INFO: Pushed 1 jobs back to Redis
2016-06-02_16:46:39.90421 2016-06-02T16:46:39.904Z 8047 TID-avh9s INFO: Bye!
2016-06-02_16:47:12.23311 2016-06-02T16:47:12.232Z 27227 TID-9v4tc INFO: Booting Sidekiq 4.1.2 with redis options {:url=>"unix:/var/opt/gitlab/redis/redis.socket", :namespace=>"resque:gitlab"}
2016-06-02_16:47:12.31666 2016-06-02T16:47:12.316Z 27227 TID-9v4tc INFO: Cron Jobs - add job with name: stuck_ci_builds_worker
2016-06-02_16:47:12.33077 2016-06-02T16:47:12.330Z 27227 TID-9v4tc INFO: Cron Jobs - add job with name: repository_archive_cache_worker
2016-06-02_16:47:12.34078 2016-06-02T16:47:12.340Z 27227 TID-9v4tc INFO: Cron Jobs - add job with name: repository_check_worker
2016-06-02_16:47:12.34822 2016-06-02T16:47:12.348Z 27227 TID-9v4tc INFO: Cron Jobs - add job with name: admin_email_worker
2016-06-02_16:47:18.53362 2016-06-02T16:47:18.533Z 27227 TID-9v4tc INFO: Running in ruby 2.1.8p440 (2015-12-16 revision 53160) [x86_64-linux]
2016-06-02_16:47:18.53365 2016-06-02T16:47:18.533Z 27227 TID-9v4tc INFO: See LICENSE and the LGPL-3.0 for licensing details.
2016-06-02_16:47:18.53366 2016-06-02T16:47:18.533Z 27227 TID-9v4tc INFO: Upgrade to Sidekiq Pro for more features and support: http://sidekiq.org
2016-06-02_16:47:18.53458 2016-06-02T16:47:18.534Z 27227 TID-9v4tc INFO: Starting processing, hit Ctrl-C to stop
2016-06-02_16:47:18.76648 2016-06-02T16:47:18.766Z 27227 TID-14q44g MergeWorker JID-03986a6df01a178d7aae735f INFO: start
2016-06-02_16:47:18.93878 2016-06-02T16:47:18.938Z 27227 TID-14q44g MergeWorker JID-03986a6df01a178d7aae735f INFO: done: 0.172 sec
      • username-removed-119840
        username-removed-119840 @gasche ·

        I just hit a similar issue in a public repository hosted on gitlab.com. I searched for "merge in progress"-related bugs, and there seems to be many issues of this kind with gitlab.

        Also, I'm pretty sure this is a duplicate.

        Oh yes!

        It seems that there may be several distinct underlying issues (in some cases, the merge is actually accepted and visible in the repository, in some it is not, etc.) But one thing is clear: the merge request interface is fragile in case of errors, and it spins endlessly instead of letting users know whether something went wrong. I think this problem should be fixed and is rather important -- I mean "merge request" is a basic functionality in a git hosting service.

        For the record, I merged my problematic MR using the command-line, but I tried to re-create another repository in the same state with a similar MR to provide a reproducible setting for Gitlab devs. The repository is gc-latency-test, and I'm trying to merge the branch problematic-pr into master. This does not quite work, but it seems to reveal another bug: I am unable to open a pull request from the problematic-pr branch to the master branch, it claims the two branches are identical although they are clearly not. See this URL for reproduction (it is my "New Merge Request" page, with the two branches that should be preset), asking for "Compare branches and continue" fails.

      • username-removed-209562
        username-removed-209562 @detailyang ·

        we hit it on production , so are there any workaround or trick to solve this? i have troubleshooting this problem several days and cannot get any error log

        @stanhu could you check this thanks

        Edited by username-removed-209562
      • username-removed-304201
        username-removed-304201 @funzie19 ·
        Author

        @detailyang When I get this I usually hit close and wait. After x amount of time the merge is completed or cancelled.

      • username-removed-209562
        username-removed-209562 @detailyang ·

        @jkregloh_sprout thanks for you reply. i misleading you. Actually in our production, we merged the MR completely, but do not update the commit for the target branch:(

      • username-removed-180833
        username-removed-180833 @cifvts ·

        I've hit a similar problem: a MR has been accept, keep showing Merge in progress..., not in Merge Requests anymore, not in Merged, you can only get to that in All, its background color is white while others have a different shade. The code is merged in target branch so the issue is just in the status of the MR.

      • username-removed-108873
        username-removed-108873 @smartygus ·

        Just ran into this on a Gitlab instance running at my university (version 8.8.2).

        Hit accept, just kept spinning. Checked the commit history, and the merge was successful. But as far as Gitlab is concerned the Merge is still in progress...

      • Stan Hu
        Stan Hu @stanhu ·
        Maintainer

        There are a lot of things being discussed here. Let me try to tackle these issues one at at a time.

        Today one of my developers accepted a merge request which has been stuck in progress for about 4 hours now. I see the process in the Busy tab on the "Background Jobs" section. It lists 25 thread but 0 of them busy.

        https://gitlab.com/gitlab-org/gitlab-ce/issues/18048#note_12226199 suggests that MergeWorker got stuck, which explains why the UI was never updated. I haven't actually seen this problem on GitLab.com myself, so I'm not quite sure how to reproduce it. @jkregloh_sprout if this happens again, please take a look at the Sidekiq troubleshooting guide and see if you can figure out where it got stuck. The TTIN output from Sidekiq and gdb backtrace could be invaluable to understanding what happened.

        Also, next time this happens, I'd also recommend checking the state of the MR in the Rails console. For example, if you have a project called namespace/myproject and you want to see the state of MR 123, run sudo gitlab-rails console:

        proj = Project.find_with_namespace('namespace/myproject')
mr = proj.merge_requests.find_by(iid: 123)
mr.state

        we hit it on production , so are there any workaround or trick to solve this? i have troubleshooting this problem several days and cannot get any error log

        This is what is supposed to happen:

        1. User clicks "Merge"
        2. This schedules a MergeWorker Sidekiq task.
        3. MergeWorker executes the MergeService task.
        4. If MergeService succeeds, it marks the MR as successful.
        5. Otherwise, if it catches a standard error, it marks the MR as unsuccessful.

        The question: where does this go wrong? In the example mentioned earlier, if the MergeService gets stuck after step 3, then that's why no update was made.

        I would suggest looking at the state of the MR as described above.

        It seems that there may be several distinct underlying issues (in some cases, the merge is actually accepted and visible in the repository, in some it is not, etc.) But one thing is clear: the merge request interface is fragile in case of errors, and it spins endlessly instead of letting users know whether something went wrong. I think this problem should be fixed and is rather important -- I mean "merge request" is a basic functionality in a git hosting service.

        I agree, but until we understand the root problems, I think it would be premature to change things. The code for MergeService actually fits in one screen. The question is: what would help? For example, if a merge gets stuck after X hours, we could then cancel the merge, log an error, or attempt to abort. But we could be masking an underlying issue and making things worse.

        Perhaps @jacobvosmaer-gitlab has some ideas here.

        For the record, I merged my problematic MR using the command-line, but I tried to re-create another repository in the same state with a similar MR to provide a reproducible setting for Gitlab devs. The repository is gc-latency-test, and I'm trying to merge the branch problematic-pr into master. This does not quite work, but it seems to reveal another bug: I am unable to open a pull request from the problematic-pr branch to the master branch, it claims the two branches are identical although they are clearly not. See this URL for reproduction (it is my "New Merge Request" page, with the two branches that should be preset), asking for "Compare branches and continue" fails.

        Right now GitLab creates a merge request based on differences in the commits instead of differences in the actual files. For example, in the example provided, master is a direct descendent of problematic-pr:

        image

        Another words, from a commit point-of-view, problematic-pr has already been merged to master. Even if master alters the changes in problematic-pr, it will appear as though there are no diffs. I believe this is consistent with how git diff A..B works. There's a larger discussion here about this: https://gitlab.com/gitlab-org/gitlab-ce/issues/15140#note_11709832

        Edited by Stan Hu
      • Stan Hu
        Stan Hu @stanhu ·
        Maintainer

        Ok, this did happen on GitLab.com on !4932 (merged). This might be a duplicate of #15229 (closed). Here's some debug info:

        irb(main):004:0> mr.state
=> "locked"

        Searching the logs for Sidekiq parameters with MR ID 593462, I see no logs in Sidekiq that this merge even was attempted. This seems like a different symptom than the ones describes in this issue; it may be closer to #15229 (closed).

        I think we need to log every attempt to call perform_async by an async task. !4936 (merged) will help diagnose which job ID was terminated, but it might not tell us the MergeWorker JID.

      • Diana Stanley
        Diana Stanley @dstanley ·

        The logs given by @jkregloh_sprout are exactly the behavior we saw in #15229 (closed)

      • Jacob Vosmaer (GitLab)
        Jacob Vosmaer (GitLab) @jacobvosmaer-gitlab ·
        Contributor

        What if we give each lock a UUID, and when locking schedule an unlock Sidekiq job X minutes in the future that checks if the lock with that UUID is still in place and then removes it.

        Or we put a timestamp on the lock and when querying it (loading the MR page) we unlock the MR if it is X minutes old.

      • username-removed-304201
        username-removed-304201 @funzie19 ·
        Author

        Following up as I am dealing with this again. I followed the steps outlined by @stanhu previously to see the status of the MR, however the MR in question is not returned. It returns another MR which is in status "merged". Now the weird thing I am getting now is the MR that is stuck merging does not show in the "Merge Requests" section.

        If I enter the internal ID we use for the code committed on the search it doesn't show up in the Open, Merged, or Closed tabs. But it's shown in the All tab. I guess it doesn't fall into the other categories. Makes sense in a way.

        Now the good thing is that I found the following in the sidekiq.log. Ideas on resolution?

        Log:

        2016-08-16_13:14:28.88366 2016-08-16T13:14:28.881Z 14246 TID-13rnzg MergeWorker JID-4bf839373ccafda550f5f432 INFO: fail: 1.861 sec
2016-08-16_13:14:28.88369 2016-08-16T13:14:28.881Z 14246 TID-13rnzg WARN: {"class":"MergeWorker","args":[5736,23,{"utf8":"✓","authenticity_token":"p5V7CmYw49MA6bQvrfOycF/fe0oJmQKf1yyOjmBgdbB25GNC2ZyCF6YW9F1p0bnOOEwnIpjYwPMNw4aMThPQ1A==","sha":"aab675327c07eb8f5a08ac2405a469ba9be8038c","commit_message":"Merge branch 'us_73030_include_funds_total_summary' into 'stage'\r\n\r\n#73030 - Update translations and add total amount on the funds ledger view\r\n\r\n\r\n\r\nSee merge request !3981","merge_when_build_succeeds":"","button":"","controller":"projects/merge_requests","action":"merge","namespace_id":"project","project_id":"app.project.com","id":"3981"}],"retry":true,"queue":"default","jid":"4bf839373ccafda550f5f432","created_at":1471353267.0189302,"enqueued_at":1471353267.0190203,"error_message":"PG::StringDataRightTruncation: ERROR: value too long for type character varying(255)\n: UPDATE \"merge_requests\" SET \"merge_error\" = $1, \"updated_at\" = $2, \"in_progress_merge_commit_sha\" = $3, \"state\" = $4 WHERE \"merge_requests\".\"id\" = $5","error_class":"ActiveRecord::StatementInvalid","failed_at":1471353268.8806896,"retry_count":0}
2016-08-16_13:14:28.88370 2016-08-16T13:14:28.881Z 14246 TID-13rnzg WARN: ActiveRecord::StatementInvalid: PG::StringDataRightTruncation: ERROR: value too long for type character varying(255)
2016-08-16_13:14:28.88370 : UPDATE "merge_requests" SET "merge_error" = $1, "updated_at" = $2, "in_progress_merge_commit_sha" = $3, "state" = $4 WHERE "merge_requests"."id" = $5
2016-08-16_13:14:28.88370 2016-08-16T13:14:28.881Z 14246 TID-13rnzg WARN: /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/postgresql_adapter.rb:602:in `exec_prepared'
2016-08-16_13:14:28.88370 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/postgresql_adapter.rb:602:in `block in exec_cache'
2016-08-16_13:14:28.88371 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/abstract_adapter.rb:484:in `block in log'
2016-08-16_13:14:28.88371 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/notifications/instrumenter.rb:20:in `instrument'
2016-08-16_13:14:28.88371 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/abstract_adapter.rb:478:in `log'
2016-08-16_13:14:28.88371 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/postgresql_adapter.rb:601:in `exec_cache'
2016-08-16_13:14:28.88372 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/postgresql_adapter.rb:585:in `execute_and_clear'
2016-08-16_13:14:28.88372 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/postgresql/database_statements.rb:173:in `exec_delete'
2016-08-16_13:14:28.88372 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/abstract/database_statements.rb:114:in `update'
2016-08-16_13:14:28.88372 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/abstract/query_cache.rb:14:in `update'
2016-08-16_13:14:28.88372 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/relation.rb:88:in `_update_record'
2016-08-16_13:14:28.88373 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/persistence.rb:515:in `_update_record'
2016-08-16_13:14:28.88373 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/locking/optimistic.rb:79:in `_update_record'
2016-08-16_13:14:28.88373 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/attribute_methods/dirty.rb:129:in `_update_record'
2016-08-16_13:14:28.88373 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/callbacks.rb:310:in `block in _update_record'
2016-08-16_13:14:28.88374 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:117:in `call'
2016-08-16_13:14:28.88374 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:117:in `call'
2016-08-16_13:14:28.88374 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:555:in `block (2 levels) in compile'
2016-08-16_13:14:28.88374 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:505:in `call'
2016-08-16_13:14:28.88374 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:505:in `call'
2016-08-16_13:14:28.88374 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:92:in `__run_callbacks__'
2016-08-16_13:14:28.88375 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:778:in `_run_update_callbacks'
2016-08-16_13:14:28.88375 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/callbacks.rb:310:in `_update_record'
2016-08-16_13:14:28.88375 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/timestamp.rb:70:in `_update_record'
2016-08-16_13:14:28.88375 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/persistence.rb:504:in `create_or_update'
2016-08-16_13:14:28.88375 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/callbacks.rb:302:in `block in create_or_update'
2016-08-16_13:14:28.88375 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:117:in `call'
2016-08-16_13:14:28.88376 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:117:in `call'
2016-08-16_13:14:28.88376 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:555:in `block (2 levels) in compile'
2016-08-16_13:14:28.88376 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:505:in `call'
2016-08-16_13:14:28.88376 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:505:in `call'
2016-08-16_13:14:28.88376 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:92:in `__run_callbacks__'
2016-08-16_13:14:28.88377 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activesupport-4.2.7/lib/active_support/callbacks.rb:778:in `_run_save_callbacks'
2016-08-16_13:14:28.88377 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/callbacks.rb:302:in `create_or_update'
2016-08-16_13:14:28.88377 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/persistence.rb:120:in `save'
2016-08-16_13:14:28.88377 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/validations.rb:37:in `save'
2016-08-16_13:14:28.88377 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/attribute_methods/dirty.rb:21:in `save'
2016-08-16_13:14:28.88378 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/transactions.rb:286:in `block (2 levels) in save'
2016-08-16_13:14:28.88378 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/transactions.rb:351:in `block in with_transaction_returning_status'
2016-08-16_13:14:28.88378 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/abstract/database_statements.rb:211:in `transaction'
2016-08-16_13:14:28.88378 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/transactions.rb:220:in `transaction'
2016-08-16_13:14:28.88378 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/transactions.rb:348:in `with_transaction_returning_status'
2016-08-16_13:14:28.88379 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/transactions.rb:286:in `block in save'
2016-08-16_13:14:28.88379 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/transactions.rb:301:in `rollback_active_record_state!'
2016-08-16_13:14:28.88379 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/transactions.rb:285:in `save'
2016-08-16_13:14:28.88379 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-activerecord-0.4.0/lib/state_machines/integrations/active_record.rb:501:in `block in save'
2016-08-16_13:14:28.88380 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-activerecord-0.4.0/lib/state_machines/integrations/active_record.rb:520:in `block in around_save'
2016-08-16_13:14:28.88380 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:150:in `block in run_actions'
2016-08-16_13:14:28.88380 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:170:in `catch_exceptions'
2016-08-16_13:14:28.88380 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:148:in `run_actions'
2016-08-16_13:14:28.88380 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:133:in `run_callbacks'
2016-08-16_13:14:28.88380 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:224:in `run_callbacks'
2016-08-16_13:14:28.88381 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:128:in `block in run_callbacks'
2016-08-16_13:14:28.88381 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition.rb:371:in `before'
2016-08-16_13:14:28.88381 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition.rb:190:in `block in run_callbacks'
2016-08-16_13:14:28.88381 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition.rb:292:in `block in pausable'
2016-08-16_13:14:28.88381 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition.rb:292:in `catch'
2016-08-16_13:14:28.88381 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition.rb:292:in `pausable'
2016-08-16_13:14:28.88382 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition.rb:190:in `run_callbacks'
2016-08-16_13:14:28.88382 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:127:in `run_callbacks'
2016-08-16_13:14:28.88382 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:212:in `run_callbacks'
2016-08-16_13:14:28.88382 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:63:in `block (2 levels) in perform'
2016-08-16_13:14:28.88382 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:63:in `catch'
2016-08-16_13:14:28.88383 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:63:in `block in perform'
2016-08-16_13:14:28.88383 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:182:in `block in within_transaction'
2016-08-16_13:14:28.88383 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition.rb:171:in `block in within_transaction'
2016-08-16_13:14:28.88383 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/machine.rb:1864:in `block in within_transaction'
2016-08-16_13:14:28.88384 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-activerecord-0.4.0/lib/state_machines/integrations/active_record.rb:547:in `block in transaction'
2016-08-16_13:14:28.88384 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `block in transaction'
2016-08-16_13:14:28.88384 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/abstract/transaction.rb:184:in `within_new_transaction'
2016-08-16_13:14:28.88384 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/connection_adapters/abstract/database_statements.rb:213:in `transaction'
2016-08-16_13:14:28.88384 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/activerecord-4.2.7/lib/active_record/transactions.rb:220:in `transaction'
2016-08-16_13:14:28.88385 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-activerecord-0.4.0/lib/state_machines/integrations/active_record.rb:546:in `transaction'
2016-08-16_13:14:28.88385 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/machine.rb:1864:in `within_transaction'
2016-08-16_13:14:28.88385 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition.rb:170:in `within_transaction'
2016-08-16_13:14:28.88385 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:181:in `within_transaction'
2016-08-16_13:14:28.88385 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:62:in `perform'
2016-08-16_13:14:28.88386 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-activerecord-0.4.0/lib/state_machines/integrations/active_record.rb:520:in `around_save'
2016-08-16_13:14:28.88386 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-activerecord-0.4.0/lib/state_machines/integrations/active_record.rb:501:in `save'
2016-08-16_13:14:28.88386 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:154:in `block (2 levels) in run_actions'
2016-08-16_13:14:28.88386 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:154:in `each'
2016-08-16_13:14:28.88386 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:154:in `block in run_actions'
2016-08-16_13:14:28.88387 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:170:in `catch_exceptions'
2016-08-16_13:14:28.88387 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:148:in `run_actions'
2016-08-16_13:14:28.88387 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition_collection.rb:60:in `perform'
2016-08-16_13:14:28.88387 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/transition.rb:163:in `perform'
2016-08-16_13:14:28.88387 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/event.rb:155:in `fire'
2016-08-16_13:14:28.88387 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/event.rb:219:in `block in add_actions'
2016-08-16_13:14:28.88388 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/machine.rb:725:in `call'
2016-08-16_13:14:28.88388 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/state_machines-0.4.0/lib/state_machines/machine.rb:725:in `block (2 levels) in define_helper'
2016-08-16_13:14:28.88388 /opt/gitlab/embedded/service/gitlab-rails/app/models/merge_request.rb:615:in `ensure in in_locked_state'
2016-08-16_13:14:28.88388 /opt/gitlab/embedded/service/gitlab-rails/app/models/merge_request.rb:615:in `in_locked_state'
2016-08-16_13:14:28.88388 /opt/gitlab/embedded/service/gitlab-rails/app/services/merge_requests/merge_service.rb:16:in `execute'
2016-08-16_13:14:28.88389 /opt/gitlab/embedded/service/gitlab-rails/app/workers/merge_worker.rb:12:in `perform'
2016-08-16_13:14:28.88389 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/processor.rb:152:in `execute_job'
2016-08-16_13:14:28.88389 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/processor.rb:134:in `block (2 levels) in process'
2016-08-16_13:14:28.88389 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/middleware/chain.rb:128:in `block in invoke'
2016-08-16_13:14:28.88389 /opt/gitlab/embedded/service/gitlab-rails/lib/gitlab/sidekiq_middleware/memory_killer.rb:17:in `call'
2016-08-16_13:14:28.88390 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
2016-08-16_13:14:28.88390 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/middleware/server/active_record.rb:6:in `call'
2016-08-16_13:14:28.88390 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
2016-08-16_13:14:28.88390 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/middleware/server/retry_jobs.rb:74:in `call'
2016-08-16_13:14:28.88390 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
2016-08-16_13:14:28.88390 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/middleware/server/logging.rb:11:in `block in call'
2016-08-16_13:14:28.88390 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/logging.rb:32:in `with_context'
2016-08-16_13:14:28.88391 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/middleware/server/logging.rb:7:in `call'
2016-08-16_13:14:28.88391 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/middleware/chain.rb:130:in `block in invoke'
2016-08-16_13:14:28.88391 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/middleware/chain.rb:133:in `call'
2016-08-16_13:14:28.88391 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/middleware/chain.rb:133:in `invoke'
2016-08-16_13:14:28.88391 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/processor.rb:129:in `block in process'
2016-08-16_13:14:28.88392 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/processor.rb:168:in `stats'
2016-08-16_13:14:28.88392 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/processor.rb:128:in `process'
2016-08-16_13:14:28.88392 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/processor.rb:80:in `process_one'
2016-08-16_13:14:28.88392 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/processor.rb:68:in `run'
2016-08-16_13:14:28.88392 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/util.rb:17:in `watchdog'
2016-08-16_13:14:28.88393 /opt/gitlab/embedded/service/gem/ruby/2.1.0/gems/sidekiq-4.1.4/lib/sidekiq/util.rb:25:in `block in safe_thread'
      • username-removed-304201
        username-removed-304201 @funzie19 ·
        Author

        After some more searching I found the following https://gitlab.com/gitlab-org/gitlab-ce/issues/20593 which describes my latest issue.

      • Jacob Vosmaer (GitLab)
        Jacob Vosmaer (GitLab) @jacobvosmaer-gitlab ·
        Contributor

        @stanhu what do you think about the expiring lock idea in https://gitlab.com/gitlab-org/gitlab-ce/issues/18048#note_13094035

      • Stan Hu
        Stan Hu @stanhu ·
        Maintainer

        What if we give each lock a UUID, and when locking schedule an unlock Sidekiq job X minutes in the future that checks if the lock with that UUID is still in place and then removes it.

        One thing that's similar would be to store the Sidekiq job ID as this UUID. If we could figure out if the Sidekiq job ID was still running/failed then we might have more information.

        Or we put a timestamp on the lock and when querying it (loading the MR page) we unlock the MR if it is X minutes old.

        Right now this is sort of done in the controller after 24 hours: https://gitlab.com/gitlab-org/gitlab-ce/blob/master/app/controllers/projects/merge_requests_controller.rb#L428 Do we want to lower this threshold?

      • Jacob Vosmaer (GitLab)
        Jacob Vosmaer (GitLab) @jacobvosmaer-gitlab ·
        Contributor

        @stanhu ah that makes sense, I knew I read that idea somewhere. (MergeRequest#locked_long_ago?)

        Maybe we just need to lower that timeout value and present a message to the user. I think we now just close the MR without explanation.

      • username-removed-615940
        username-removed-615940 @ryanjaeb ·

        I think I ran into this about a week ago.

        • It happened on an Omnibus install (v8.15.x) that's very lightly used. I'm the only user.
        • The merge happened immediately and the source branch was deleted, but the request was stuck spinning forever. The merge was listed under All, but not Open, Merged, or Closed. I couldn't close it manually.
        • I updated from 8.15.3 to 8.15.4 (I think) while it was stuck and it was still stuck after the update.
        • Something cleaned it up eventually by closing the merge request, but now the repo is in the wrong state. The request was merged, but it shows up in Closed and says it failed.

        Another thing that may or may not be relevant is that I think I accepted the merge request at the exact moment the build pipeline was finishing (successfully).

        Are there any logs I can provide that would be useful?

      • username-removed-938690
        username-removed-938690 @mosmani ·

        Our env looks like this

        System information
System:         Debian 8.7
Current User:   git
Using RVM:      no
Ruby Version:   2.3.3p222
Gem Version:    2.6.6
Bundler Version:1.13.7
Rake Version:   10.5.0
Sidekiq Version:4.2.7

GitLab information
Version:        8.16.4-ee
Revision:       93daa28
Directory:      /opt/gitlab/embedded/service/gitlab-rails
DB Adapter:     PostgreSQL
DB Version:     9.6.1
URL:            https://xxx
HTTP Clone URL: https://xxx/some-group/some-project.git
SSH Clone URL:  git@xxx:some-group/some-project.git
Elasticsearch:  no
Geo:            no
Using LDAP:     yes
Using Omniauth: no

GitLab Shell
Version:        4.1.1
Repository storage paths:
- default:      /var/opt/gitlab/git-data/repositories
Hooks:          /opt/gitlab/embedded/service/gitlab-shell/hooks/
Git:            /opt/gitlab/embedded/bin/git

gitlab-ee                           8.16.4-ee.0                       amd64        GitLab Enterprise Edition and GitLab CI (including NGINX, Postgres, Redis)

        I see a lot of MR which has the state

        "Merge in progress… This merge request is in the process of being merged, during which time it is locked and cannot be closed. "

        Is there a workaround how i can close these MRs because i saw that they are already merged into master.

        I tried the "close"-Button but it does not work.

        Regards

        Edited by username-removed-938690
      • username-removed-636429
        username-removed-636429 @mikegreiling ·
        Maintainer

        I've encountered this issue on GitLab.com for MR !10099 (closed) which was set to "merge when pipeline succeeds", but after the pipeline completed it got stuck on "merge in progress" for over 12 hours and counting as of this comment.

        I also mentioned this in #2995 (moved). I'm unsure if this counts as a duplicate issue.

      • username-removed-640663
        username-removed-640663 @meno ·

        This also just happened in our repo. Our (private) MR is now in the same state as @mosmani described.

      • username-removed-521015
        username-removed-521015 @gdavalos ·

        I just had this happen to me in our private repo on gitlab.com today, it's been two hours and counting and the merge request is still in progress while it usually doesn't take more than a minute

        Edited by username-removed-521015
      • username-removed-86853 added ~12980 ~13921 labels

        added ~12980 ~13921 labels

      • username-removed-908853
        username-removed-908853 @arunkumar.nagarajan ·

        the same thing happening to one of our merge requests also. Yesterday created MR still, shows Merge in progress… Any solution for this?

      • username-removed-121963
        username-removed-121963 @fgilio ·

        Same here, a MR has been in progress for more than 12 hours. Using gitlab.com

      • username-removed-626558
        username-removed-626558 @apple4ever ·

        This just happened to use on our 8.17 self hosted instance.

        @stanhu your commands no longer work.

        I'd be happen to provide more diagnostic info if requested and instructions are provided.

      • username-removed-683698
        username-removed-683698 @eliskovets ·

        This just happened on our production gitlab 9.0.5 server. I guess the main cause of this was our git post-receive hook, as it failed, but the question still why it's stuck in "Merge in progress' status and what's the right way to solve it? Right now I had to solve it by direct update in the merge_requests db table, as the merge request was actually merged. Our git-hook was not so important.

      • username-removed-708597
        username-removed-708597 @gkaran ·

        We have the same problem in our self hosted gitlab server (8.10.13) and it is not rare at all. 1 out of 3 MRs get in that state. All of them appear as locked in the DB. Some of them do get merged but stay locked and some other don't get merged at all.

        We have been searching the log files with no good findings and we don't know how to actually reproduce this. In the cases that the merge is not executed, MergeWorker appears to have completed succesfully but the code was not actually merged.

      • username-removed-683698
        username-removed-683698 @eliskovets ·

        As nobody from gitlab team would like to provide a solution. Here is the way how I solved this issue. (In my case it was just a lock in the interface and I can't find any errors in gitlab logs, plus in git repo it was actually successfully merged.)

        # login to postgres instance
sudo gitlab-rails dbconsole
        -- check the list of locked merge requests
select id, iid as merge_id, source_branch, target_branch, locked_at, merge_error, merge_commit_sha, in_progress_merge_commit_sha, merge_status, state from merge_requests where state='locked' order by id desc;
        -- mark them as merged
update merge_requests set merge_commit_sha=in_progress_merge_commit_sha, locked_at=null, state='merged', in_progress_merge_commit_sha=null where state='locked';
      • username-removed-708597
        username-removed-708597 @gkaran ·

        This is whay we actually do as well to overcome this but this is not actually a solutions but a dirty hack as we tamper with the db manually which is not ok.

      • username-removed-708597
        username-removed-708597 @gkaran ·

        Also when a MR appears as locked, we cannot merge anything else (probaly due to the locked state).

      • username-removed-814991 mentioned in issue #32803 (closed)

        mentioned in issue #32803 (closed)

      • Drew Blessing
        Drew Blessing @dblessing ·
        Maintainer

        @stanhu @smcgivern Do you have any ideas on how to improve this situation? I have another customer in https://gitlab.zendesk.com/agent/filters/325771188 experiencing this. We'll address there specific case(s) in the ticket, but this issue has certainly been popular so it's probably a good idea to move it forward soonish. After we get your input, we can ask @victorwu to schedule it.

      • Stan Hu
        Stan Hu @stanhu ·
        Maintainer

        I think https://gitlab.com/gitlab-org/gitlab-ce/merge_requests/13207, which will land in 9.5, will be a big step towards improving the situation.

      • Victor Wu added Discussion label

        added Discussion label

      • Victor Wu changed milestone to %Next 2-3 months

        changed milestone to %Next 2-3 months

      • username-removed-443319
        username-removed-443319 @smcgivern ·
        Contributor

        @dblessing https://gitlab.com/gitlab-org/gitlab-ce/merge_requests/13207 should do the following:

        1. Make this more reliable in general.
        2. Prevent an MR being 'stuck' for more than two hours.

        @oswaldo - let's keep an eye on that, as we may be able to close this issue too :thumbsup:

      • Reb added customer customer success labels

        added customer customer success labels

      • Reb added customer+ and removed customer labels

        added customer+ and removed customer labels

      • Oswaldo Ferreir
        Oswaldo Ferreir @oswaldo ·
        Developer

        As per https://gitlab.com/gitlab-org/gitlab-ce/issues/18048#note_37153820, closing this one for now.

      • Oswaldo Ferreir closed

        closed

      Please register or sign in to reply