SQL exception upon build start while inserting into node_tasks_long_value

Hello,

We are facing an SQL issue when a build process just started (sorry about the long text):

 

[16:42:03]    Unexpected exception: SQL error when doing 'DML query' while performing SQL query: SQL DML: insert into node_tasks_long_value (uuid, long_value) values (?, ?) | PARAMETERS: "231ff0d3-5579-4055-8dcf-8632eeb1959f", "$plain:{\"body\":\"\u003cAgentBuild\u003e\u003cmyBuildId\u003e155856\u003c/myBuildId\u003e\u003cmyBuildTypeId\u003ebt66\u003c/myBuildTypeId\u003e\u003cmyBuildTypeExternalId\u003eApplc_OnDemandBuild\u003c/myBuildTypeExternalId\u003e\u003cmyArtifactPaths\u003e\u003c/myArtifactPaths\u003e\u003cmyPersonal\u003efalse\u003c/myPersonal\u003e\u003cmyPersonalPatchAvailable\u003efalse\u003c/myPersonalPatchAvailable\u003e\u003cmyCleanCheckoutEnforcedBuildId\u003e-1\u003c/myCleanCheckoutEnforcedBuildId\u003e\u003cmyAccessCode\u003eSnm8L4p9z0x1RaLQDA8ELMsAV9j2xi94\u003c/myAccessCode\u003e\u003cmyCheckoutType\u003eMANUAL\u003c/myCheckoutType\u003e\u003cmyServerParameters class\u003d\\"ParametersMap\\"\u003e\u003cdictionary\u003e\u003cv\u003eCIS\u003c/v\u003e\u003cv\u003ePythonVEnv\u003c/v\u003e\u003cv\u003e3_8\u003c/v\u003e\u003cv\u003eenv\u003c/v\u003e\u003cv\u003esBuildPlatforms\u003c/v\u003e\u003cv\u003eWin64_Steam\u003c/v\u003e\u003cv\u003eteamcity\u003c/v\u003e\u003cv\u003ebuild\u003c/v\u003e\u003cv\u003etriggeredBy\u003c/v\u003e\u003cv\u003eusername\u003c/v\u003e\u003cv\u003ebuilder\u003c/v\u003e\u003cv\u003esystem\u003c/v\u003e\u003cv\u003ebuildConfName\u003c/v\u003e\u003cv\u003eOn Demand Build\u003c/v\u003e\u003cv\u003ebForDistribution\u003c/v\u003e\u003cv\u003eTrue\u003c/v\u003e\u003cv\u003ebuildType\u003c/v\u003e\u003cv\u003eid\u003c/v\u003e\u003cv\u003eApplc_OnDemandBuild\u003c/v\u003e\u003cv\u003ecounter\u003c/v\u003e\u003cv\u003e134\u003c/v\u003e\u003cv\u003evcsroot\u003c/v\u003e\u003cv\u003eApplc_DailyWorkspace\u003c/v\u003e\u003cv\u003euse-client\u003c/v\u003e\u003cv\u003estream\u003c/v\u003e\u003cv\u003esLatestPatchPathPS5\u003c/v\u003e\u003cv\u003e\u003c/v\u003e\u003cv\u003eLocalWorkspace\u003c/v\u003e\u003cv\u003ebuilder_%teamcity.agent.name%_AP\u003c/v\u003e\u003cv\u003esLatestPatchPathPS4\u003c/v\u003e\u003cv\u003ePublishFolder\u003c/v\u003e\u003cv\u003eTest\u003c/v\u003e\u003cv\u003eAgones\u003c/v\u003e\u003cv\u003eDeployFleet\u003c/v\u003e\u003cv\u003eFalse\u003c...parameters\u003c/string\u003e\u003cstring\u003eBuildScripts\\ProjectOnDemandBuild.py\u003c/string\u003e\u003c/entry\u003e\u003centry\u003e\u003cstring\u003eteamcity.build.workingDir\u003c/string\u003e\u003cstring\u003e%env.VCS_ROOT%\\ue\u003c/string\u003e\u003c/entry\u003e\u003centry\u003e\u003cstring\u003eteamcity.step.mode\u003c/string\u003e\u003cstring\u003edefault\u003c/string\u003e\u003c/entry\u003e\u003c/myRunnerParameters\u003e\u003cmyServerParameters class\u003d\\"tree-map\\"\u003e\u003centry\u003e\u003cstring\u003eteamcity.build.step.name\u003c/string\u003e\u003cstring\u003eExecute build script\u003c/string\u003e\u003c/entry\u003e\u003c/myServerParameters\u003e\u003c/jetbrains.buildServer.agentServer.BuildRunnerData\u003e\u003c/myBuildRunners\u003e\u003cmyDefaultExecutionTimeout\u003e0\u003c/myDefaultExecutionTimeout\u003e\u003cmyBuildFeatures\u003e\u003cjetbrains.buildServer.agentServer.BuildFeatureInfo\u003e\u003cmyId\u003eBUILD_EXT_13\u003c/myId\u003e\u003cmyType\u003eBuildFailureOnMessage\u003c/myType\u003e\u003cmyParameters class\u003d\\"tree-map\\"\u003e\u003centry\u003e\u003cstring\u003ebuildFailureOnMessage.conditionType\u003c/string\u003e\u003cstring\u003econtains\u003c/string\u003e\u003c/entry\u003e\u003centry\u003e\u003cstring\u003ebuildFailureOnMessage.messagePattern\u003c/string\u003e\u003cstring\u003eERROR:\u003c/string\u003e\u003c/entry\u003e\u003centry\u003e\u003cstring\u003ebuildFailureOnMessage.outputText\u003c/string\u003e\u003cstring\u003eError messages in build log\u003c/string\u003e\u003c/entry\u003e\u003centry\u003e\u003cstring\u003ebuildFailureOnMessage.reverse\u003c/string\u003e\u003cstring\u003efalse\u003c/string\u003e\u003c/entry\u003e\u003c/myParameters\u003e\u003c/jetbrains.buildServer.agentServer.BuildFeatureInfo\u003e\u003c/myBuildFeatures\u003e\u003cmyRequiredTools/\u003e\u003cmyArtifactStorageSettings/\u003e\u003cmyOwnerNodeId\u003eMAIN_SERVER\u003c/myOwnerNodeId\u003e\u003c/AgentBuild\u003e\",\"contentType\":\"application/xml\"}": com.mysql.jdbc.PacketTooBigException: Packet for query is too large (1235032 > 1048576). You can change this value on the server by setting the max_allowed_packet' variable.

