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: | Truphone DBA | Email Updates: | |
Status: | Closed | Impact on me: | |
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]
Truphone DBA
[29 Apr 2019 17:42]
Truphone DBA
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]
Truphone DBA
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.