Bug #9340 STARTED log event arrives very late
Submitted: 22 Mar 2005 16:00 Modified: 23 May 2005 5:04
Reporter: Johan Andersson Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Cluster: Cluster (NDB) storage engine Severity:S2 (Serious)
Version:5.* OS:Any (*)
Assigned to: Assigned Account CPU Architecture:Any

[22 Mar 2005 16:00] Johan Andersson 
Description:
STARTED log event comes very late to the mgmapi for a recovering ndbd node.

How to repeat:
2005-03-22 15:37:02 [MgmSrvr] ALERT    -- Node 6: Node 5 Disconnected
2005-03-22 15:37:02 [MgmSrvr] INFO     -- Node 3: Communication to Node 5 closed
2005-03-22 15:37:02 [MgmSrvr] ALERT    -- Node 1: Node 5 Disconnected
2005-03-22 15:37:02 [MgmSrvr] ALERT    -- Node 3: Arbitration check won - node group majority
2005-03-22 15:37:02 [MgmSrvr] INFO     -- Node 3: President restarts arbitration thread [state=6]
2005-03-22 15:37:02 [MgmSrvr] INFO     -- Node 4: Communication to Node 5 closed
2005-03-22 15:37:02 [MgmSrvr] INFO     -- Node 6: Communication to Node 5 closed
 
vm10:/usr/dhafw/out/mysql(2)# 2005-03-22 15:37:02 [MgmSrvr] ALERT    -- Node 3: Node 5 Disconnected
2005-03-22 15:37:02 [MgmSrvr] ALERT    -- Node 4: Node 5 Disconnected
2005-03-22 15:37:02 [MgmSrvr] INFO     -- Mgmt server state: nodeid 5 freed, m_reserved_nodes 00000000000001da.
ndb_waiter -c "STATION_A:2200"2005-03-22 15:37:03 [MgmSrvr] INFO     -- Mgmt server state: nodeid 5 reserved for ip 172.16.16.4, m_reserved_nodes 00000000000001fa.
 
Connecting to mgmsrv at STATION_A:2200
State node 3 STARTED
State node 4 STARTED
State node 5 UNKNOWN
State node 6 STARTED
Waiting for cluster enter state STARTED
2005-03-22 15:37:04 [MgmSrvr] INFO     -- Node 1: Node 5 Connected
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
2005-03-22 15:37:05 [MgmSrvr] INFO     -- Node 6: Communication to Node 5 opened
2005-03-22 15:37:05 [MgmSrvr] INFO     -- Node 6: Node 5 Connected
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 4: Communication to Node 5 opened
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 5: Node 4 Connected
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 5: Node 6 Connected
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 4: Node 5 Connected
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 3: Communication to Node 5 opened
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 3: Node 5 Connected
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 5: Node 3 Connected
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 5: CM_REGCONF president = 3, own Node = 5, our dynamic
id = 7
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 3: Node 5: API version 5.0.3
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 4: Node 5: API version 5.0.3
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 6: Node 5: API version 5.0.3
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 5: Node 3: API version 5.0.3
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 5: Node 4: API version 5.0.3
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 5: Node 6: API version 5.0.3
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 5: Start phase 1 completed
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 5: Start phase 2 completed (node restart)
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 5: Start phase 3 completed (node restart)
2005-03-22 15:37:06 [MgmSrvr] INFO     -- Node 5: Start phase 4 completed (node restart)
2005-03-22 15:37:07 [MgmSrvr] INFO     -- Node 5: Receive arbitrator node 2 [ticket=03660001ca955ba2]
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
2005-03-22 15:37:07 [MgmSrvr] INFO     -- Node 3: Local checkpoint 140 started. Keep GCI = 181975 oldest restorable GCI = 181975
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Start phase 5 completed (node restart)
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Start phase 6 completed (node restart)
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Start phase 7 completed (node restart)
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Communication to Node 7 opened
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Communication to Node 8 opened
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Communication to Node 9 opened
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Communication to Node 10 opened
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Communication to Node 11 opened
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Communication to Node 12 opened
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Communication to Node 13 opened
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Communication to Node 0 opened
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Start phase 8 completed (node restart)
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Start phase 9 completed (node restart)
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Started (version 5.0.3)
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Node 7 Connected
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Node 8 Connected
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Node 8: API version 5.0.3
2005-03-22 15:37:10 [MgmSrvr] INFO     -- Node 5: Node 7: API version 5.0.3
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTING
State node 6 STARTED
Waiting for cluster enter state STARTED
State node 3 STARTED
State node 4 STARTED
State node 5 STARTED
State node 6 STARTED
Waiting for cluster enter state STARTED
2005-03-22 15:37:34 [MgmSrvr] INFO     -- Node 5: Node 2: API version 5.0.3
2005-03-22 15:37:34 [MgmSrvr] INFO     -- Node 5: Node 1: API version 5.0.3
 
NDBT_ProgramExit: 0 - OK
[24 Mar 2005 4:22] Jorge del Conde 
Verified w/ 5.0.3 bk
[23 Apr 2005 5:04] Stewart Smith 
Please post configuration used and any data set that may help.

Could not duplicate on 5.1 build that was handy. Am rebuilding latest 5.0 and will test there too.
[23 May 2005 23:00] Bugs System 
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".