Unexpected error during build messages processing in TeamCity - 2023.05

Avatar
Patrick
Created

After updating to 2023.05, we are facing issues with our builds. After succesfully running the unit tests, we sometimes get the error: "Unexpected error during build messages processing in TeamCity".

Looking into the teamcity-server.log, we can only see: 
Unexpected exception occurred during message processing, will change build status to failing for build #3.1.50379. [Message pack info...]
java.lang.NullPointerException: null

Message pack info has been redacted as it only shows some test namespaces, but if they are needed please let me know.

 

We do notice some warnings around the error that might help here:

Release flow '1754443963400_0-1022' as it is opened again with a different parent: 1754443963400_0-1028;

and

Releasing flow with unfinished tests: [TestName] in build 766347

 

Other than that, we don't see any information in the logging, so we are kinda stuck on how to solve this issue.

 

We use nUnit for the tests along with the latest version of NUnit.Extension.TeamCityEventListener. We noticed that the TeamCityEventListener hasn't been updated in a while.

Votes

1

Share

2 comments
Avatar
Dominique Boyer
Created

I have exactly the same issue since we upgraded to 2023.05 :

Here is what I've in the logs :

[2023-06-22 10:05:32,100]  ERROR -   jetbrains.buildServer.SERVER - Unexpected exception occurred during message processing, will change build status to failing for build #5131 {build id=43868, buildTypeId=AlcuinUnitTests}, messages pack: [BuildMessage1 85161 Text ##teamcity[testFinished name='Alcuin.Services.JS.Job.JobBase.Tests.JobBase_ProgressionEventArgs.Completed' duration='3254' flowId='259217021311500_1-1001'] DefaultMessage NORMAL 259217021311500 , BuildMessage1 85162 Text ##teamcity[flowFinished flowId='259217021311500_1-1001'] DefaultMessage NORMAL 259217021311500 , BuildMessage1 85163 Text ##teamcity[flowStarted flowId='259217021311500_1-1002' parent='259217021311500_1-1003'] DefaultMessage NORMAL 259217021311500 , BuildMessage1 85164 Text ##teamcity[testStarted name='Alcuin.Services.JS.Job.JobBase.Tests.JobBase_ProgressionEventArgs.Error' captureStandardOutput='false' flowId='259217021311500_1-1002'] DefaultMessage NORMAL 259217021311500 , BuildMessage1 85165 Text ##teamcity[testFinished name='Alcuin.Services.JS.Job.JobBase.Tests.JobBase_ProgressionEventArgs.Error' duration='47' flowId='259217021311500_1-1002'] DefaultMessage NORMAL 259217021311500 , BuildMessage1 85166 Text ##teamcity[flowFinished flowId='259217021311500_1-1002'] DefaultMessage NORMAL 259217021311500 , BuildMessage1 85167 Text ##teamcity[testSuiteFinished name='Alcuin.Services.JS.Job.JobBase.Tests.dll' flowId='259217021311500_1-1003'] DefaultMessage NORMAL 259217021311500 , BuildMessage1 85168 Text ##teamcity[flowFinished flowId='259217021311500_1-1003'] DefaultMessage NORMAL 259217021311500 , BuildMessage1 85169 Text  DefaultMessage NORMAL 259217021311500 , BuildMessage1 85170 Text Run Settings DefaultMessage NORMAL 259217021311500 , BuildMessage1 85171 Text     DisposeRunners: True DefaultMessage NORMAL 259217021311500 , BuildMessage1 85172 Text     InternalTraceLevel: Verbose DefaultMessage NORMAL 259217021311500 , BuildMessage1 85173 Text     WorkDirectory: H:\TeamCity\buildAgent\work\5e9b572fce1b943f DefaultMessage NORMAL 259217021311500 , BuildMessage1 85174 Text     ImageRuntimeVersion: 4.0.30319 DefaultMessage NORMAL 259217021311500 , BuildMessage1 85175 Text     ImageTargetFrameworkName: .NETFramework,Version=v4.8 DefaultMessage NORMAL 259217021311500 , BuildMessage1 85176 Text     ImageRequiresX86: False DefaultMessage NORMAL 259217021311500 , BuildMessage1 85177 Text     ImageRequiresDefaultAppDomainAssemblyResolver: False DefaultMessage NORMAL 259217021311500 , BuildMessage1 85178 Text     TargetRuntimeFramework: net-4.8 DefaultMessage NORMAL 259217021311500 , BuildMessage1 85179 Text     NumberOfTestWorkers: 8 DefaultMessage NORMAL 259217021311500 , BuildMessage1 85180 Text  DefaultMessage NORMAL 259217021311500 , BuildMessage1 85181 Text Test Run Summary DefaultMessage NORMAL 259217021311500 , BuildMessage1 85182 Text   Overall result: Passed DefaultMessage NORMAL 259217021311500 , BuildMessage1 85183 Text   Test Count: 2, Passed: 2, Failed: 0, Warnings: 0, Inconclusive: 0, Skipped: 0 DefaultMessage NORMAL 259217021311500 , BuildMessage1 85184 Text   Start time: 2023-06-22 08:05:24Z DefaultMessage NORMAL 259217021311500 , BuildMessage1 85185 Text     End time: 2023-06-22 08:05:28Z DefaultMessage NORMAL 259217021311500 , BuildMessage1 85186 Text     Duration: 4.458 seconds DefaultMessage NORMAL 259217021311500 , BuildMessage1 85187 Text  DefaultMessage NORMAL 259217021311500 , BuildMessage1 85188 Text Results (nunit3) saved as H:\TeamCity\buildAgent\temp\buildTmp\Alcuin.Services.JS.Job.JobBase.Tests.nunit.xml DefaultMessage NORMAL 259217021311500 , BuildMessage1 85189 Text Runtime Environment DefaultMessage NORMAL 259217021311500 , BuildMessage1 85190 Text    OS Version: Microsoft Windows NT 6.2.9200.0 DefaultMessage NORMAL 259217021311500 , BuildMessage1 85191 Text    Runtime: .NET Framework CLR v4.0.30319.42000 DefaultMessage NORMAL 259217021311500 , BuildMessage1 85192 Text  DefaultMessage NORMAL 259217021311500 , BuildMessage1 85193 Text Test Files DefaultMessage NORMAL 259217021311500 , BuildMessage1 85194 Text     H:\TeamCity\buildAgent\work\5e9b572fce1b943f\Tests\Alcuin.Services.JS.Job.MassUpdate.Tests\bin\Debug\net48\Alcuin.Services.JS.Job.MassUpdate.Tests.dll DefaultMessage NORMAL 259217021311500 , BuildMessage1 85195 Text  DefaultMessage NORMAL 259217021311500 , BuildMessage1 85196 Text Test Filters DefaultMessage NORMAL 259217021311500 , BuildMessage1 85197 Text     Where: namespace =~ Alcuin.Services.JS.Job.MassUpdate.Tests DefaultMessage NORMAL 259217021311500 , BuildMessage1 85198 Text  DefaultMessage NORMAL 259217021311500 ]
 
