MySQL Bugs: #23662: NDB Error message truncated "ERROR 1297 (HY000): Got temporary error 410 'REDO"

Bug #23662	NDB Error message truncated "ERROR 1297 (HY000): Got temporary error 410 'REDO"
Submitted:	26 Oct 2006 10:05	Modified:	4 Nov 2009 14:38
Reporter:	Roland Bouman	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Cluster: Cluster (NDB) storage engine	Severity:	S3 (Non-critical)
Version:	mysql-5.1	OS:	Linux (Ubuntu dapper drake)
Assigned to:	Martin Zaun	CPU Architecture:	Any
Tags:	5.1.13 bk, error, ERROR 1297, ndb, REDO log files overloaded, temporary error 410, truncated

Description:
The NDB engine can give a temorary error when the load is too high to fit in the REDO log files, a condition that can be solved by either upping the TimeBetweenLocalCheckpoints, increasing the NoOfFragmentLogFiles or spreading the load more evenly through time. 

When the error logs overflow, and error is generated. However, the error message is truncated. 

ERROR 1297 (HY000): Got temporary error 410 'REDO log files overloaded, consult online manual (decrease TimeBetweenLocalCheckpoints, and|or incre' from NDB

The piece between the single quotes is truncated. It should probably read 'REDO log files overloaded, consult online manual (decrease TimeBetweenLocalCheckpoints, and|or increase the NoOfFragmentLogFiles)'

The manual reference is curently found here: http://dev.mysql.com/doc/refman/5.1/en/mysql-cluster-ndbd-definition.html#mysql-cluster-lo...

How to repeat:
If you really want to invoke this problem, follow the recipe. However, it does not seem to be necessary to have to do this. I think looking at the source code might be a lot quicker. 

Configure a cluster, set TimeBetweenLocalCheckpoints to the maximum (I think 31), set NoOfFragementLogFiles to the minimum (3 - careful, pre 5.1.12 accept lower values but that leads to serious other problems). Make sure you set DataMemory not too low (say > 250Mb), and the MaxNoOfConcurrentOperations fairly high, Start the cluster. 

Create a table: 

create table test (
    data varbinary(7168)
) engine = ndb;

insert into test(data) values (repeat('a',7168));

then, repeat the following statement until you hit the error:

insert into test (data) select data from test;

  

Suggested fix:
Please don't trunctate the error message. Alternatively shorthen the message so it is a complete sentence again.

also reported on the public cluster mailing list

Hi,

I have seen the message below before and now we have a customer reporting issues because of it, but as you can see the message is truncated.

Got temporary error 410 'REDO log files overloaded, consult online manual (decrease TimeBetweenLocalCheckpoints, and|or incre' 

Suggested new message

Got temporary error 410 'REDO log overloaded, decrease Local Checkpoint times and|or increase REDO log space'

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/28122

ChangeSet@1.2518, 2007-06-05 16:01:35+02:00, jmiller@mysql.com +1 -0
  ndberror.c:
    Proposed patch to message truncation issue for Bug#23662

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/85424

3052 Martin Zaun	2009-10-01
      ndb - bug#23662 - fixed truncated error message 410 'REDO log files overloaded...'

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/85430

3065 Martin Zaun	2009-10-01
      ndb - bug#23662 - fixed truncated error message 410 'REDO log files overloaded...'

Pushed into 5.1.39-ndb-7.0.9 (revid:martin.zaun@sun.com-20091001191741-20gpuhevktlej4a2) (version source revid:martin.zaun@sun.com-20091001191741-20gpuhevktlej4a2) (merge vers: 5.1.39-ndb-7.0.9) (pib:11)

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/85431

3065 Martin Zaun	2009-10-01 [merge]
      ndb - bug#23662 - fixed truncated error message 410 'REDO log files overloaded...'

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/85448

3012 Martin Zaun	2009-10-01
      ndb - bug#23662 - fixed truncated error message 410 'REDO log files overloaded...'

I verified the patch with the CRUND benchmark, which triggered the bug when
trying to inserted 1MB blobs via JDBC/mysqld.  The fixed error message below.

run:
     [java] java version "1.5.0_20"
     [java] Java(TM) 2 Runtime Environment, Standard Edition (build 1.5.0_20-b02-315)
     [java] Java HotSpot(TM) Server VM (build 1.5.0_20-141, mixed mode)

set.paths.mysql.run:

