Because a timestamp is casted to Instant and retain it on MemoryRecord,
but MemoryRecord tries to cast from Timestamp to Instant and raises ClassCastException.
And so, retryExecutor abort on the first retry.
error log with #325
2023-10-02 09:51:58.971 2023-10-02 09:51:58.971 +0000 [INFO] (0019:task-0012): > 0.86 seconds (loaded 3,744 rows in total)
2023-10-02 09:51:59.375 2023-10-02 09:51:59.376 +0000 [ERROR] (0018:task-0013): Operation failed (first exception:{SQLState=1213, ErrorCode=40001})
2023-10-02 09:51:59.375 java.sql.BatchUpdateException: Deadlock found when trying to get lock; try restarting transaction
2023-10-02 09:51:59.375 at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
2023-10-02 09:51:59.375 at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
2023-10-02 09:51:59.375 at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
2023-10-02 09:51:59.377 at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
2023-10-02 09:51:59.377 at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
2023-10-02 09:51:59.377 at com.mysql.jdbc.Util.getInstance(Util.java:408)
2023-10-02 09:51:59.377 at com.mysql.jdbc.SQLError.createBatchUpdateException(SQLError.java:1162)
2023-10-02 09:51:59.377 at com.mysql.jdbc.StatementImpl.handleExceptionForBatch(StatementImpl.java:1290)
2023-10-02 09:51:59.377 at com.mysql.jdbc.PreparedStatement.executeBatchedInserts(PreparedStatement.java:1550)
2023-10-02 09:51:59.377 at com.mysql.jdbc.PreparedStatement.executeBatchInternal(PreparedStatement.java:1253)
2023-10-02 09:51:59.377 at com.mysql.jdbc.StatementImpl.executeBatch(StatementImpl.java:970)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.StandardBatchInsert.flush(StandardBatchInsert.java:82)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin$PluginPageOutput$1.run(AbstractJdbcOutputPlugin.java:1192)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin$RetryableSQLExecution.call(AbstractJdbcOutputPlugin.java:1343)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin$RetryableSQLExecution.call(AbstractJdbcOutputPlugin.java:1331)
2023-10-02 09:51:59.377 at org.embulk.util.retryhelper.RetryExecutor.run(RetryExecutor.java:109)
2023-10-02 09:51:59.377 at org.embulk.util.retryhelper.RetryExecutor.runInterruptible(RetryExecutor.java:90)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin.withRetry(AbstractJdbcOutputPlugin.java:1309)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin.withRetry(AbstractJdbcOutputPlugin.java:1301)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin$PluginPageOutput.flush(AbstractJdbcOutputPlugin.java:1182)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin$PluginPageOutput.add(AbstractJdbcOutputPlugin.java:1173)
2023-10-02 09:51:59.377 at org.embulk.spi.PageBuilderImpl.doFlush(PageBuilderImpl.java:244)
2023-10-02 09:51:59.377 at org.embulk.spi.PageBuilderImpl.flush(PageBuilderImpl.java:249)
2023-10-02 09:51:59.377 at org.embulk.spi.PageBuilderImpl.addRecord(PageBuilderImpl.java:228)
2023-10-02 09:51:59.377 at org.embulk.spi.PageBuilder.addRecord(PageBuilder.java:220)
2023-10-02 09:51:59.377 at org.embulk.parser.avro.AvroParserPlugin.run(AvroParserPlugin.java:232)
2023-10-02 09:51:59.377 at org.embulk.spi.FileInputRunner.run(FileInputRunner.java:138)
2023-10-02 09:51:59.377 at org.embulk.spi.util.ExecutorsInternal.process(ExecutorsInternal.java:60)
2023-10-02 09:51:59.377 at org.embulk.spi.util.ExecutorsInternal.process(ExecutorsInternal.java:37)
2023-10-02 09:51:59.377 at org.embulk.exec.LocalExecutorPlugin$DirectExecutor$1.call(LocalExecutorPlugin.java:194)
2023-10-02 09:51:59.377 at org.embulk.exec.LocalExecutorPlugin$DirectExecutor$1.call(LocalExecutorPlugin.java:191)
2023-10-02 09:51:59.377 at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
2023-10-02 09:51:59.377 at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2023-10-02 09:51:59.377 at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2023-10-02 09:51:59.377 at java.base/java.lang.Thread.run(Thread.java:829)
2023-10-02 09:51:59.377 Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
2023-10-02 09:51:59.377 at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
2023-10-02 09:51:59.377 at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
2023-10-02 09:51:59.377 at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
2023-10-02 09:51:59.377 at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
2023-10-02 09:51:59.377 at com.mysql.jdbc.Util.handleNewInstance(Util.java:425)
2023-10-02 09:51:59.377 at com.mysql.jdbc.Util.getInstance(Util.java:408)
2023-10-02 09:51:59.377 at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:951)
2023-10-02 09:51:59.377 at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3973)
2023-10-02 09:51:59.377 at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3909)
2023-10-02 09:51:59.377 at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2527)
2023-10-02 09:51:59.377 at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2680)
2023-10-02 09:51:59.377 at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2487)
2023-10-02 09:51:59.377 at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1858)
2023-10-02 09:51:59.377 at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2079)
2023-10-02 09:51:59.377 at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2013)
2023-10-02 09:51:59.377 at com.mysql.jdbc.PreparedStatement.executeLargeUpdate(PreparedStatement.java:5104)
2023-10-02 09:51:59.377 at com.mysql.jdbc.PreparedStatement.executeBatchedInserts(PreparedStatement.java:1548)
2023-10-02 09:51:59.377 ... 26 common frames omitted
2023-10-02 09:51:59.377 2023-10-02 09:51:59.376 +0000 [ERROR] (0018:task-0013): Operation failed (last exception)
2023-10-02 09:51:59.377 java.lang.ClassCastException: class java.time.Instant cannot be cast to class org.embulk.spi.time.Timestamp (java.time.Instant is in module java.base of loader 'bootstrap'; org.embulk.spi.time.Timestamp is in unnamed module of loader 'app')
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.MemoryRecord.getTimestamp(MemoryRecord.java:44)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.setter.ColumnSetterVisitor.timestampColumn(ColumnSetterVisitor.java:104)
2023-10-02 09:51:59.377 at org.embulk.spi.Column.visit(Column.java:77)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin$PluginPageOutput.retryColumnsSetters(AbstractJdbcOutputPlugin.java:1265)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin$PluginPageOutput$1.run(AbstractJdbcOutputPlugin.java:1189)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin$RetryableSQLExecution.call(AbstractJdbcOutputPlugin.java:1343)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin$RetryableSQLExecution.call(AbstractJdbcOutputPlugin.java:1331)
2023-10-02 09:51:59.377 at org.embulk.util.retryhelper.RetryExecutor.run(RetryExecutor.java:109)
2023-10-02 09:51:59.377 at org.embulk.util.retryhelper.RetryExecutor.runInterruptible(RetryExecutor.java:90)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin.withRetry(AbstractJdbcOutputPlugin.java:1309)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin.withRetry(AbstractJdbcOutputPlugin.java:1301)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin$PluginPageOutput.flush(AbstractJdbcOutputPlugin.java:1182)
2023-10-02 09:51:59.377 at org.embulk.output.jdbc.AbstractJdbcOutputPlugin$PluginPageOutput.add(AbstractJdbcOutputPlugin.java:1173)
2023-10-02 09:51:59.377 at org.embulk.spi.PageBuilderImpl.doFlush(PageBuilderImpl.java:244)
2023-10-02 09:51:59.377 at org.embulk.spi.PageBuilderImpl.flush(PageBuilderImpl.java:249)
2023-10-02 09:51:59.377 at org.embulk.spi.PageBuilderImpl.addRecord(PageBuilderImpl.java:228)
2023-10-02 09:51:59.377 at org.embulk.spi.PageBuilder.addRecord(PageBuilder.java:220)
2023-10-02 09:51:59.377 at org.embulk.parser.avro.AvroParserPlugin.run(AvroParserPlugin.java:232)
2023-10-02 09:51:59.377 at org.embulk.spi.FileInputRunner.run(FileInputRunner.java:138)
2023-10-02 09:51:59.377 at org.embulk.spi.util.ExecutorsInternal.process(ExecutorsInternal.java:60)
2023-10-02 09:51:59.377 at org.embulk.spi.util.ExecutorsInternal.process(ExecutorsInternal.java:37)
2023-10-02 09:51:59.377 at org.embulk.exec.LocalExecutorPlugin$DirectExecutor$1.call(LocalExecutorPlugin.java:194)
2023-10-02 09:51:59.377 at org.embulk.exec.LocalExecutorPlugin$DirectExecutor$1.call(LocalExecutorPlugin.java:191)
2023-10-02 09:51:59.377 at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
2023-10-02 09:51:59.377 at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
2023-10-02 09:51:59.377 at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
2023-10-02 09:51:59.377 at java.base/java.lang.Thread.run(Thread.java:829)
in order to avoid to abort retrying.
Because a timestamp is casted to Instant and retain it on MemoryRecord, but MemoryRecord tries to cast from Timestamp to Instant and raises ClassCastException. And so, retryExecutor abort on the first retry.
error log with #325