Material update broke after 16.6 upgrade (Windows)

[esiqveland]

Issue Type

• Bug Report

Summary

After upgrading go CD from 16.3 to 16.6 on windows I am getting this with several pipelines, and they refuse to build:

Material update failed for material 'git@github.com:....' because: Cannot save modification: All modifications already exist in db: [789dfd0c99e4d6ec02f35e499b873bcdf04f3945]. 
Cause: All modifications already exist in db: [789dfd0c99e4d6ec02f35e499b873bcdf04f3945]

I made sure to stop the server before starting the upgrade.
I also made a backup of the db folder after stopping the service.

Environment

• Go Version: 16.6.0 (3590-af0f8b8ae8a4342ab748ce80224971887f018ccc)
• JAVA Version:

java.runtime.name: "Java(TM) SE Runtime Environment",
java.runtime.version: "1.7.0_60-b19",
java.specification.name: "Java Platform API Specification",
java.specification.vendor: "Oracle Corporation",
java.specification.version: "1.7",

• OS: Windows Server 2012

Additional Environment Details

Including this as it was the only part listing anything of my plugins:
Maybe /support api should include list of plugins + their versions?

Config file locations: {
loc.config.dir: "C:\bin\Go Server\config",
loc.log.root.0: "C:\bin\Go Server",
loc.log.basename.0: "go-server.log",
loc.log.root.1: "C:\bin\Go Server",
loc.log.basename.1: "plugin-maven.log",
loc.log.root.2: "C:\bin\Go Server",
loc.log.basename.2: "plugin-git.fb.log",
loc.log.root.3: "C:\bin\Go Server",
loc.log.basename.3: "plugin-slack.notifier.log",
loc.log.root.4: "C:\bin\Go Server",
loc.log.basename.4: "go-shine.log",
loc.log.root.5: "C:\bin\Go Server",
loc.log.basename.5: "plugin-github.pr.log"

Steps to Reproduce

Can't reproduce at will :/

Expected Results

I expect material updates to work after upgrade :)

Actual Results

Some materials broke updating after upgrade.

Possible Workaround

Modifying material path so it gets seen as a new material seems to work around the issue.

Log snippets

2016-06-29 10:00:31,933  INFO [101@MessageListener for MaterialUpdateListener] ScmMaterialUpdater:63 - [Material Update] Found '1' modifications for material 'GitMaterial{url=git@github.com:..., branch='master', submoduleFolder='null', shallowClone=false}' with flyweight '4b14960b49797ea5b886eec1cb7090c11365eaef29f804a1485410d89803ee95' using working directory 'C:\bin\Go Server\pipelines\flyweight\008fe843-6fc6-416a-8656-f1c66b645497'
2016-06-29 10:00:31,933 ERROR [101@MessageListener for MaterialUpdateListener] MaterialRepository:818 - Cannot save modification: 
java.lang.RuntimeException: All modifications already exist in db: [3a0db4192abe2b743f35e5e8575d568bc52eb1b1]
    at com.thoughtworks.go.server.persistence.MaterialRepository.checkAndRemoveDuplicates(MaterialRepository.java:852)
    at com.thoughtworks.go.server.persistence.MaterialRepository.saveModifications(MaterialRepository.java:814)
    at com.thoughtworks.go.server.materials.ScmMaterialUpdater.insertLatestOrNewModifications(ScmMaterialUpdater.java:66)
    at com.thoughtworks.go.server.materials.MaterialDatabaseUpdater.insertLatestOrNewModifications(MaterialDatabaseUpdater.java:155)
    at com.thoughtworks.go.server.materials.MaterialDatabaseUpdater.updateMaterialWithNewRevisions(MaterialDatabaseUpdater.java:147)
    at com.thoughtworks.go.server.materials.MaterialDatabaseUpdater$2.doInTransaction(MaterialDatabaseUpdater.java:110)
    at com.thoughtworks.go.server.transaction.TransactionCallback.doWithExceptionHandling(TransactionCallback.java:24)
    at com.thoughtworks.go.server.transaction.TransactionTemplate$3.doInTransaction(TransactionTemplate.java:53)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130)
    at com.thoughtworks.go.server.transaction.TransactionTemplate.executeWithExceptionHandling(TransactionTemplate.java:49)
    at com.thoughtworks.go.server.materials.MaterialDatabaseUpdater.updateMaterial(MaterialDatabaseUpdater.java:107)
    at com.thoughtworks.go.server.materials.MaterialUpdateListener.onMessage(MaterialUpdateListener.java:50)
    at com.thoughtworks.go.server.materials.MaterialUpdateListener.onMessage(MaterialUpdateListener.java:30)
    at com.thoughtworks.go.server.messaging.activemq.JMSMessageListenerAdapter.runImpl(JMSMessageListenerAdapter.java:65)
    at com.thoughtworks.go.server.messaging.activemq.JMSMessageListenerAdapter.run(JMSMessageListenerAdapter.java:50)
    at java.lang.Thread.run(Thread.java:745)