run.mysql:
     [echo] using:
     [echo]   classpath.mysql.run: /Users/mz/mysql/crund/build:/Users/mz/mysql/crund/lib/mysql-connector-java-5.1.7-bin.jar
     [echo] 
     [java] JdbcLoad.main()
     [java] 
     [java] reading properties file:    crundRun.properties
     [java] reading properties file:    crundMysql.properties
     [java] 
     [java] main settings:
     [java] logRealTime:                true
     [java] logMemUsage:                false
     [java] includeFullGC:              false
     [java] logSumOfOps:                true
     [java] renewOperations:            false
     [java] renewConnection:            false
     [java] allowExtendedPC:            false
     [java] aStart:                     1024
     [java] aEnd:                       1024
     [java] aIncr:                      4
     [java] bStart:                     1024
     [java] bEnd:                       1024
     [java] bIncr:                      4
     [java] maxVarbinaryBytes:          10
     [java] maxVarcharChars:            10
     [java] maxBlobBytes:               1000000
     [java] maxTextChars:               1000000
     [java] warmupRuns:                 0
     [java] hotRuns:                    1
     [java] exclude:                    []
     [java] jdbc.driver:                com.mysql.jdbc.Driver
     [java] jdbc.url:                   jdbc:mysql://localhost/crunddb
     [java] 
     [java] writing results to file:    log_20091001_091031.txt
     [java] 
     [java] ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
     [java] start logging results ...
     [java] ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
     [java] 
     [java] closing files ...           [ok]
     [java] 
     [java] writing results to file:    log_20091001_091031.txt
     [java] initializing connection ... [Conn: 1]
     [java] initializing statements ... [JdbcOp: 22]
     [java] 
     [java] ------------------------------------------------------------
     [java] countA = 1024, countB = 1024
     [java] 
     [java] deleting all rows ...       [B0: 0, A: 0]
     [java] 
     [java] insA
     [java] tx real time      = 375	ms [begin..commit]
     [java] 
     [java] insB0
     [java] tx real time      = 411	ms [begin..commit]
     [java] 
     [java] setAByPK
     [java] tx real time      = 598	ms [begin..commit]
     [java] 
     [java] setB0ByPK
     [java] tx real time      = 608	ms [begin..commit]
     [java] 
     [java] setBlob1000
     [java] tx real time      = 1109	ms [begin..commit]
     [java] 
     [java] getBlob1000
     [java] tx real time      = 689	ms [begin..commit]
     [java] 
     [java] setBlob10000
     [java] tx real time      = 2122	ms [begin..commit]
     [java] 
     [java] getBlob10000
     [java] tx real time      = 821	ms [begin..commit]
     [java] 
     [java] setBlob100000
     [java] tx real time      = 19715	ms [begin..commit]
     [java] 
     [java] getBlob100000
     [java] tx real time      = 2479	ms [begin..commit]
     [java] 
     [java] setBlob1000000
     [java] caught java.sql.SQLException: Got temporary error 410 'REDO log files overloaded (decrease TimeBetweenLocalCheckpoints or increase NoOfFragmentLogFiles)' from NDB
     [java] java.sql.SQLException: Got temporary error 410 'REDO log files overloaded (decrease TimeBetweenLocalCheckpoints or increase NoOfFragmentLogFiles)' from NDB
     [java] 	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1055)
     [java] 	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
     [java] 	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3515)
     [java] 	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3447)
     [java] 	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1951)
     [java] 	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2101)
     [java] 	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2554)
     [java] 	at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1761)
     [java] 	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2046)
     [java] 	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1964)
     [java] 	at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1949)
     [java] 	at com.mysql.cluster.crund.JdbcLoad$5.run(JdbcLoad.java:361)
     [java] 	at com.mysql.cluster.crund.Driver.runOp(Driver.java:569)
     [java] 	at com.mysql.cluster.crund.Driver.runOperations(Driver.java:532)
     [java] 	at com.mysql.cluster.crund.Driver.runTests(Driver.java:475)
     [java] 	at com.mysql.cluster.crund.Driver.run(Driver.java:282)
     [java] 	at com.mysql.cluster.crund.JdbcLoad.main(JdbcLoad.java:685)

BUILD FAILED
/Users/mz/mysql/crund/build.xml:683: Java returned: 2

Pushed into 5.1.39-ndb-7.1.0 (revid:martin.zaun@sun.com-20091002135800-89zrb1zo75g8kwb5) (version source revid:martin.zaun@sun.com-20091002135800-89zrb1zo75g8kwb5) (merge vers: 5.1.39-ndb-7.1.0) (pib:11)

this has been pushed to 6.2.19, 6.3.27a, 7.0.8a

Documented bugfix in the NDB-6.2.19, 6.3.27a, and 7.0.8a changelogs, as follows:

        The error message text for NDB error code 410 ('REDO log 
        files overloaded...') was truncated.

Closed.