Details
-
Bug
-
Resolution: Answered
-
Medium
-
None
-
6.0.3
-
Severity 3 - Minor
-
Description
Summary
Build numbers are getting incremented even when the plans fail to get started/triggered. This causes confusion because on the next successful run of the plan we will have a completely unexpected build number. It will look like as if Bamboo jumped several builds for that plan with no explanation, but in the background Bamboo was incrementing the build number for each one of the unsuccessful attempts of triggering that plan.
The actual reason for the failure might differ from case to case. This bug report was created to address the side-effect of the failure. In other words, prevent Bamboo from incrementing the build number for a plan that failed to get started.
Please note this is not about failed builds, but plans that failed to get started in the first place after the change detection process. There's no build result summary for this failure.
The following exception is observed each time Bamboo fails to start a plan:
2017-08-16 15:23:43,600 ERROR [10-BAM::PlanExec:pool-17-thread-1] [ChainExecutionManagerImpl] Plan 'PROJ-PLAN' could not be started.
Steps to Reproduce
To illustrate the problem we will use the following example, but please note there might be multiple causes for the plan to fail to start.
The following scenario requires Bamboo and MySQL.
- Create a new plan and set it up to checkout code from your repository.
- Run a couple builds to make sure it's working fine and Bamboo is able to checkout code from your repository.
- Set up your plan to use the Repository Polling strategy to automatically trigger a new build when there's code change. You can set the Polling frequency to 60 seconds in this example.
- At this point you will have 2 build results for that Plan: build #1 and build #2.
- Perform a couple of changes in the repository and add an emoji to the commit message before pushing the changes. We will use a sad face in this example (😢). You must add an emoji to the commit message to reproduce the problem.
Expected Results
In this case Bamboo will fail to automatically start the plan after detecting the changes because the emoji is a 4-byte UTF-8 character and by default MySQL is configured to handle 3-byte characters only. This doesn't end up well and the following exception is thrown in the logs:
2017-08-16 15:23:43,435 INFO [10-BAM::PlanExec:pool-17-thread-1] [ChangeDetectionListenerAction] : Change detection found 2 changes for plan PROJ-PLAN
2017-08-16 15:23:43,582 INFO [10-BAM::PlanExec:pool-17-thread-1] [AbstractBatchImpl] HHH000010: On release of batch it still contained JDBC statements
2017-08-16 15:23:43,582 WARN [10-BAM::PlanExec:pool-17-thread-1] [SqlExceptionHelper] SQL Error: 1366, SQLState: HY000
2017-08-16 15:23:43,582 ERROR [10-BAM::PlanExec:pool-17-thread-1] [SqlExceptionHelper] Incorrect string value: '\xF0\x9F\x98\x80' for column 'COMMIT_COMMENT_CLOB' at row 1
2017-08-16 15:23:43,582 ERROR [10-BAM::PlanExec:pool-17-thread-1] [BatchingBatch] HHH000315: Exception executing batch [could not execute batch]
2017-08-16 15:23:43,583 ERROR [10-BAM::PlanExec:pool-17-thread-1] [SessionImpl] HHH000346: Error during managed flush [could not execute batch]
2017-08-16 15:23:43,600 ERROR [10-BAM::PlanExec:pool-17-thread-1] [ChainExecutionManagerImpl] Plan 'PROJ-PLAN' could not be started. Exception: JDBC exception on Hibernate data access: SQLException for SQL [insert into USER_COMMIT (REPOSITORY_CHANGESET_ID, AUTHOR_ID, COMMIT_DATE, COMMIT_REVISION, COMMIT_COMMENT_CLOB, FOREIGN_COMMIT, COMMIT_ID) values (?, ?, ?, ?, ?, ?, ?)]; SQL state [HY000]; error code [1366]; could not execute batch; nested exception is org.hibernate.exception.GenericJDBCException: could not execute batch
org.springframework.orm.hibernate5.HibernateJdbcException: JDBC exception on Hibernate data access: SQLException for SQL [insert into USER_COMMIT (REPOSITORY_CHANGESET_ID, AUTHOR_ID, COMMIT_DATE, COMMIT_REVISION, COMMIT_COMMENT_CLOB, FOREIGN_COMMIT, COMMIT_ID) values (?, ?, ?, ?, ?, ?, ?)]; SQL state [HY000]; error code [1366]; could not execute batch; nested exception is org.hibernate.exception.GenericJDBCException: could not execute batch
at org.springframework.orm.hibernate5.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:171)
at org.springframework.orm.hibernate5.HibernateTransactionManager.convertHibernateAccessException(HibernateTransactionManager.java:739)
at org.springframework.orm.hibernate5.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:588)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:761)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:730)
at sun.reflect.GeneratedMethodAccessor171.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:302)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy64.commit(Unknown Source)
at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:484)
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:291)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at com.atlassian.bamboo.author.AuthorCreatorServiceInterceptor.invoke(AuthorCreatorServiceInterceptor.java:40)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:208)
at com.sun.proxy.$Proxy219.create(Unknown Source)
at sun.reflect.GeneratedMethodAccessor1919.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:302)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy216.create(Unknown Source)
at com.atlassian.bamboo.chains.ChainExecutionManagerImpl.createNewChainState(ChainExecutionManagerImpl.java:524)
at com.atlassian.bamboo.chains.ChainExecutionManagerImpl.lambda$start$0(ChainExecutionManagerImpl.java:223)
at com.atlassian.bamboo.chains.ChainExecutionManagerImpl.tryStartChainState(ChainExecutionManagerImpl.java:314)
at com.atlassian.bamboo.chains.ChainExecutionManagerImpl.start(ChainExecutionManagerImpl.java:221)
at sun.reflect.GeneratedMethodAccessor1918.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
...
Caused by: java.sql.BatchUpdateException: Incorrect string value: '\xF0\x9F\x98\x80' for column 'COMMIT_COMMENT_CLOB' at row 1
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:404)
at com.mysql.jdbc.Util.getInstance(Util.java:387)
at com.mysql.jdbc.SQLError.createBatchUpdateException(SQLError.java:1154)
at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1773)
at com.mysql.jdbc.PreparedStatement.executeBatchInternal(PreparedStatement.java:1257)
at com.mysql.jdbc.StatementImpl.executeBatch(StatementImpl.java:959)
at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:2544)
at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:110)
... 94 more
Caused by: java.sql.SQLException: Incorrect string value: '\xF0\x9F\x98\x80' for column 'COMMIT_COMMENT_CLOB' at row 1
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:957)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3878)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3814)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2478)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2625)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2551)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861)
at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2073)
at com.mysql.jdbc.PreparedStatement.executeBatchSerially(PreparedStatement.java:1751)
... 98 more
2017-08-16 15:23:43,601 INFO [10-BAM::PlanExec:pool-17-thread-1] [DefaultErrorHandler] Recording an error: Plan 'PROJ-PLAN' could not be started. Exception: JDBC exception on Hibernate data access: SQLException for SQL [insert into USER_COMMIT (REPOSITORY_CHANGESET_ID, AUTHOR_ID, COMMIT_DATE, COMMIT_REVISION, COMMIT_COMMENT_CLOB, FOREIGN_COMMIT, COMMIT_ID) values (?, ?, ?, ?, ?, ?, ?)]; SQL state [HY000]; error code [1366]; could not execute batch; nested exception is org.hibernate.exception.GenericJDBCException: could not execute batch : PROJ-PLAN : JDBC exception on Hibernate data access: SQLException for SQL [insert into USER_COMMIT (REPOSITORY_CHANGESET_ID, AUTHOR_ID, COMMIT_DATE, COMMIT_REVISION, COMMIT_COMMENT_CLOB, FOREIGN_COMMIT, COMMIT_ID) values (?, ?, ?, ?, ?, ?, ?)]; SQL state [HY000]; error code [1366]; could not execute batch; nested exception is org.hibernate.exception.GenericJDBCException: could not execute batch
We will not get into the details of the error message because that's not the point here. After waiting 5 minutes, looking at the BUILD_NUMBERS table, the NEXT_BUILD_NUMBER value for that plan should be 3 because we only triggered 2 builds after all. Even though Bamboo failed to start the plan after adding the emoji to the commit message, there's no indication in the GUI of a failed attempt to start that plan except for the error message. This means you will only see 2 results, from the 2 builds we triggered previously.
Actual Results
During the 5 minutes we waited for the plan to start up, Bamboo ran change detection and failed to start that plan 5 times. The NEXT_BUILD_NUMBER value for that plan increased significantly and we now see NEXT_BUILD_NUMBER set to 8. Bamboo increased that value after each unsuccessful attempt. After fixing the problem (e.g. getting rid of the emoji) and triggering a new build, Bamboo reports we just completed the eighth build for that plan even though we really only triggered 2 builds up to this point. So we are now at build #8 and there's no trace of builds #3 to #7 in the GUI or in the database.
Attachments
Issue Links
- has a derivative of
-
-
- Closed
-