2016-06-29 10:00:31,933  WARN [101@MessageListener for MaterialUpdateListener] MaterialDatabaseUpdater:121 - [Material Update] Modification check failed for material: URL: git@github.com:..., Branch: master
java.lang.RuntimeException: Cannot save modification: All modifications already exist in db: [3a0db4192abe2b743f35e5e8575d568bc52eb1b1]
    at com.thoughtworks.go.server.persistence.MaterialRepository.saveModifications(MaterialRepository.java:819)
    at com.thoughtworks.go.server.materials.ScmMaterialUpdater.insertLatestOrNewModifications(ScmMaterialUpdater.java:66)
    at com.thoughtworks.go.server.materials.MaterialDatabaseUpdater.insertLatestOrNewModifications(MaterialDatabaseUpdater.java:155)
    at com.thoughtworks.go.server.materials.MaterialDatabaseUpdater.updateMaterialWithNewRevisions(MaterialDatabaseUpdater.java:147)
    at com.thoughtworks.go.server.materials.MaterialDatabaseUpdater$2.doInTransaction(MaterialDatabaseUpdater.java:110)
    at com.thoughtworks.go.server.transaction.TransactionCallback.doWithExceptionHandling(TransactionCallback.java:24)
    at com.thoughtworks.go.server.transaction.TransactionTemplate$3.doInTransaction(TransactionTemplate.java:53)
    at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130)
    at com.thoughtworks.go.server.transaction.TransactionTemplate.executeWithExceptionHandling(TransactionTemplate.java:49)
    at com.thoughtworks.go.server.materials.MaterialDatabaseUpdater.updateMaterial(MaterialDatabaseUpdater.java:107)
    at com.thoughtworks.go.server.materials.MaterialUpdateListener.onMessage(MaterialUpdateListener.java:50)
    at com.thoughtworks.go.server.materials.MaterialUpdateListener.onMessage(MaterialUpdateListener.java:30)
    at com.thoughtworks.go.server.messaging.activemq.JMSMessageListenerAdapter.runImpl(JMSMessageListenerAdapter.java:65)
    at com.thoughtworks.go.server.messaging.activemq.JMSMessageListenerAdapter.run(JMSMessageListenerAdapter.java:50)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: All modifications already exist in db: [3a0db4192abe2b743f35e5e8575d568bc52eb1b1]
    at com.thoughtworks.go.server.persistence.MaterialRepository.checkAndRemoveDuplicates(MaterialRepository.java:852)
    at com.thoughtworks.go.server.persistence.MaterialRepository.saveModifications(MaterialRepository.java:814)
    ... 14 more

Code snippets/Screenshots

Any other info

[zabil]

@esiqveland
This check was added to fix a bug that led to #2110
The only way to fix this is

• Make a new commit
• Or change the fingerprint of the material (i.e change the path to make it look like a new material)

Closing this as we recommend discarding the corrupted material history.

More details on this commit 43e907a

[greenmoss]

Hi there, I have had this issue for weeks on four of my repos/pipelines. New commits have come through on the affected repos, yet this error persists. Should this be a new ticket?

GoCD version is 16.9.0

[zabil]

Were the repo's rebased?
Do your pipelines trigger despite the error?

[greenmoss]

I'm not sure whether the repos were rebased. Is there a command I can run to find out?
The pipelines do trigger despite the error.

[arvindsv]

Assigning to @jyotisingh to take a look once back on Monday. I suspect we'll need more information to diagnose this. This issue could also be related to #2470.

[jyotisingh]

@greenmoss - could you pick one of the repos for which you have been seeing this issue and give some more details about that one. The things I would like to know are:
(i) The exact error message that you see including the list of revisions mentioned in the error message
(ii) Is this a plain-old scm material or did you use one of the scm plugins to configure this? If so, which one?
(iii) When you say The pipelines do trigger despite the error, do you mean they trigger automatically or only when you force/manually trigger them?

[greenmoss]

Please find answers below:

(i)
Modification check failed for material: URL: https://the.server/path/repo.git, Branch: master [Oct-04 13:54:50] Cannot save modification: All modifications already exist in db: [b192de98652770bbe93cfcd6669a900d56133995]

(ii) This is a plain scm git material.

