PowerFlex-MDM-Cluster nach Switchover heruntergestuft

Szenario
Während geplanter (Beispiel: NDU) oder nicht geplant (Beispiel: Netzwerkprobleme) MDM-Switchover durchgeführt wird, kann der neue primäre MDM keine Verbindung zu einem oder beiden sekundären MDMs herstellen. Das MDM-Ereignisprotokoll meldet, dass der Cluster im heruntergestuften Modus ausgeführt wird.

Das Problem bleibt bestehen, bis die "rsync"-Generations-ID höher ist als die gespeicherte Generations-ID der sekundären MDMs oder wenn die MDM-Prozess-ID geändert wird – siehe Ursache für weitere Details. 

Symptome
MDM 'A' wurde Master:

30/07 07:19:12.578262 0x7f1b222dcdb8:mosEventLog_PostInternal:00608: New event added. Message: "This MDM is switching to Master mode. MDM will start running.". Additional info: "" Severity: Warning
30/07 07:19:12.377519 0x7f1b223fcdb8:mosEventLog_PostInternal:00608: New event added. Message: "This MDM, na39tp8siob01 (ID 6b7c89e2367c8f02), took control of the cluster and is now the Master MDM.". Additional info: "" Severity: Warning

MDM "A" sendet "Start sync" an "B" mit Resync-ID (5075, 1) – Generation 1, die abgelehnt wird:

30/07 07:19:12.377948 0x7f1b2240edb8:syncer_SendStartSync:00423: Syncer_1: syncSize: 954880. Local: PID 5075, Gen 1. Msg: PID 5075, Gen 1
30/07 07:19:12.378367 0x7f1b2240edb8:syncer_SendStartSync:00464: Syncer_1: Start sync return with RC: INVALID, send-error: 0, syncSize: 954880, PID 5075, Gen 1, send-time 0 ms

"start-sync" auf MDM "B" wird abgelehnt:

30/07 07:19:12.378029 0x7f65163abdb8:syncerSlaveRcvGrp_RecvRequestCB:01782: start-sync BEGIN 
30/07 07:19:12.378033 0x7f65163abdb8:syncerSlave_HandleStartSync:01165: SyncerSlave received start-sync
...
30/07 07:19:12.378252 0x7f65163abdb8:syncerSlave_HandleStartSync:01231: SyncerSlave rejected start-sync.Invalid resync ID. Current slave resync ID (5075,4557). Got (5075,1).
30/07 07:19:12.378254 0x7f65163abdb8:syncerSlaveRcvGrp_RecvRequestCB:01821: start-sync END RC = INVALID

Es werden mehrere Versuche zum Starten der Synchronisierung durchgeführt, 1 Wiederholung pro Sekunde:

30/07 07:19:15.284522 0x7f1b2240edb8:syncer_SendStartSync:00423: Syncer_1: syncSize: 954880. Local: PID 5075, Gen 12. Msg: PID 5075, Gen 12
30/07 07:19:15.284979 0x7f1b2240edb8:syncer_SendStartSync:00464: Syncer_1: Start sync return with RC: INVALID, send-error: 0, syncSize: 954880, PID 5075, Gen 12, send-time 0 ms
30/07 07:19:16.276536 0x7f1b2240edb8:syncer_SendStartSync:00423: Syncer_1: syncSize: 954880. Local: PID 5075, Gen 13. Msg: PID 5075, Gen 13
30/07 07:19:16.276929 0x7f1b2240edb8:syncer_SendStartSync:00464: Syncer_1: Start sync return with RC: INVALID, send-error: 0, syncSize: 954880, PID 5075, Gen 13, send-time 0 ms
30/07 07:19:17.279471 0x7f1b2240edb8:syncer_SendStartSync:00423: Syncer_1: syncSize: 954880. Local: PID 5075, Gen 14. Msg: PID 5075, Gen 14
30/07 07:19:17.280293 0x7f1b2240edb8:syncer_SendStartSync:00464: Syncer_1: Start sync return with RC: INVALID, send-error: 0, syncSize: 954880, PID 5075, Gen 14, send-time 0 ms

MDM 'A' empfängt den Fehler "Kommunikation nicht möglich":

30/07 07:19:20.282247 0x7f1b2240edb8:mosEventLog_PostInternal:00608: New event added. Message: "This MDM cannot communicate with MDM cluster node, na39tp8sioc01 (ID 714d95f32a26d201), invalid response (Internal error: INVALID).". Additional info: "" Severity: Error

Die obigen Fehler werden weiterhin angezeigt, bis eine "gültige" Generierungs-ID erreicht ist (aus Sicht von MDM 'B'), und sobald dies geschieht, wird "start-sync" akzeptiert:

30/07 08:35:07.727104 0x7f65163abdb8:syncerSlave_HandleStartSync:01231: SyncerSlave rejected start-sync.Invalid resync ID. Current slave resync ID (5075,4557). Got (5075,4557).
30/07 08:35:08.732717 0x7f65163abdb8:syncerSlave_HandleStartSync:01165: SyncerSlave received start-sync
30/07 08:35:08.732917 0x7f65163abdb8:syncerSlave_HandleStartSync:01265: Accepted start-sync. resync-id: (5075, 4558) remote-version: 3.0.202

MDM "B" wird neu synchronisiert (aus Sicht von MDM "B"):

