Bug #95191 Cluster.status: get_uint(24): field value out of the allowed range (ArgumentErro
Submitted: 29 Apr 2019 17:29 Modified: 16 Dec 2019 15:56
Reporter: Pedro Pinheiro Email Updates:
Status: Closed Impact on me:
None 
Category:Shell AdminAPI InnoDB Cluster / ReplicaSet Severity:S3 (Non-critical)
Version:8.0.16 OS:Any
Assigned to: CPU Architecture:Any

[29 Apr 2019 17:29] Pedro Pinheiro
Description:
When performing the command using mysql Shell:
--------
cluster.status({queryMembers:true})
--------

When get the error:
Cluster.status: get_uint(24): field value out of the allowed range (ArgumentError)

How to repeat:
c=dba.getCluster
cluster.status({queryMembers:true})

Relevant information:
---------

SELECT *,TIMESTAMPDIFF(MICROSECOND, LAST_QUEUED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP, LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP) AS LAST_ORIGINAL_COMMIT_TO_END_QUEUE_TIME,TIMESTAMPDIFF(MICROSECOND, LAST_QUEUED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP, LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP) AS LAST_IMMEDIATE_COMMIT_TO_END_QUEUE_TIME,TIMESTAMPDIFF(MICROSECOND, LAST_QUEUED_TRANSACTION_START_QUEUE_TIMESTAMP, LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP) AS LAST_QUEUE_TIME,TIMESTAMPDIFF(MICROSECOND, QUEUEING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP, NOW(6)) AS CURRENT_ORIGINAL_COMMIT_TO_NOW_TIME,TIMESTAMPDIFF(MICROSECOND, QUEUEING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP, NOW(6)) AS CURRENT_IMMEDIATE_COMMIT_TO_NOW_TIME FROM performance_schema.replication_connection_status\G
*************************** 1. row ***************************
                                     CHANNEL_NAME: group_replication_applier
                                       GROUP_NAME: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe
                                      SOURCE_UUID: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe
                                        THREAD_ID: NULL
                                    SERVICE_STATE: ON
                        COUNT_RECEIVED_HEARTBEATS: 0
                         LAST_HEARTBEAT_TIMESTAMP: 0000-00-00 00:00:00
                         RECEIVED_TRANSACTION_SET: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe:1-23,
cb89323e-6a6d-11e9-a7e7-005056b4f3fe:1-13
                                LAST_ERROR_NUMBER: 0
                               LAST_ERROR_MESSAGE:
                             LAST_ERROR_TIMESTAMP: 0000-00-00 00:00:00
                          LAST_QUEUED_TRANSACTION: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe:13
LAST_QUEUED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
LAST_QUEUED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
    LAST_QUEUED_TRANSACTION_START_QUEUE_TIMESTAMP: 2019-04-29 12:01:18.521368
      LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP: 2019-04-29 12:01:18.521557
                             QUEUEING_TRANSACTION:
   QUEUEING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
  QUEUEING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
       QUEUEING_TRANSACTION_START_QUEUE_TIMESTAMP: 0000-00-00 00:00:00
           LAST_ORIGINAL_COMMIT_TO_END_QUEUE_TIME: NULL
          LAST_IMMEDIATE_COMMIT_TO_END_QUEUE_TIME: NULL
                                  LAST_QUEUE_TIME: 189
              CURRENT_ORIGINAL_COMMIT_TO_NOW_TIME: NULL
             CURRENT_IMMEDIATE_COMMIT_TO_NOW_TIME: NULL
1 row in set (0.0013 sec)
---------
[29 Apr 2019 17:42] Pedro Pinheiro
On node 2:
--------------
SELECT *,TIMESTAMPDIFF(MICROSECOND, LAST_QUEUED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP, LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP) AS LAST_ORIGINAL_COMMIT_TO_END_QUEUE_TIME,TIMESTAMPDIFF(MICROSECOND, LAST_QUEUED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP, LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP) AS LAST_IMMEDIATE_COMMIT_TO_END_QUEUE_TIME,TIMESTAMPDIFF(MICROSECOND, LAST_QUEUED_TRANSACTION_START_QUEUE_TIMESTAMP, LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP) AS LAST_QUEUE_TIME,TIMESTAMPDIFF(MICROSECOND, QUEUEING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP, NOW(6)) AS CURRENT_ORIGINAL_COMMIT_TO_NOW_TIME,TIMESTAMPDIFF(MICROSECOND, QUEUEING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP, NOW(6)) AS CURRENT_IMMEDIATE_COMMIT_TO_NOW_TIME FROM performance_schema.replication_connection_status\G
*************************** 1. row ***************************
                                      CHANNEL_NAME: group_replication_recovery
                                        GROUP_NAME:
                                       SOURCE_UUID:
                                         THREAD_ID: NULL
                                     SERVICE_STATE: OFF
                         COUNT_RECEIVED_HEARTBEATS: 0
                          LAST_HEARTBEAT_TIMESTAMP: 0000-00-00 00:00:00
                          RECEIVED_TRANSACTION_SET:
                                 LAST_ERROR_NUMBER: 0
                                LAST_ERROR_MESSAGE:
                              LAST_ERROR_TIMESTAMP: 0000-00-00 00:00:00
                           LAST_QUEUED_TRANSACTION:
 LAST_QUEUED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