java.lang.NullPointerException: null
at jetbrains.buildServer.serverSide.buildLog.BuildLogLocalState.updateFlowHierarchyCache(BuildLogLocalState.java:33) ~[server.jar:?]
at jetbrains.buildServer.serverSide.buildLog.BuildLogLocalState.pushMessage(BuildLogLocalState.java:107) ~[server.jar:?]
at jetbrains.buildServer.serverSide.buildLog.ServerBuildLog.processLogMessageDataAsync(ServerBuildLog.java:124) ~[server.jar:?]
at jetbrains.buildServer.serverSide.buildLog.ServerBuildLog.flowFinished(ServerBuildLog.java:69) ~[server.jar:?]
at jetbrains.buildServer.serverSide.stat.DefaultMessagesProcessor.releaseFlow(DefaultMessagesProcessor.java:262) ~[server.jar:?]
at jetbrains.buildServer.serverSide.stat.DefaultMessagesProcessor.access$5500(DefaultMessagesProcessor.java:20) ~[server.jar:?]
at jetbrains.buildServer.serverSide.stat.DefaultMessagesProcessor$FlowFinishedProcessor.processMessage(DefaultMessagesProcessor.java:5) ~[server.jar:?]
at jetbrains.buildServer.serverSide.stat.DefaultMessagesProcessor.doProcessMessage(DefaultMessagesProcessor.java:13) ~[server.jar:?]
at jetbrains.buildServer.serverSide.stat.BaseMessageProcessor.processMessage(BaseMessageProcessor.java:7) ~[server.jar:?]
at jetbrains.buildServer.serverSide.impl.BuildAgentMessagesQueue$BuildMessagesQueue.doProcessMessage(BuildAgentMessagesQueue.java:150) ~[server.jar:?]
at jetbrains.buildServer.serverSide.impl.BuildAgentMessagesQueue$BuildMessagesQueue.access$1000(BuildAgentMessagesQueue.java:126) ~[server.jar:?]
at jetbrains.buildServer.serverSide.impl.BuildAgentMessagesQueue$BuildMessagesQueue$1.doInTransactionWithoutResult(BuildAgentMessagesQueue.java:2) ~[server.jar:?]
at org.springframework.transaction.support.TransactionCallbackWithoutResult.doInTransaction(TransactionCallbackWithoutResult.java:36) ~[spring.jar:5.3.18]
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ~[spring.jar:5.3.18]
at jetbrains.buildServer.serverSide.impl.BuildAgentMessagesQueue$BuildMessagesQueue.doProcessMessages(BuildAgentMessagesQueue.java:33) ~[server.jar:?]
at jetbrains.buildServer.serverSide.impl.BuildAgentMessagesQueue$BuildMessagesQueue.lambda$processMessages$1(BuildAgentMessagesQueue.java:145) ~[server.jar:?]
at jetbrains.buildServer.util.NamedThreadFactory.executeWithNewThreadName(NamedThreadFactory.java:76) ~[common-api.jar:129203]
at jetbrains.buildServer.serverSide.impl.BuildAgentMessagesQueue$BuildMessagesQueue.processMessages(BuildAgentMessagesQueue.java:50) ~[server.jar:?]
at jetbrains.buildServer.serverSide.impl.BuildAgentMessagesQueue$ProcessorTask.run(BuildAgentMessagesQueue.java:47) ~[server.jar:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
at java.lang.Thread.run(Thread.java:829) ~[?:?]
0
Avatar
Anatoly Cherenkov
Created
Hi! The fix is coming with the next patch, 2023.05.1: https://youtrack.jetbrains.com/issue/TW-81913. We expect to release it at the end of June or early July. 
Thanks for reporting the issue, and sorry about the inconvenience.
0

Please sign in to leave a comment.