30/07 08:35:07.727123 0x7f1b2240edb8:syncer_SendStartSync:00464: Syncer_1: Start sync return with RC: INVALID, send-error: 0, syncSize: 954880, PID 5075, Gen 4557, send-time 0 ms
30/07 08:35:08.732530 0x7f1b2240edb8:syncer_SendStartSync:00423: Syncer_1: syncSize: 954880. Local: PID 5075, Gen 4558. Msg: PID 5075, Gen 4558
...
30/07 08:35:08.746942 0x7f1b2240edb8:syncer_Resync:00722: Syncer_1: Write remote SUCCESS - startLB: 911360, sizeLB: 2048, index 445, last: 1
30/07 08:35:08.746948 0x7f1b2240edb8:syncerDegrador_SetDegradationStateUnlocked:01571: Syncer_1: Degrador asked to work - curState: NOT_WORKING requestedState: MOVE_OUT_OF_DEGRADED (Blocking)
30/07 08:35:08.746959 0x7f1b223bddb8:syncerDegrador_Umt:01396: Syncer_1: Degrador asked to move to state MOVE_OUT_OF_DEGRADED
30/07 08:35:08.746963 0x7f1b223bddb8:syncerDegrador_Umt:01412: Syncer_1: CLEAR_DEGRADED for 4df81aa716c3e301

Das Cluster kehrt in den NORMAL-Modus zurück:

30/07 08:35:08.747350 0x7f1b223fcdb8:mosEventLog_PostInternal:00608: New event added. Message: "MDM cluster node na39tp8sioc01 (ID 714d95f32a26d201); IPs: [10.31.211.139,10.31.195.139], Port: 9011 is now in NORMAL state.". Additional info: "" Severity: Info
30/07 08:35:08.747383 0x7f1b223fcdb8:mosEventLog_PostInternal:00608: New event added. Message: "MDM cluster is now in NORMAL mode.". Additional info: "" Severity: Info

Auswirkungen 

Der MDM-Cluster wird möglicherweise in einem Single Point of Failure ausgeführt, bis das Problem behoben ist.

Dies ist eine seltene Bedingung, bei der 2 MDMs (alter primärer MDM und neuer primärer MDM) dieselbe PID erhalten, sodass der primäre und der sekundäre MDM-Prozess keine Verbindung herstellen können.

Wenn ein MDM zum primären MDM wird, wird versucht, die Nachricht "rsync" an die sekundären MDMs im Cluster zu senden, um die Verbindung zwischen ihnen herzustellen. Jede Neusynchronisierung vom primären MDM zu den sekundären MDMs im System hat eine Resync-ID, die aus <der Master-PID>< und der Generationsnummer> besteht.

Der sekundäre MDM, der die neue Startsynchronisierungsanforderung und ihre Resync-ID prüft - wenn er eine ältere "Generation" als die gespeicherte "Generation" als Teil der alten Resync-ID hat und zusätzlich dieselbe Prozess-ID hat - lehnt er die Startsynchronisierungsanforderung ab, da diese ID als nicht relevant (alt) erscheinen würde.

Hinweis: Das Problem wird möglicherweise ohne Intervention behoben, da der primäre MDM versucht, alle 1 Sekunde eine "Start-Synchronisierung" durchzuführen.

Beispiel:

Basierend auf den obigen Protokollen:

Der neue primäre (MDM "A") hatte genau die gleiche PID wie der vorherige primäre (MDM "C") – in unserem Beispiel ist die PID – 5075. Die Generationsnummer, die MDM "C" verwendet hat, lautet: 4557 - was bedeutet, dass MDM 'C' als Master mit MDM 'B' über Resync-ID verbunden war -> (5075,4557).

Nachdem MDM "A" zum primären MDM wurde, wurde versucht, eine "Resynchronisation" mit MDM "B" durchzuführen, auf dem die Generation 4557 für die PID 5075 gespeichert wurde, wie oben angegeben. Sobald der neue primäre Datenträger (MDM "A") versucht, sich mit "MDM B" neu zu synchronisieren, hat er die Generation "1" von derselben PID empfangen, die älter ist als die Generation "4557". Daher wird der Versuch abgelehnt.

Die erneute Synchronisierung wird alle 1 Sekunde erneut versucht und es dauert 4558 Versuche (~1 h 16 m), bis eine gültige Resynchronisations-ID angegeben wurde (5075,4558). Dann kehrt der Cluster zu NORMAL zurück.

Melden Sie sich beim sekundären MDM an und führen Sie einen pkill für den MDM-Prozess aus.

Beispiel:

[root@112AX-8 ~]# ps -ef | grep -i [m]dm
root      25844      1  0 Jul22 ?        04:37:01 /opt/emc/scaleio/mdm/bin/mdm-3.5.0.306 --log_dir /opt/emc/scaleio/mdm/bin/../logs --conf_file /opt/emc/scaleio/mdm/bin/../cfg/conf.txt
[root@112AX-8 ~]# pkill mdm
[root@112AX-8 ~]# ps -ef | grep -i [m]dm
root      90189      1  9 15:21 ?        00:00:00 /opt/emc/scaleio/mdm/bin/mdm-3.5.0.306 --log_dir /opt/emc/scaleio/mdm/bin/../logs --conf_file /opt/emc/scaleio/mdm/bin/../cfg/conf.txt