LAST_QUEUED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
     LAST_QUEUED_TRANSACTION_START_QUEUE_TIMESTAMP: 0000-00-00 00:00:00
       LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP: 0000-00-00 00:00:00
                              QUEUEING_TRANSACTION:
    QUEUEING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
   QUEUEING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
        QUEUEING_TRANSACTION_START_QUEUE_TIMESTAMP: 0000-00-00 00:00:00
            LAST_ORIGINAL_COMMIT_TO_END_QUEUE_TIME: NULL
           LAST_IMMEDIATE_COMMIT_TO_END_QUEUE_TIME: NULL
                                   LAST_QUEUE_TIME: NULL
               CURRENT_ORIGINAL_COMMIT_TO_NOW_TIME: NULL
              CURRENT_IMMEDIATE_COMMIT_TO_NOW_TIME: NULL
*************************** 2. row ***************************
                                      CHANNEL_NAME: group_replication_applier
                                        GROUP_NAME: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe
                                       SOURCE_UUID: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe
                                         THREAD_ID: NULL
                                     SERVICE_STATE: ON
                         COUNT_RECEIVED_HEARTBEATS: 0
                          LAST_HEARTBEAT_TIMESTAMP: 0000-00-00 00:00:00
                          RECEIVED_TRANSACTION_SET: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe:1-23,
cb89323e-6a6d-11e9-a7e7-005056b4f3fe:1-13
                                 LAST_ERROR_NUMBER: 0
                                LAST_ERROR_MESSAGE:
                              LAST_ERROR_TIMESTAMP: 0000-00-00 00:00:00
                           LAST_QUEUED_TRANSACTION: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe:23
 LAST_QUEUED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 2019-04-29 15:48:30.79316
LAST_QUEUED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
     LAST_QUEUED_TRANSACTION_START_QUEUE_TIMESTAMP: 2019-04-29 15:48:30.961492
       LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP: 2019-04-29 15:48:30.961518
                              QUEUEING_TRANSACTION:
    QUEUEING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
   QUEUEING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
        QUEUEING_TRANSACTION_START_QUEUE_TIMESTAMP: 0000-00-00 00:00:00
            LAST_ORIGINAL_COMMIT_TO_END_QUEUE_TIME: 168358
           LAST_IMMEDIATE_COMMIT_TO_END_QUEUE_TIME: NULL
                                   LAST_QUEUE_TIME: 26
               CURRENT_ORIGINAL_COMMIT_TO_NOW_TIME: NULL
              CURRENT_IMMEDIATE_COMMIT_TO_NOW_TIME: NULL
2 rows in set (0.0021 sec)
--------------
[29 Apr 2019 17:42] Pedro Pinheiro
on Node 3: (negative vales can be found)
------------------
SELECT *,TIMESTAMPDIFF(MICROSECOND, LAST_QUEUED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP, LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP) AS LAST_ORIGINAL_COMMIT_TO_END_QUEUE_TIME,TIMESTAMPDIFF(MICROSECOND, LAST_QUEUED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP, LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP) AS LAST_IMMEDIATE_COMMIT_TO_END_QUEUE_TIME,TIMESTAMPDIFF(MICROSECOND, LAST_QUEUED_TRANSACTION_START_QUEUE_TIMESTAMP, LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP) AS LAST_QUEUE_TIME,TIMESTAMPDIFF(MICROSECOND, QUEUEING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP, NOW(6)) AS CURRENT_ORIGINAL_COMMIT_TO_NOW_TIME,TIMESTAMPDIFF(MICROSECOND, QUEUEING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP, NOW(6)) AS CURRENT_IMMEDIATE_COMMIT_TO_NOW_TIME FROM performance_schema.replication_connection_status\G
*************************** 1. row ***************************
                                      CHANNEL_NAME: group_replication_recovery
                                        GROUP_NAME:
                                       SOURCE_UUID:
                                         THREAD_ID: NULL
                                     SERVICE_STATE: OFF
                         COUNT_RECEIVED_HEARTBEATS: 0
                          LAST_HEARTBEAT_TIMESTAMP: 0000-00-00 00:00:00
                          RECEIVED_TRANSACTION_SET:
                                 LAST_ERROR_NUMBER: 0
                                LAST_ERROR_MESSAGE:
                              LAST_ERROR_TIMESTAMP: 0000-00-00 00:00:00
                           LAST_QUEUED_TRANSACTION:
 LAST_QUEUED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
