Possible issue with Octopus integration and NuGet indexing?

Hello,

When using OctoPack via the Octopus Deploy integration into TeamCity, I noticed the following in my TeamCity server logs:

[2014-12-31 12:08:10,608]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact MyPackage.0.1.0.1.nupkg of build #0.1.0.1 {build id=112, buildTypeId=MyConfiguration}
[2014-12-31 12:08:37,125]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact MyPackage.0.1.0.1.nupkg of build #0.1.0.1 {build id=112, buildTypeId=MyConfiguration}
[2014-12-31 12:08:44,393]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact MyPackage.0.1.0.1.nupkg of build #0.1.0.1 {build id=112, buildTypeId=MyConfiguration}
[2014-12-31 12:08:47,692]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact MyPackage.0.1.0.1.nupkg of build #0.1.0.1 {build id=112, buildTypeId=MyConfiguration}
[2014-12-31 12:09:13,735]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact MyPackage.0.1.0.1.nupkg of build #0.1.0.1 {build id=112, buildTypeId=MyConfiguration}
[2014-12-31 12:09:32,464]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact MyPackage.0.1.0.1.nupkg of build #0.1.0.1 {build id=112, buildTypeId=MyConfiguration}
[2014-12-31 12:09:39,636]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact MyPackage.0.1.0.1.nupkg of build #0.1.0.1 {build id=112, buildTypeId=MyConfiguration}
[2014-12-31 12:09:47,217]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact MyPackage.0.1.0.1.nupkg of build #0.1.0.1 {build id=112, buildTypeId=MyConfiguration}

The same NuGet package is indexed 8 times when it is built. Can anyone tell me if the underlying issue is probably with my configuration or TeamCity, or if I need to take this up with the Octopus Deploy folks? Thanks.

3 comments
Comment actions Permalink

Hi Jason,

Which TeamCity version do you use? If not the latest one (9.0.1 as of now) then please upgrade and inform us if the issue is reproduced.
When these logs appear: when the build finishes or at the time of clean up?

0
Comment actions Permalink

Alina,

This is using 9.0.1. These events occur more than just at the end.

0
Comment actions Permalink

Okay, so it looks like the issue is related to the generation of many packages in a single build. Every time a new package is generated, all packages from the build get re-indexed. Then everything gets indexed at the end. This seems pretty inefficient. Here is a summary of the pattern:

... various build-start log messages ...
[2015-01-16 10:07:23,691]   INFO -   jetbrains.buildServer.SERVER - Build removed from queue (started): 256
[2015-01-16 10:07:23,691]   INFO -   jetbrains.buildServer.SERVER - Flush queue finished, number of builds started: 1
[2015-01-16 10:07:28,238]   INFO -   jetbrains.buildServer.SERVER - Running build saved to DB: build id=256, promotion id=256

[2015-01-16 10:13:10,733]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact Module-01-Module.0.1.0.18.nupkg of build #0.1.0.18 {build id=256, buildTypeId=BuildName}

[2015-01-16 10:13:46,209]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact Module-02-Module.0.1.0.18.nupkg of build #0.1.0.18 {build id=256, buildTypeId=BuildName}
[2015-01-16 10:13:47,660]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact Module-01-Module.0.1.0.18.nupkg of build #0.1.0.18 {build id=256, buildTypeId=BuildName}

[2015-01-16 10:13:57,118]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact Module-02-Module.0.1.0.18.nupkg of build #0.1.0.18 {build id=256, buildTypeId=BuildName}
[2015-01-16 10:13:58,497]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact Module-03-Module.0.1.0.18.nupkg of build #0.1.0.18 {build id=256, buildTypeId=BuildName}
[2015-01-16 10:13:59,343]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact Module-01-Module.0.1.0.18.nupkg of build #0.1.0.18 {build id=256, buildTypeId=BuildName}

[2015-01-16 10:14:06,724]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact Module-02-Module.0.1.0.18.nupkg of build #0.1.0.18 {build id=256, buildTypeId=BuildName}
[2015-01-16 10:14:08,080]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact Module-03-Module.0.1.0.18.nupkg of build #0.1.0.18 {build id=256, buildTypeId=BuildName}
[2015-01-16 10:14:09,031]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact Module-01-Module.0.1.0.18.nupkg of build #0.1.0.18 {build id=256, buildTypeId=BuildName}
[2015-01-16 10:14:10,348]   INFO - NuGetArtifactsMetadataProvider - Indexing NuGet package from artifact Module-04-Module.0.1.0.18.nupkg of build #0.1.0.18 {build id=256, buildTypeId=BuildName}

... etc ...

[2015-01-16 10:16:00,028]   INFO - ndexer.EventBasedBuildsIndexer - Indexing finishing build: #0.1.0.18 {build id=256, buildTypeId=BuildName}
[2015-01-16 10:16:00,106]   INFO - de.impl.history.DBBuildHistory - Created build history entry; build id: 256, finish date: 16 Jan 15 10:15:59
[2015-01-16 10:16:00,106]   INFO -   jetbrains.buildServer.SERVER - Start loading cache of build committers...
[2015-01-16 10:16:00,106]   INFO -   jetbrains.buildServer.SERVER - Done loading cache of build committers
[2015-01-16 10:16:00,122]   INFO - tbrains.buildServer.ACTIVITIES - Finished build ProjectName :: ConfigName {id=BuildName, internal id=bt1} #0.1.0.18 {build id=256, promotion id=256, branch=<default>, history=false, agent=teamcity {id=1, host=127.0.0.1:1010, agentTypeId=1, pool=Default}, triggered by "admin" (##userId='1'). Started Fri Jan 16 10:07:28 EST 2015}

... at this point it reindexes every package one more time, and that's it for log file entries.

It seems like only the index after the build has completed is appropriate. The index passes as packages are being generated is concerning. Hopefully this anonymized log except helps clarify the issue.

0

Please sign in to leave a comment.