At first glance, we supposed we should rise the max_allowed_packet DB config value, but later we realized that it seems that the issue could be related to the 'body' malformed XML string? Once you replace the unicode scaped characters by “<,>,=” where appropiate, we obtain thiis XML string:

 

<AgentBuild>

    <myBuildId>155856</myBuildId>

    <myBuildTypeId>bt66</myBuildTypeId>

    <myBuildTypeExternalId>Applc_OnDemandBuild</myBuildTypeExternalId>

    <myArtifactPaths></myArtifactPaths>

    <myPersonal>false</myPersonal>

    <myPersonalPatchAvailable>false</myPersonalPatchAvailable>

    <myCleanCheckoutEnforcedBuildId>-1</myCleanCheckoutEnforcedBuildId>

    <myAccessCode>Snm8L4p9z0x1RaLQDA8ELMsAV9j2xi94</myAccessCode>

    <myCheckoutType>MANUAL</myCheckoutType>

    <myServerParameters class=\\"ParametersMap\\">

        <dictionary><v>CIS</v>

            <v>PythonVEnv</v>

            <v>3_8</v>

            <v>env</v>

            <v>sBuildPlatforms</v>

            <v>Win64_Steam</v>

            <v>teamcity</v>

            <v>build</v>

            <v>triggeredBy</v>

            <v>username</v>

            <v>builder</v>

            <v>system</v>

            <v>buildConfName</v>

            <v>On Demand Build</v>

            <v>bForDistribution</v>

            <v>True</v><v>buildType</v>

            <v>id</v>

            <v>Applc_OnDemandBuild</v>

            <v>counter</v>

            <v>134</v>

            <v>vcsroot</v>

            <v>Applc_DailyWorkspace</v>

            <v>use-client</v>

            <v>stream</v>

            <v>sLatestPatchPathPS5</v>

            <v></v>

            <v>LocalWorkspace</v>

            <v>builder_%teamcity.agent.name%_AP</v>

            <v>sLatestPatchPathPS4</v>

            <v>PublishFolder</v>

            <v>Test</v><v>Agones</v>

            <v>DeployFleet</v>

            <v>False<...parameters

            </string>

            <string>BuildScripts\\ProjectOnDemandBuild.py</string>

        </entry>

        <entry>

            <string>teamcity.build.workingDir</string>

            <string>%env.VCS_ROOT%\\ue</string>

        </entry>

        <entry>

            <string>teamcity.step.mode</string>

            <string>default</string>

        </entry>

    </myRunnerParameters>

    <myServerParameters class=\\"tree-map\\">

        <entry>

            <string>teamcity.build.step.name</string>

            <string>Execute build script</string>

        </entry>

    </myServerParameters>

</jetbrains.buildServer.agentServer.BuildRunnerData>

</myBuildRunners>

<myDefaultExecutionTimeout>0</myDefaultExecutionTimeout>