(iii) They trigger automatically. I confirmed this by looking at the "changes" list of the pipeline associated with the repo. The git repo pointed to by the error message is highlighted in yellow, referencing the same commit hash. So even though there's an error for that hash, it did launch the pipeline.

Also, a bunch of new errors of this nature just appeared. I've seen this before on other repo/branch combinations: the error appears and persists for several days, then eventually disappears.

[jyotisingh]

They trigger automatically. I confirmed this by looking at the "changes" list of the pipeline associated with the repo. The git repo pointed to by the error message is highlighted in yellow, referencing the same commit hash. So even though there's an error for that hash, it did launch the pipeline.

Are you saying for every new commit that you make, the error log entry says unable to save modification with that same SHA as your commit but the build triggers and the same SHA is listed out on the changes popup for the pipeline run?

Could you look for a message such as Saving revisions for material [URL: https://the.server/path/repo.git, Branch: master] after removing the following duplicates <list of duplicate SHAs> in the server logs. Check if there are any duplicates listed.

I speculate this is happening because of rebasing and force push to the git repo. While rebase workflow mostly works in newer releases of Go, this could possibly be a missing scenario.

I would need your help to find whats going on. From the log message that you shared earlier:

2016-06-29 10:00:31,933  INFO [101@MessageListener for MaterialUpdateListener] ScmMaterialUpdater:63 - [Material Update] Found '1' modifications for material 'GitMaterial{url=git@github.com:..., branch='master', submoduleFolder='null', shallowClone=false}' with flyweight '4b14960b49797ea5b886eec1cb7090c11365eaef29f804a1485410d89803ee95' using working directory 'C:\bin\Go Server\pipelines\flyweight\008fe843-6fc6-416a-8656-f1c66b645497'
2016-06-29 10:00:31,933 ERROR [101@MessageListener for MaterialUpdateListener] MaterialRepository:818 - Cannot save modification: 
java.lang.RuntimeException: All modifications already exist in db: [3a0db4192abe2b743f35e5e8575d568bc52eb1b1]

The log message here lists out the flyweight folder (mentioned as working directory) as C:\bin\Go Server\pipelines\flyweight\008fe843-6fc6-416a-8656-f1c66b645497 for the concerned material. Could you find the flyweight folder for the material that you mentioned in your previous reply from the logs, go to that location and just rename (do not delete) the folder. This would cause Go to perform a fresh checkout of the material on the server side during the next material update cycle. If the repo is huge or has huge history, then this is going to take sometime and there is a chance that you would start seeing messages such as "[Material Update] Skipping update of material .. which has been in-progress since ..", and thats expected.

Check the output of <go-server>/go/api/process_list. You would see something like this:

{
    "process-list": [{
        "command": "git-remote-https origin <git_repo_url>",
        "start_time": "04/10/16 - 22:28:57:129",
        "idle_time": "0 minutes"
    }]
}

Or you could just look for all git processes running on Go server whichever you find easier.
As long as this has an entry for the concerned material we are good. Once the process finishes, make a new commit to your repo. Keep monitoring the logs to see if you still see the "Modification check failed.." message for this specific repo. If you do, then I will have to think of something else. If you don't then we might have to run some commands on the original flyweight folder that we had renamed earlier to see whats wrong.

[arvindsv]

@jyotisingh: Unsure if it's related to something happening in this issue. I realize that one is GitHub PR and not pure git.

[jyotisingh]

@greenmoss - Could you please tell the version of git running on your git-server as well as the version running on go-server machine.

[jyotisingh]

@greenmoss - could you run git ls-remote origin against the repo and share the result here.

[jyotisingh]

Started seeing this issue recently on one of our local servers for a few git materials. It turns out, these git repos had a branch called HEAD pointing to an older SHA. This caused git to get confused. Every alternate git fetch origin call from Go server during a material update would switch between the real HEAD and the SHA that the branch called HEAD was pointing to. Deleting the branch on the remote git server fixed things.

[greenmoss]

@jyotisingh I plan to look into this some more next week

[compuguy]

@jyotisingh I work with @greenmoss and I have been assigned to work on this. We are using github-enterprise, 2.7.5. I don't know the version of git running on it, because it is a self contained application. Based on the commit mentioned earlier, has this been fixed on the latest version of GoCD, 16.11?

[arvindsv]

@compuguy - There was a change made to help with this, and it was released as a part of 16.11 a few days ago. The PR was this. If you have a test system, you can check whether it helps.

[compuguy]

@arvindsv Upgrading from 16.09 to 16.11 is on our todo list. I will have to talk to @greenmoss about when we want to test migrating to 16.11.