Salt: Git Module : Failed to update repository

Created on 11 Aug 2017 · 13Comments · Source: saltstack/salt

Description of Issue/Question

We have random errors while using git.latest. This is the error we get from time to time

       ----------
                 ID: source_code
           Function: git.latest
               Name: [email protected]:developers/company.git
             Result: False
            Comment: Failed to update repository

              Changes already made: [email protected]:developers/company.git was fetched, resulting in updated refs. Repository was fast-forwarded to origin/master (9f6c8a3).
            Started: 21:56:04.742518
           Duration: 3077219.038 ms
            Changes:

Setup

We have the following state

source_code:
  git.latest:
    - require:
      - file: company_git
      - pkg: users_bash-package
      - pkg: git
    - name: {{ pillar['git_url'] }}
    - rev: {{ pillar[grains['deployment']]['git_branch'] }}
    - branch: {{ pillar[grains['deployment']]['git_branch'] }}
    - target: /usr/local/www/company
    - user: git
    - update_head: True
    - force_checkout: True
    - force_clone: True
    - force_fetch: True
    - force_reset: True

Pillar is set like this git_branch: master

This is the salt log when state runs fine

[INFO    ] Running state [[email protected]:developers/company.git] at time 19:42:48.267272
[INFO    ] Executing state git.latest for [email protected]:developers/company.git
[INFO    ] Checking remote revision for [email protected]:developers/company.git
[INFO    ] Executing command ['git', 'ls-remote', '[email protected]:developers/company.git'] as user 'git' in directory '/home/git'
[INFO    ] Executing command ['git', 'for-each-ref', '--format', '%(refname:short)', 'refs/heads/'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'for-each-ref', '--format', '%(refname:short)', 'refs/tags/'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Checking local revision for /usr/local/www/company
[INFO    ] Executing command ['git', 'rev-parse', 'HEAD'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Checking local branch for /usr/local/www/company
[INFO    ] Executing command ['git', 'rev-parse', '--abbrev-ref', 'HEAD'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'remote', '--verbose'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'diff', 'HEAD'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'rev-parse', 'a2992c79370b3273d6bde157ba28c3a41f56a4f8^{commit}'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'rev-parse', 'origin/master'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'rev-parse', '--abbrev-ref', 'master@{upstream}'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'fetch', '--force', 'origin', 'refs/heads/*:refs/remotes/origin/*', '+refs/tags/*:refs/tags/*'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'rev-parse', 'a2992c79370b3273d6bde157ba28c3a41f56a4f8^{commit}'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'merge-base', '--is-ancestor', 'd2d8cfcccf6df4ee84f12a680a97f4920ab24696', 'a2992c79370b3273d6bde157ba28c3a41f56a4f8'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'symbolic-ref', '--quiet', 'HEAD'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'merge', '--ff-only', 'origin/master'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'rev-parse', 'HEAD'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Repository /usr/local/www/company updated: d2d8cfcccf6df4ee84f12a680a97f4920ab24696 => a2992c79370b3273d6bde157ba28c3a41f56a4f8
[INFO    ] Made the following changes:
'revision' changed from 'd2d8cfcccf6df4ee84f12a680a97f4920ab24696' to 'a2992c79370b3273d6bde157ba28c3a41f56a4f8'

[INFO    ] Complet

And this one is the log when this state fails

[INFO    ] Running state [[email protected]:developers/company.git] at time 21:56:04.742611
[INFO    ] Executing state git.latest for [email protected]:developers/company.git
[INFO    ] Checking remote revision for [email protected]:developers/company.git
[INFO    ] Executing command ['git', 'ls-remote', '[email protected]:developers/company.git'] as user 'git' in directory '/home/git'
[INFO    ] Executing command ['git', 'for-each-ref', '--format', '%(refname:short)', 'refs/heads/'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'for-each-ref', '--format', '%(refname:short)', 'refs/tags/'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Checking local revision for /usr/local/www/company
[INFO    ] Executing command ['git', 'rev-parse', 'HEAD'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Checking local branch for /usr/local/www/company
[INFO    ] Executing command ['git', 'rev-parse', '--abbrev-ref', 'HEAD'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'remote', '--verbose'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'diff', 'HEAD'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'rev-parse', '9f6c8a32c139aa465da0207753208521267b1920^{commit}'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'rev-parse', '--abbrev-ref', 'master@{upstream}'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'fetch', '--force', 'origin', 'refs/heads/*:refs/remotes/origin/*', '+refs/tags/*:refs/tags/*'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'rev-parse', '9f6c8a32c139aa465da0207753208521267b1920^{commit}'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'merge-base', '--is-ancestor', '052e48e89c5edb97804a554a97bee65b71bf7117', '9f6c8a32c139aa465da0207753208521267b1920'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'symbolic-ref', '--quiet', 'HEAD'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'merge', '--ff-only', 'origin/master'] as user 'git' in directory '/usr/local/www/company'
[INFO    ] Executing command ['git', 'rev-parse', 'HEAD'] as user 'git' in directory '/usr/local/www/company'
[ERROR   ] Failed to update repository

Changes already made: [email protected]:developers/company.git was fetched, resulting in updated refs. Repository was fast-forwarded to origin/master (9f6c8a3).
[INFO    ] Completed state [[email protected]:developers/company.git] at time 22:47:21.961556 duration_in_ms=3077219.038

Steps to Reproduce Issue

This issue is random, so we don't know :(

Versions Report

Master

salt --versions-report
Salt Version:
           Salt: 2016.11.2

Dependency Versions:
           cffi: Not Installed
       cherrypy: Not Installed
       dateutil: 2.6.0
          gitdb: Not Installed
      gitpython: Not Installed
          ioflo: Not Installed
         Jinja2: 2.8
        libgit2: Not Installed
        libnacl: Not Installed
       M2Crypto: Not Installed
           Mako: Not Installed
   msgpack-pure: Not Installed
 msgpack-python: 0.4.6
   mysql-python: Not Installed
      pycparser: Not Installed
       pycrypto: 2.6.1
         pygit2: Not Installed
         Python: 2.7.12 (default, Nov 19 2016, 06:48:10)
   python-gnupg: Not Installed
         PyYAML: 3.12
          PyZMQ: 15.2.0
           RAET: Not Installed
          smmap: Not Installed
        timelib: Not Installed
        Tornado: 4.2.1
            ZMQ: 4.1.4

System Versions:
           dist: Ubuntu 16.04 xenial
        machine: x86_64
        release: 4.4.0-1022-aws
         system: Linux
        version: Ubuntu 16.04 xenial

Minion

Salt Version:
           Salt: 2016.11.2

Dependency Versions:
           cffi: 1.7.0
       cherrypy: Not Installed
       dateutil: 2.6.0
          gitdb: Not Installed
      gitpython: Not Installed
          ioflo: Not Installed
         Jinja2: 2.9.5
        libgit2: Not Installed
        libnacl: Not Installed
       M2Crypto: Not Installed
           Mako: Not Installed
   msgpack-pure: Not Installed
 msgpack-python: 0.4.7
   mysql-python: Not Installed
      pycparser: 2.10
       pycrypto: 2.6.1
         pygit2: Not Installed
         Python: 2.7.13 (default, Jul 13 2017, 01:14:26)
   python-gnupg: Not Installed
         PyYAML: 3.11
          PyZMQ: 16.0.2
           RAET: Not Installed
          smmap: Not Installed
        timelib: Not Installed
        Tornado: 4.5.1
            ZMQ: 4.1.5

System Versions:
           dist:
        machine: amd64
        release: 10.3-RELEASE-p18
         system: FreeBSD
        version: Not Installed

Any suggestion/idea how we can start troubleshooting this issue? We have jenkins/kitchen to run integration tests for every role, and this issue makes the whole process to fail randomly which is really annoying.

Thanks

Bug P2 ZD fixed-pending-your-verification severity-medium

Source

abednarik

Most helpful comment

I spoke with @UtahDave about this and we narrowed it down to a race condition when the remote repo is updated between when we run git ls-remote to check which commit we are targeting, and when the remote repo is fetched. I was able to reproduce the failure by pausing execution in a debugger, then pushing a new commit to the remote repo before resuming.

The fix is in https://github.com/saltstack/salt/pull/43064.

terminalmage on 18 Aug 2017

👍2

All 13 comments

ZD 1681

UtahDave on 15 Aug 2017

@abednarik are you using git_pillar with the same repo?

UtahDave on 16 Aug 2017

Hi @UtahDave

No we are not using git_illar at all. t’s a plain GIT repo that we want to checkout. Since is a huge repository (~7G) and this in a kitchen tests context, we bring the vm up where we run the tests and we do a rsync of this repo before running salt states. And it’s quite possible that this happens when we have pushes to master at same time we are running that command

thanks.

abednarik on 16 Aug 2017

The git state has seen some improvements. Would it be possible to test this on the latest 2017.7.1 Salt release?

UtahDave on 17 Aug 2017

Ok, I will give it a try.

abednarik on 17 Aug 2017

HI @UtahDave

We tried with 2017.7.1 but we found a critical bug https://github.com/saltstack/salt/issues/36675#issuecomment-323176122 so is not an option right now :(

abednarik on 17 Aug 2017

OK, so aside from the bug you ran into, does the git.latest work with 2017.7.1?

UtahDave on 18 Aug 2017

We didn't tried because tests always fails, so with that bug, is impossible for us to run tests and reproudce this error.

abednarik on 18 Aug 2017

Would it be possible to isolate just the git.latest piece of your test suite and test against 2017.7.1?

UtahDave on 18 Aug 2017

Sadly at this point is not an option.

Cheers.

abednarik on 18 Aug 2017

The fix is in https://github.com/saltstack/salt/pull/43064.

terminalmage on 18 Aug 2017

👍2

Hi @terminalmage

Thanks for fixing this one. For sure we will try this fix next week.

Cheers.

abednarik on 19 Aug 2017

Hey @UtahDave / @terminalmage / @rallytime ,

We are trying to test this fix by using 2016.11 branch but unfortunately we found this bug(#42642 comment) and we can't change our testing environment to that branch until is fixed because as @abednarik said this was a rare race-condition we had so we can't replicate it easily.

If you can help us to get that fixed would be great so we can give you feedback on this issue.

Thanks!