<myBuildFeatures>

    <jetbrains.buildServer.agentServer.BuildFeatureInfo>

        <myId>BUILD_EXT_13</myId>

        <myType>BuildFailureOnMessage</myType>

        <myParameters class=\\"tree-map\\">

            <entry>

                <string>buildFailureOnMessage.conditionType</string>

                <string>contains</string>

            </entry>

            <entry>

                <string>buildFailureOnMessage.messagePattern</string>

                <string>ERROR:</string>

            </entry>

            <entry>

                <string>buildFailureOnMessage.outputText</string>

                <string>Error messages in build log</string>

            </entry>

            <entry>

                <string>buildFailureOnMessage.reverse</string>

                <string>false</string>

            </entry>

        </myParameters>

    </jetbrains.buildServer.agentServer.BuildFeatureInfo>

</myBuildFeatures>

<myRequiredTools/>

<myArtifactStorageSettings/>

<myOwnerNodeId>MAIN_SERVER</myOwnerNodeId>

</AgentBuild>

 

Please notice that from “<v>False<...parameters” the XML format is broken: there are lots of missing build parameters that we have in the build configuration and markup pairs are broken. We are not sure if the XML issues are only present in the build log (printing issue) or there are actual issues while formatting the SQL string that is sent to the DB. Maybe character scape issues?

If we duplicate the build configuration and launch a build on it, the issue is not present.

We are using Teamcity Professional 2023.11.3 (build 147512). Does anyone have a clue on this? Any help would be much appreciated.

 

Regards,

Marcos Falcón Pérez

Tech Director

Saber Interactive

0
5 comments
Hi Marcos,

It seems that just the first and last few lines of the XML were outputted to the logs to avoid flooding, so the XML should be correct.

Please check if increasing the max_allowed_packet variable will help, as it is a known cause for the PacketTooBigException. You can refer to the steps described in the TeamCity documentation: https://www.jetbrains.com/help/teamcity/common-problems.html#MySQL+JDBC+driver+error%3A+PacketTooBigException.

If that doesn't help, it may be worthwhile to compare the XML files for the failing and duplicated configurations. Open the /config/projects, locate your project and build configurations, the XMLs can be found there.

Please share these XML files if you don't see any noticeable differences, I will check them as well. You can upload it to https://uploads.jetbrains.com/ and share the upload ID to share it privately.

Best regards,
Anton
0

Hi Anton,

Thanks for your quick response. Comparing both (original build ocnfiguration and copied one) XML files, there are no differences, apart from build config ID of course.

What is weird is why triggering the copied configuration is not failing (same XML, same inherited build parameters). We wonder if original and copied could be executing different queries to the DB? Copied build configuration has just few builds on its history, but original one has hundreds. How could we monitor the DB queries? We discovered the teamcity-sql.log file but it seems that not all queries are logged. Any chance to rise the verbosity of that logs?

Kind regards,

Marcos

 

0
Dear Marcos,

You are correct, since there are no differences in XML as expected, to point out the exact cause, you would need to compare the DB queries in these two scenarios. The SQL logging is described here: https://www.jetbrains.com/help/teamcity/reporting-issues.html#Database-related+Slowdowns. The default setting is to log all queries that take longer than 1 second to execute, but you can change this setting as described in the documentation.

In any way, large inserts are expected in the node_tasks_long_value table. I can't provide the exact implementation details, but as far as I can tell, multiple factors, not only the configuration XML, may affect the size of the query. PacketTooBigException is a common issue when the max_allowed_packet value is left default. It is a general and mentioned in the documentation recommendation to increase it. Please let me know if it helps.

Best regards,
Anton
0

Hi Anton,

We faced a weird “fixed without doing almost nothing” situation. The issue is gone after setting the log profile to ‘debug-sql’. No new SQL exceptions due to max_allowed_packet even after setting back the log profile to ‘Default’.

We think that there could be an underliying issue with the SQL string handling. Maybe a string buffer overrun? Strangely, this issue happened after upgrading to 2023.11.3 from an old version 2021.X.Y (cannot recall the exact version).

Unfortunately, lines printed to teamcity-sql.log file strip long strings too, so we cannot confirm the lenght of affected SQL queries, but taking into consideration that we have been using the same build configurations, with the same parameter set, same DB instance, etc. for more than seven years, we don't see how the max_allowed_packet was exceeded just for a certain build config in this short period of time only.

I'll keep this post alive if we found the issue again.

Best regards,

Marcos

 

0
Dear Marcos,

Thank you for letting me know that the issue is resolved for now. Please consider increasing the max_allowed_packet value as stated in the documentation to prevent it from happening again in the future.

Best regards,
Anton
0

Please sign in to leave a comment.