LAST_QUEUED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
     LAST_QUEUED_TRANSACTION_START_QUEUE_TIMESTAMP: 0000-00-00 00:00:00
       LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP: 0000-00-00 00:00:00
                              QUEUEING_TRANSACTION:
    QUEUEING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
   QUEUEING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
        QUEUEING_TRANSACTION_START_QUEUE_TIMESTAMP: 0000-00-00 00:00:00
            LAST_ORIGINAL_COMMIT_TO_END_QUEUE_TIME: NULL
           LAST_IMMEDIATE_COMMIT_TO_END_QUEUE_TIME: NULL
                                   LAST_QUEUE_TIME: NULL
               CURRENT_ORIGINAL_COMMIT_TO_NOW_TIME: NULL
              CURRENT_IMMEDIATE_COMMIT_TO_NOW_TIME: NULL
*************************** 2. row ***************************
                                      CHANNEL_NAME: group_replication_applier
                                        GROUP_NAME: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe
                                       SOURCE_UUID: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe
                                         THREAD_ID: NULL
                                     SERVICE_STATE: ON
                         COUNT_RECEIVED_HEARTBEATS: 0
                          LAST_HEARTBEAT_TIMESTAMP: 0000-00-00 00:00:00
                          RECEIVED_TRANSACTION_SET: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe:1-23,
cb89323e-6a6d-11e9-a7e7-005056b4f3fe:1-13
                                 LAST_ERROR_NUMBER: 0
                                LAST_ERROR_MESSAGE:
                              LAST_ERROR_TIMESTAMP: 0000-00-00 00:00:00
                           LAST_QUEUED_TRANSACTION: 12860b9d-6a6e-11e9-a9ee-005056b4f3fe:23
 LAST_QUEUED_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 2019-04-29 15:48:30.79316
LAST_QUEUED_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
     LAST_QUEUED_TRANSACTION_START_QUEUE_TIMESTAMP: 2019-04-29 15:48:30.111988
       LAST_QUEUED_TRANSACTION_END_QUEUE_TIMESTAMP: 2019-04-29 15:48:30.112054
                              QUEUEING_TRANSACTION:
    QUEUEING_TRANSACTION_ORIGINAL_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
   QUEUEING_TRANSACTION_IMMEDIATE_COMMIT_TIMESTAMP: 0000-00-00 00:00:00
        QUEUEING_TRANSACTION_START_QUEUE_TIMESTAMP: 0000-00-00 00:00:00
            LAST_ORIGINAL_COMMIT_TO_END_QUEUE_TIME: -681106
           LAST_IMMEDIATE_COMMIT_TO_END_QUEUE_TIME: NULL
                                   LAST_QUEUE_TIME: 66
               CURRENT_ORIGINAL_COMMIT_TO_NOW_TIME: NULL
              CURRENT_IMMEDIATE_COMMIT_TO_NOW_TIME: NULL
2 rows in set (0.0128 sec)

------------------
[29 Apr 2019 18:05] Alfredo Kojima
Thank you for the bug report.

This issue is caused by hosts having skewed clocks. status() should ignore negative time values that result from these so that output is still produced for other information, although time related fields would end up with invalid values.
[24 Jun 2019 13:21] Stefano Rocca
I have a similar error (qet_uint(20) instead of get_uint(24)) and on my servers the clocks are synched (to the second).
Please note that calling c.status({extended:true}) works.
[16 Dec 2019 15:56] David Moss
Posted by developer:
 
Thank you for your feedback, this has been fixed in upcoming versions and the following was added to the 8.0.19 / 8.0.19 changelog:

The Cluster.status() operation could report an error get_uint(24): field value out of the allowed range because it was always expecting a positive value for some fields that could in fact have negative values. For example, this could happen when the clocks of different instances were offset.