Prism

Prism

91.2k Downloads

[BUG] Incorrect string value exception

Bobcat00 opened this issue ยท 4 comments

commented

Describe the bug

java.sql.SQLException: Incorrect string value: '\xF0\xB6\xB0\x99\xE2\xB6...' for column 'data' at row 1
	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:965)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3933)
	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3869)
	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2524)
	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2675)
	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2465)
	at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1915)
	at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2136)
	at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2070)
	at com.mysql.jdbc.PreparedStatement.executeLargeUpdate(PreparedStatement.java:5187)
	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2055)
	at com.botsko.prism.libs.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61)
	at com.botsko.prism.libs.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java)
	at me.botsko.prism.database.sql.SqlInsertBuilder.insertActionIntoDatabase(SqlInsertBuilder.java:88)
	at me.botsko.prism.actionlibs.RecordingTask.insertActionsIntoDatabase(RecordingTask.java:118)
	at me.botsko.prism.actionlibs.RecordingTask.save(RecordingTask.java:46)
	at me.botsko.prism.actionlibs.RecordingTask.run(RecordingTask.java:153)
	at org.bukkit.craftbukkit.v1_16_R3.scheduler.CraftTask.run(CraftTask.java:81)
	at org.bukkit.craftbukkit.v1_16_R3.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:54)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

Also see it with \xF4\x86\x97\x85\xED\x8C...

To Reproduce
I'm not sure what was being logged, but this happens several times a day. There's nothing in the log to indicate what was going on at the time.

Server (please complete the following information):

  • Prism Version: v2.1.8-SNAPSHOT- build 216 plus changes from PR 251
  • Server Type: Spigot
  • Server Version: 3019-Spigot-bff5261-ee5006d (MC: 1.16.5)
commented

It looks like it was saving an action and the data included a color? - if you turn on debugging it will log the query that caused the error,

commented

Here's the debug log:

2021-03-12 20:23:01 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:01 [INFO] [Prism] - Debug - Batch insert was commit: 1615598581846
2021-03-12 20:23:06 [INFO] [Prism] - Debug - Beginning batch insert from queue. 1615598586026
2021-03-12 20:23:06 [INFO] [Prism] - Debug - Loaded player lava, id: 5 into the cache.
2021-03-12 20:23:06 [INFO] [Prism] - Debug - Batch insert was commit: 1615598586049
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Beginning batch insert from queue. 1615598588276
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [WARN] java.sql.SQLException: Incorrect string value: '\xF4\x86\x97\x85\xED\x8C...' for column 'data' at row 1
2021-03-12 20:23:08 [WARN] 	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:965)
2021-03-12 20:23:08 [WARN] 	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3933)
2021-03-12 20:23:08 [WARN] 	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3869)
2021-03-12 20:23:08 [WARN] 	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2524)
2021-03-12 20:23:08 [WARN] 	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2675)
2021-03-12 20:23:08 [WARN] 	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2465)
2021-03-12 20:23:08 [WARN] 	at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1915)
2021-03-12 20:23:08 [WARN] 	at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2136)
2021-03-12 20:23:08 [WARN] 	at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2070)
2021-03-12 20:23:08 [WARN] 	at com.mysql.jdbc.PreparedStatement.executeLargeUpdate(PreparedStatement.java:5187)
2021-03-12 20:23:08 [WARN] 	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2055)
2021-03-12 20:23:08 [WARN] 	at com.botsko.prism.libs.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61)
2021-03-12 20:23:08 [WARN] 	at com.botsko.prism.libs.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java)
2021-03-12 20:23:08 [WARN] 	at me.botsko.prism.database.sql.SqlInsertBuilder.insertActionIntoDatabase(SqlInsertBuilder.java:88)
2021-03-12 20:23:08 [WARN] 	at me.botsko.prism.actionlibs.RecordingTask.insertActionsIntoDatabase(RecordingTask.java:118)
2021-03-12 20:23:08 [WARN] 	at me.botsko.prism.actionlibs.RecordingTask.save(RecordingTask.java:46)
2021-03-12 20:23:08 [WARN] 	at me.botsko.prism.actionlibs.RecordingTask.run(RecordingTask.java:153)
2021-03-12 20:23:08 [WARN] 	at org.bukkit.craftbukkit.v1_16_R3.scheduler.CraftTask.run(CraftTask.java:81)
2021-03-12 20:23:08 [WARN] 	at org.bukkit.craftbukkit.v1_16_R3.scheduler.CraftAsyncTask.run(CraftAsyncTask.java:54)
2021-03-12 20:23:08 [WARN] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
2021-03-12 20:23:08 [WARN] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
2021-03-12 20:23:08 [WARN] 	at java.lang.Thread.run(Thread.java:748)
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Loaded player beehive, id: 23 into the cache.
2021-03-12 20:23:08 [INFO] [Prism] - Debug - Batch insert was commit: 1615598588549
2021-03-12 20:23:09 [INFO] [Prism] - Debug - Beginning batch insert from queue. 1615598589276
2021-03-12 20:23:09 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:09 [INFO] [Prism] - Debug - Batch insert was commit: 1615598589298
2021-03-12 20:23:14 [INFO] [Prism] - Debug - Beginning batch insert from queue. 1615598594676
2021-03-12 20:23:14 [INFO] [Prism] - Debug - Loaded player Mr_Microwave_Man, id: 2538 into the cache.
2021-03-12 20:23:14 [INFO] [Prism] - Debug - Batch insert was commit: 1615598594696
commented

OK, to document the Stack Overflow posts about this error - https://stackoverflow.com/questions/10957238/incorrect-string-value-when-trying-to-insert-utf-8-into-mysql-via-jdbc
I think we have a handle on what caused this. You can leave the issue open if you want, or close it if you don't feel it's necessary to fix.

commented

Looks like it has something to do with breaking a shulker box. It may be with a particular shulker box and maybe using a certain pickaxe. Maybe even a certain player. I'm still working on trying to get a debug log.

I'm not seeing any debug info for the break. But the break is being recorded.

P.S. The only table with a column named data is prism_data_extra, and that column is defined as text, so how could the string be incorrect? Is there a length limitation?