diff --git a/src/go/pt-galera-log-explainer/regex/regex.go b/src/go/pt-galera-log-explainer/regex/regex.go index 1b112853..99962d23 100644 --- a/src/go/pt-galera-log-explainer/regex/regex.go +++ b/src/go/pt-galera-log-explainer/regex/regex.go @@ -61,7 +61,7 @@ var ( regexSeqno = "(?P<" + groupSeqno + ">[0-9]+)" regexNodeIP = "(?P<" + groupNodeIP + ">[0-9]{1,3}\\.[0-9]{1,3}\\.[0-9]{1,3}\\.[0-9]{1,3})" regexNodeIPMethod = "(?P<" + groupMethod + ">.+)://" + regexNodeIP + ":[0-9]{1,6}" - regexIdx = "(?P<" + groupIdx + ">-?[0-9]{1,2})" + regexIdx = "(?P<" + groupIdx + ">-?[0-9]{1,2})(\\.-?[0-9])?" regexVersion = "(?P<" + groupVersion + ">(5|8|10|11)\\.[0-9]\\.[0-9]{1,2})" regexErrorMD5 = "(?P<" + groupErrorMD5 + ">[a-z0-9]*)" ) diff --git a/src/go/pt-galera-log-explainer/regex/regex_test.go b/src/go/pt-galera-log-explainer/regex/regex_test.go index c9a675fa..7cc1f033 100644 --- a/src/go/pt-galera-log-explainer/regex/regex_test.go +++ b/src/go/pt-galera-log-explainer/regex/regex_test.go @@ -4,6 +4,7 @@ import ( "io/ioutil" "os/exec" "testing" + "time" "github.com/davecgh/go-spew/spew" "github.com/google/go-cmp/cmp" @@ -740,8 +741,8 @@ func TestRegexes(t *testing.T) { { log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: Member 2.0 (node2) requested state transfer from '*any*'. Selected 0.0 (node1)(SYNCED) as donor.", - inputCtx: types.LogCtx{}, - expectedCtx: types.LogCtx{}, + inputCtx: types.LogCtx{SSTs: map[string]types.SST{}}, + expectedCtx: types.LogCtx{SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", SelectionTimestamp: timeMustParse("2001-01-01T01:01:01.000000Z")}}}, expectedOut: "node1 will resync node2", mapToTest: SSTMap, key: "RegexSSTRequestSuccess", @@ -749,8 +750,8 @@ func TestRegexes(t *testing.T) { { name: "with fqdn", log: "2001-01-01T01:01:01.000000Z 0 [Note] [MY-000000] [Galera] Member 2.0 (node2.host.com) requested state transfer from '*any*'. Selected 0.0 (node1.host.com)(SYNCED) as donor.", - inputCtx: types.LogCtx{}, - expectedCtx: types.LogCtx{}, + inputCtx: types.LogCtx{SSTs: map[string]types.SST{}}, + expectedCtx: types.LogCtx{SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", SelectionTimestamp: timeMustParse("2001-01-01T01:01:01.000000Z")}}}, expectedOut: "node1 will resync node2", mapToTest: SSTMap, key: "RegexSSTRequestSuccess", @@ -760,10 +761,11 @@ func TestRegexes(t *testing.T) { log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: Member 2.0 (node2) requested state transfer from '*any*'. Selected 0.0 (node1)(SYNCED) as donor.", inputCtx: types.LogCtx{ OwnNames: []string{"node2"}, + SSTs: map[string]types.SST{}, }, expectedCtx: types.LogCtx{ OwnNames: []string{"node2"}, - SST: types.SST{ResyncedFromNode: "node1"}, + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", SelectionTimestamp: timeMustParse("2001-01-01T01:01:01.000000Z")}}, }, expectedOut: "node1 will resync local node", mapToTest: SSTMap, @@ -774,10 +776,11 @@ func TestRegexes(t *testing.T) { log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: Member 2.0 (node2) requested state transfer from '*any*'. Selected 0.0 (node1)(SYNCED) as donor.", inputCtx: types.LogCtx{ OwnNames: []string{"node1"}, + SSTs: map[string]types.SST{}, }, expectedCtx: types.LogCtx{ OwnNames: []string{"node1"}, - SST: types.SST{ResyncingNode: "node2"}, + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", SelectionTimestamp: timeMustParse("2001-01-01T01:01:01.000000Z")}}, }, expectedOut: "local node will resync node2", mapToTest: SSTMap, @@ -807,9 +810,13 @@ func TestRegexes(t *testing.T) { }, { - log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: 0.0 (node1): State transfer to 2.0 (node2) complete.", - inputCtx: types.LogCtx{}, - expectedCtx: types.LogCtx{}, + log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: 0.0 (node1): State transfer to 2.0 (node2) complete.", + inputCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, + }, + expectedCtx: types.LogCtx{ + SSTs: map[string]types.SST{}, + }, expectedOut: "node1 synced node2", mapToTest: SSTMap, key: "RegexSSTComplete", @@ -819,10 +826,10 @@ func TestRegexes(t *testing.T) { log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: 0.0 (node1): State transfer to 2.0 (node2) complete.", inputCtx: types.LogCtx{ OwnNames: []string{"node2"}, - SST: types.SST{ResyncedFromNode: "node1"}, + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, }, expectedCtx: types.LogCtx{ - SST: types.SST{ResyncedFromNode: ""}, + SSTs: map[string]types.SST{}, OwnNames: []string{"node2"}, }, expectedOut: "got SST from node1", @@ -834,10 +841,10 @@ func TestRegexes(t *testing.T) { log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: 0.0 (node1): State transfer to 2.0 (node2) complete.", inputCtx: types.LogCtx{ OwnNames: []string{"node2"}, - SST: types.SST{ResyncedFromNode: "node1", Type: "IST"}, + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", Type: "IST"}}, }, expectedCtx: types.LogCtx{ - SST: types.SST{ResyncedFromNode: "", Type: ""}, + SSTs: map[string]types.SST{}, OwnNames: []string{"node2"}, }, expectedOut: "got IST from node1", @@ -849,10 +856,10 @@ func TestRegexes(t *testing.T) { log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: 0.0 (node1): State transfer to 2.0 (node2) complete.", inputCtx: types.LogCtx{ OwnNames: []string{"node1"}, - SST: types.SST{ResyncingNode: "node2"}, + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, }, expectedCtx: types.LogCtx{ - SST: types.SST{ResyncingNode: ""}, + SSTs: map[string]types.SST{}, OwnNames: []string{"node1"}, }, expectedOut: "finished sending SST to node2", @@ -864,48 +871,16 @@ func TestRegexes(t *testing.T) { log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: 0.0 (node1): State transfer to 2.0 (node2) complete.", inputCtx: types.LogCtx{ OwnNames: []string{"node1"}, - SST: types.SST{ResyncingNode: "node2", Type: "IST"}, + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", Type: "IST"}}, }, expectedCtx: types.LogCtx{ - SST: types.SST{ResyncingNode: "", Type: ""}, + SSTs: map[string]types.SST{}, OwnNames: []string{"node1"}, }, expectedOut: "finished sending IST to node2", mapToTest: SSTMap, key: "RegexSSTComplete", }, - { - name: "with donor name", - log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: 0.0 (node1): State transfer to 2.0 (node2) complete.", - inputCtx: types.LogCtx{ - SST: types.SST{ResyncingNode: "node2", Type: "IST"}, - }, - expectedCtx: types.LogCtx{ - SST: types.SST{ResyncingNode: "", Type: ""}, - OwnNames: []string{"node1"}, - }, - inputState: "DONOR", - expectedState: "DONOR", - expectedOut: "finished sending IST to node2", - mapToTest: SSTMap, - key: "RegexSSTComplete", - }, - { - name: "with joiner name", - log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: 0.0 (node1): State transfer to 2.0 (node2) complete.", - inputCtx: types.LogCtx{ - SST: types.SST{ResyncingNode: "node2", Type: "IST"}, - }, - expectedCtx: types.LogCtx{ - SST: types.SST{ResyncingNode: "", Type: ""}, - OwnNames: []string{"node2"}, - }, - inputState: "JOINER", - expectedState: "JOINER", - expectedOut: "got IST from node1", - mapToTest: SSTMap, - key: "RegexSSTComplete", - }, { log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: 0.0 (node1): State transfer to -1.-1 (left the group) complete.", @@ -931,8 +906,15 @@ func TestRegexes(t *testing.T) { }, { - log: "2001-01-01T01:01:01.000000Z WSREP_SST: [INFO] Proceeding with SST.........", - expectedCtx: types.LogCtx{SST: types.SST{Type: "SST"}}, + log: "2001-01-01T01:01:01.000000Z WSREP_SST: [INFO] Proceeding with SST.........", + inputCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, + OwnNames: []string{"node2"}, + }, + expectedCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", Type: "SST"}}, + OwnNames: []string{"node2"}, + }, expectedState: "JOINER", expectedOut: "receiving SST", mapToTest: SSTMap, @@ -941,7 +923,6 @@ func TestRegexes(t *testing.T) { { log: "2001-01-01T01:01:01.000000Z WSREP_SST: [INFO] Streaming the backup to joiner at 172.17.0.2 4444", - expectedCtx: types.LogCtx{SST: types.SST{ResyncingNode: "172.17.0.2"}}, expectedState: "DONOR", expectedOut: "SST to 172.17.0.2", mapToTest: SSTMap, @@ -957,8 +938,15 @@ func TestRegexes(t *testing.T) { }, { - log: "2001-01-01 1:01:01 140433613571840 [Note] WSREP: async IST sender starting to serve tcp://172.17.0.2:4568 sending 2-116", - expectedCtx: types.LogCtx{SST: types.SST{Type: "IST"}}, + log: "2001-01-01 1:01:01 140433613571840 [Note] WSREP: async IST sender starting to serve tcp://172.17.0.2:4568 sending 2-116", + inputCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, + OwnNames: []string{"node1"}, + }, + expectedCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", Type: "IST"}}, + OwnNames: []string{"node1"}, + }, expectedState: "DONOR", expectedOut: "IST to 172.17.0.2(seqno:116)", mapToTest: SSTMap, @@ -966,25 +954,46 @@ func TestRegexes(t *testing.T) { }, { - log: "2001-01-01T01:01:01.000000Z 0 [Note] [MY-000000] [Galera] Prepared IST receiver for 114-116, listening at: ssl://172.17.0.2:4568", - expectedCtx: types.LogCtx{SST: types.SST{Type: "IST"}}, + log: "2001-01-01T01:01:01.000000Z 0 [Note] [MY-000000] [Galera] Prepared IST receiver for 114-116, listening at: ssl://172.17.0.2:4568", + inputCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, + OwnNames: []string{"node2"}, + }, + expectedCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", Type: "IST"}}, + OwnNames: []string{"node2"}, + }, expectedState: "JOINER", expectedOut: "will receive IST(seqno:116)", mapToTest: SSTMap, key: "RegexISTReceiver", }, { - log: "2001-01-01T01:01:01.000000Z 0 [Note] [MY-000000] [Galera] Prepared IST receiver for 0-116, listening at: ssl://172.17.0.2:4568", - expectedCtx: types.LogCtx{SST: types.SST{Type: "SST"}}, + log: "2001-01-01T01:01:01.000000Z 0 [Note] [MY-000000] [Galera] Prepared IST receiver for 0-116, listening at: ssl://172.17.0.2:4568", + inputCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, + OwnNames: []string{"node2"}, + }, + expectedCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", Type: "SST"}}, + OwnNames: []string{"node2"}, + }, expectedState: "JOINER", expectedOut: "will receive SST", mapToTest: SSTMap, key: "RegexISTReceiver", }, { - name: "mdb variant", - log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: Prepared IST receiver, listening at: ssl://172.17.0.2:4568", - expectedCtx: types.LogCtx{SST: types.SST{Type: "IST"}}, + name: "mdb variant", + log: "2001-01-01T01:01:01.000000Z 0 [Note] WSREP: Prepared IST receiver, listening at: ssl://172.17.0.2:4568", + inputCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, + OwnNames: []string{"node2"}, + }, + expectedCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", Type: "IST"}}, + OwnNames: []string{"node2"}, + }, expectedState: "JOINER", expectedOut: "will receive IST", mapToTest: SSTMap, @@ -1012,26 +1021,70 @@ func TestRegexes(t *testing.T) { }, { - log: "2001-01-01T01:01:01.000000Z 1 [Note] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (ed16c932-84b3-11ed-998c-8e3ae5bc328f): 1 (Operation not permitted)", - expectedCtx: types.LogCtx{SST: types.SST{Type: "SST"}}, - expectedOut: "IST is not applicable", - mapToTest: SSTMap, - key: "RegexFailedToPrepareIST", + log: "2001-01-01T01:01:01.000000Z 1 [Note] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (ed16c932-84b3-11ed-998c-8e3ae5bc328f): 1 (Operation not permitted)", + inputState: "JOINER", + inputCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, + OwnNames: []string{"node2"}, + }, + expectedCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", Type: "SST"}}, + OwnNames: []string{"node2"}, + }, + expectedState: "JOINER", + expectedOut: "IST is not applicable", + mapToTest: SSTMap, + key: "RegexFailedToPrepareIST", }, { - log: "2001-01-01T01:01:01.000000Z 1 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state seqno is undefined: 1 (Operation not permitted)", - expectedCtx: types.LogCtx{SST: types.SST{Type: "SST"}}, - expectedOut: "IST is not applicable", - mapToTest: SSTMap, - key: "RegexFailedToPrepareIST", + log: "2001-01-01T01:01:01.000000Z 1 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state seqno is undefined: 1 (Operation not permitted)", + inputState: "JOINER", + inputCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, + OwnNames: []string{"node2"}, + }, + expectedCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", Type: "SST"}}, + OwnNames: []string{"node2"}, + }, + expectedState: "JOINER", + expectedOut: "IST is not applicable", + mapToTest: SSTMap, + key: "RegexFailedToPrepareIST", }, { - log: "2001-01-01T01:01:01.000000Z WSREP_SST: [INFO] Bypassing SST. Can work it through IST", - expectedCtx: types.LogCtx{SST: types.SST{Type: "IST"}}, - expectedOut: "IST will be used", - mapToTest: SSTMap, - key: "RegexBypassSST", + log: "2001-01-01T01:01:01.000000Z WSREP_SST: [INFO] Bypassing SST. Can work it through IST", + inputState: "JOINER", + inputCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, + OwnNames: []string{"node2"}, + }, + expectedCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", Type: "IST"}}, + OwnNames: []string{"node2"}, + }, + expectedState: "JOINER", + expectedOut: "IST will be used", + mapToTest: SSTMap, + key: "RegexBypassSST", + }, + + { + log: "2001-01-01T01:01:01.000000Z 0 [Note] [MY-000000] [WSREP-SST] xtrabackup_ist received from donor: Running IST", + inputState: "JOINER", + inputCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2"}}, + OwnNames: []string{"node2"}, + }, + expectedCtx: types.LogCtx{ + SSTs: map[string]types.SST{"node1": types.SST{Donor: "node1", Joiner: "node2", Type: "IST"}}, + OwnNames: []string{"node2"}, + }, + expectedState: "JOINER", + expectedOut: "IST running", + mapToTest: SSTMap, + key: "RegexXtrabackupISTReceived", }, { @@ -1256,6 +1309,11 @@ func TestRegexes(t *testing.T) { } } +func timeMustParse(s string) *time.Time { + t, _, _ := SearchDateFromLog(s) + return &t +} + func testRegexFromMap(t *testing.T, log string, regex *types.LogRegex) error { m := types.RegexMap{"test": regex} diff --git a/src/go/pt-galera-log-explainer/regex/sst.go b/src/go/pt-galera-log-explainer/regex/sst.go index 1884d457..37c786df 100644 --- a/src/go/pt-galera-log-explainer/regex/sst.go +++ b/src/go/pt-galera-log-explainer/regex/sst.go @@ -15,18 +15,26 @@ var SSTMap = types.RegexMap{ // TODO: requested state from unknown node "RegexSSTRequestSuccess": &types.LogRegex{ Regex: regexp.MustCompile("requested state transfer.*Selected"), - InternalRegex: regexp.MustCompile("Member .* \\(" + regexNodeName + "\\) requested state transfer.*Selected .* \\(" + regexNodeName2 + "\\)\\("), + InternalRegex: regexp.MustCompile("Member " + regexIdx + " \\(" + regexNodeName + "\\) requested state transfer.*Selected " + regexIdx + " \\(" + regexNodeName2 + "\\)\\("), Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { joiner := utils.ShortNodeName(submatches[groupNodeName]) donor := utils.ShortNodeName(submatches[groupNodeName2]) - if utils.SliceContains(ctx.OwnNames, joiner) { - ctx.SST.ResyncedFromNode = donor + + sst := types.SST{ + Donor: donor, + Joiner: joiner, } - if utils.SliceContains(ctx.OwnNames, donor) { - ctx.SST.ResyncingNode = joiner + + // here this is a limitation of the handler signature + // this is the only case when resorting to timestamps is necessary + selectionTimestamp, _, ok := SearchDateFromLog(log) + if ok { + sst.SelectionTimestamp = &selectionTimestamp } + ctx.SSTs[donor] = sst + return ctx, func(ctx types.LogCtx) string { if utils.SliceContains(ctx.OwnNames, joiner) { return donor + utils.Paint(utils.GreenText, " will resync local node") @@ -58,18 +66,16 @@ var SSTMap = types.RegexMap{ // 2022-12-24T03:28:22.444125Z 0 [Note] WSREP: 0.0 (name): State transfer to 2.0 (name2) complete. "RegexSSTComplete": &types.LogRegex{ Regex: regexp.MustCompile("State transfer to.*complete"), - InternalRegex: regexp.MustCompile("\\(" + regexNodeName + "\\): State transfer.*\\(" + regexNodeName2 + "\\) complete"), + InternalRegex: regexp.MustCompile(regexIdx + " \\(" + regexNodeName + "\\): State transfer to " + regexIdx + " \\(" + regexNodeName2 + "\\) complete"), Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { donor := utils.ShortNodeName(submatches[groupNodeName]) joiner := utils.ShortNodeName(submatches[groupNodeName2]) displayType := "SST" - if ctx.SST.Type != "" { - displayType = ctx.SST.Type + if ctx.SSTs[donor].Type != "" { + displayType = ctx.SSTs[donor].Type } - ctx.SST.Reset() - - ctx = addOwnNameWithSSTMetadata(ctx, joiner, donor) + delete(ctx.SSTs, donor) return ctx, func(ctx types.LogCtx) string { if utils.SliceContains(ctx.OwnNames, joiner) { @@ -88,34 +94,34 @@ var SSTMap = types.RegexMap{ // 2022-12-24T03:27:41.966118Z 0 [Note] WSREP: 0.0 (name): State transfer to -1.-1 (left the group) complete. "RegexSSTCompleteUnknown": &types.LogRegex{ Regex: regexp.MustCompile("State transfer to.*left the group.*complete"), - InternalRegex: regexp.MustCompile("\\(" + regexNodeName + "\\): State transfer.*\\(left the group\\) complete"), + InternalRegex: regexp.MustCompile(regexIdx + " \\(" + regexNodeName + "\\): State transfer.*\\(left the group\\) complete"), Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { donor := utils.ShortNodeName(submatches[groupNodeName]) - ctx = addOwnNameWithSSTMetadata(ctx, "", donor) + delete(ctx.SSTs, donor) return ctx, types.SimpleDisplayer(donor + utils.Paint(utils.RedText, " synced ??(node left)")) }, }, "RegexSSTFailedUnknown": &types.LogRegex{ Regex: regexp.MustCompile("State transfer to.*left the group.*failed"), - InternalRegex: regexp.MustCompile("\\(" + regexNodeName + "\\): State transfer.*\\(left the group\\) failed"), + InternalRegex: regexp.MustCompile(regexIdx + " \\(" + regexNodeName + "\\): State transfer.*\\(left the group\\) failed"), Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { donor := utils.ShortNodeName(submatches[groupNodeName]) - ctx = addOwnNameWithSSTMetadata(ctx, "", donor) + delete(ctx.SSTs, donor) return ctx, types.SimpleDisplayer(donor + utils.Paint(utils.RedText, " failed to sync ??(node left)")) }, }, "RegexSSTStateTransferFailed": &types.LogRegex{ Regex: regexp.MustCompile("State transfer to.*failed:"), - InternalRegex: regexp.MustCompile("\\(" + regexNodeName + "\\): State transfer.*\\(" + regexNodeName2 + "\\) failed"), + InternalRegex: regexp.MustCompile(regexIdx + " \\(" + regexNodeName + "\\): State transfer to " + regexIdx + " \\(" + regexNodeName2 + "\\) failed"), Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { donor := utils.ShortNodeName(submatches[groupNodeName]) joiner := utils.ShortNodeName(submatches[groupNodeName2]) - ctx = addOwnNameWithSSTMetadata(ctx, joiner, donor) + delete(ctx.SSTs, donor) return ctx, types.SimpleDisplayer(donor + utils.Paint(utils.RedText, " failed to sync ") + joiner) }, }, @@ -128,6 +134,15 @@ var SSTMap = types.RegexMap{ }, }, + "RegexSSTInitiating": &types.LogRegex{ + Regex: regexp.MustCompile("Initiating SST.IST transfer on DONOR side"), + InternalRegex: regexp.MustCompile("DONOR side \\((?P[a-zA-Z0-9-_]*) --role 'donor' --address '" + regexNodeIP + ":(?P[0-9]*)\\)"), + Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { + + return ctx, types.SimpleDisplayer("init sst using " + submatches["scriptname"]) + }, + }, + "RegexSSTCancellation": &types.LogRegex{ Regex: regexp.MustCompile("Initiating SST cancellation"), Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { @@ -140,7 +155,7 @@ var SSTMap = types.RegexMap{ Regex: regexp.MustCompile("Proceeding with SST"), Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { ctx.SetState("JOINER") - ctx.SST.Type = "SST" + ctx.SetSSTTypeMaybe("SST") return ctx, types.SimpleDisplayer(utils.Paint(utils.YellowText, "receiving SST")) }, @@ -152,13 +167,10 @@ var SSTMap = types.RegexMap{ Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { ctx.SetState("DONOR") - node := submatches[groupNodeIP] - if ctx.SST.ResyncingNode == "" { // we should already have something at this point - ctx.SST.ResyncingNode = node - } + joiner := submatches[groupNodeIP] return ctx, func(ctx types.LogCtx) string { - return utils.Paint(utils.YellowText, "SST to ") + types.DisplayNodeSimplestForm(ctx, node) + return utils.Paint(utils.YellowText, "SST to ") + types.DisplayNodeSimplestForm(ctx, joiner) } }, }, @@ -181,8 +193,8 @@ var SSTMap = types.RegexMap{ // TODO: sometimes, it's a hostname here InternalRegex: regexp.MustCompile("IST sender starting to serve " + regexNodeIPMethod + " sending [0-9]+-" + regexSeqno), Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { - ctx.SST.Type = "IST" ctx.SetState("DONOR") + ctx.SetSSTTypeMaybe("IST") seqno := submatches[groupSeqno] node := submatches[groupNodeIP] @@ -206,13 +218,13 @@ var SSTMap = types.RegexMap{ startingseqno := submatches["startingseqno"] // if it's 0, it will go to SST without a doubt if startingseqno == "0" { - ctx.SST.Type = "SST" + ctx.SetSSTTypeMaybe("SST") msg += "SST" // not totally correct, but need more logs to get proper pattern // in some cases it does IST before going with SST } else { - ctx.SST.Type = "IST" + ctx.SetSSTTypeMaybe("IST") msg += "IST" if seqno != "" { msg += "(seqno:" + seqno + ")" @@ -225,16 +237,25 @@ var SSTMap = types.RegexMap{ "RegexFailedToPrepareIST": &types.LogRegex{ Regex: regexp.MustCompile("Failed to prepare for incremental state transfer"), Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { - ctx.SST.Type = "SST" + ctx.SetSSTTypeMaybe("SST") return ctx, types.SimpleDisplayer("IST is not applicable") }, }, + "RegexXtrabackupISTReceived": &types.LogRegex{ + Regex: regexp.MustCompile("xtrabackup_ist received from donor"), + Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { + ctx.SetSSTTypeMaybe("IST") + return ctx, types.SimpleDisplayer("IST running") + }, + Verbosity: types.DebugMySQL, // that one is not really helpful, except for tooling constraints + }, + // could not find production examples yet, but it did exist in older version there also was "Bypassing state dump" "RegexBypassSST": &types.LogRegex{ Regex: regexp.MustCompile("Bypassing SST"), Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { - ctx.SST.Type = "IST" + ctx.SetSSTTypeMaybe("IST") return ctx, types.SimpleDisplayer("IST will be used") }, }, @@ -283,24 +304,7 @@ var SSTMap = types.RegexMap{ }, } -func addOwnNameWithSSTMetadata(ctx types.LogCtx, joiner, donor string) types.LogCtx { - - var nameToAdd string - - if ctx.State() == "JOINER" && joiner != "" { - nameToAdd = joiner - } - if ctx.State() == "DONOR" && donor != "" { - nameToAdd = donor - } - if nameToAdd != "" { - ctx.AddOwnName(nameToAdd) - } - return ctx -} - /* - 2023-06-07T02:42:29.734960-06:00 0 [ERROR] WSREP: sst sent called when not SST donor, state SYNCED 2023-06-07T02:42:00.234711-06:00 0 [Warning] WSREP: Protocol violation. JOIN message sender 0.0 (node1) is not in state transfer (SYNCED). Message ignored. diff --git a/src/go/pt-galera-log-explainer/regex/states.go b/src/go/pt-galera-log-explainer/regex/states.go index 1f1075a9..aa76c509 100644 --- a/src/go/pt-galera-log-explainer/regex/states.go +++ b/src/go/pt-galera-log-explainer/regex/states.go @@ -14,7 +14,16 @@ func init() { var ( shiftFunc = func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) { - ctx.SetState(submatches["state2"]) + newState := submatches["state2"] + ctx.SetState(newState) + + if newState == "DONOR" || newState == "JOINER" { + shiftTimestamp, _, ok := SearchDateFromLog(log) + if ok { + ctx.ConfirmSSTMetadata(shiftTimestamp) + } + } + log = utils.PaintForState(submatches["state1"], submatches["state1"]) + " -> " + utils.PaintForState(submatches["state2"], submatches["state2"]) return ctx, types.SimpleDisplayer(log) diff --git a/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all b/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all index e3719f0b..74678c61 100644 --- a/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all +++ b/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all @@ -1,7 +1,7 @@ -identifier 172.17.0.2 node2 node3 +identifier node1 node2 node3 current path tests/logs/upgrade/node1.log tests/logs/upgrade/node2.log tests/logs/upgrade/node3.log last known ip 172.17.0.2 172.17.0.3 172.17.0.4 -last known name node2 node3 +last known name node1 node2 node3 mysql version 8.0.28 8.0.28 8.0.28 2023-03-12T07:24:13.733958Z | starting(5.7.40) | @@ -225,7 +225,7 @@ mysql version 8.0.28 8.0.28 2023-03-12T19:35:07.638676Z will receive IST(seqno:178226774) |  |  2023-03-12T19:35:07.644560Z |  |  local node will resync node1 2023-03-12T19:35:07.644570Z |  |  SYNCED -> DONOR -2023-03-12T19:35:07.644668Z node3 will resync node1 |  |  +2023-03-12T19:35:07.644668Z node3 will resync local node |  |  2023-03-12T19:35:07.644683Z PRIMARY -> JOINER |  |  2023-03-12T19:35:07.644740Z |  node3 will resync node1 |  2023-03-12T19:36:48.567087Z timeout from donor in gtid/keyring stage |  |  @@ -259,16 +259,16 @@ mysql version 8.0.28 8.0.28 2023-03-12T19:43:18.130916Z OPEN -> PRIMARY |  |  2023-03-12T19:43:18.904410Z will receive IST(seqno:178226792) |  |  2023-03-12T19:43:18.913328Z |  |  node1 cannot find donor -2023-03-12T19:43:18.913429Z node1 cannot find donor |  |  +2023-03-12T19:43:18.913429Z cannot find donor |  |  2023-03-12T19:43:18.913565Z |  node1 cannot find donor |  2023-03-12T19:43:19.914122Z |  |  node1 cannot find donor -2023-03-12T19:43:19.914259Z node1 cannot find donor |  |  +2023-03-12T19:43:19.914259Z cannot find donor |  |  2023-03-12T19:43:19.914362Z |  node1 cannot find donor |  2023-03-12T19:43:20.914957Z |  |  (repeated x97)node1 cannot find donor -2023-03-12T19:43:20.915143Z (repeated x97)node1 cannot find donor |  |  +2023-03-12T19:43:20.915143Z (repeated x97)cannot find donor |  |  2023-03-12T19:43:20.915262Z |  (repeated x97)node1 cannot find donor |  2023-03-12T19:44:58.999603Z |  |  node1 cannot find donor -2023-03-12T19:44:58.999791Z node1 cannot find donor |  |  +2023-03-12T19:44:58.999791Z cannot find donor |  |  2023-03-12T19:44:58.999891Z |  node1 cannot find donor |  2023-03-12T19:44:59.817822Z timeout from donor in gtid/keyring stage |  |  2023-03-12T19:44:59.839692Z SST error |  |  @@ -318,8 +318,8 @@ mysql version 8.0.28 8.0.28 2023-03-12T22:00:28.094664Z |  |  node2 left 2023-03-12T22:00:28.094708Z |  |  PRIMARY(n=1) -identifier 172.17.0.2 node2 node3 +identifier node1 node2 node3 current path tests/logs/upgrade/node1.log tests/logs/upgrade/node2.log tests/logs/upgrade/node3.log last known ip 172.17.0.2 172.17.0.3 172.17.0.4 -last known name node2 node3 +last known name node1 node2 node3 mysql version 8.0.28 8.0.28 8.0.28 diff --git a/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all_no_color b/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all_no_color index f89354c1..8144a7ac 100644 --- a/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all_no_color +++ b/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all_no_color @@ -1,7 +1,7 @@ -identifier 172.17.0.2 node2 node3 +identifier node1 node2 node3 current path tests/logs/upgrade/node1.log tests/logs/upgrade/node2.log tests/logs/upgrade/node3.log last known ip 172.17.0.2 172.17.0.3 172.17.0.4 -last known name node2 node3 +last known name node1 node2 node3 mysql version 8.0.28 8.0.28 8.0.28 2023-03-12T07:24:13.733958Z | starting(5.7.40) | @@ -225,7 +225,7 @@ mysql version 8.0.28 8.0.28 2023-03-12T19:35:07.638676Z will receive IST(seqno:178226774) | | 2023-03-12T19:35:07.644560Z | | local node will resync node1 2023-03-12T19:35:07.644570Z | | SYNCED -> DONOR -2023-03-12T19:35:07.644668Z node3 will resync node1 | | +2023-03-12T19:35:07.644668Z node3 will resync local node | | 2023-03-12T19:35:07.644683Z PRIMARY -> JOINER | | 2023-03-12T19:35:07.644740Z | node3 will resync node1 | 2023-03-12T19:36:48.567087Z timeout from donor in gtid/keyring stage | | @@ -259,16 +259,16 @@ mysql version 8.0.28 8.0.28 2023-03-12T19:43:18.130916Z OPEN -> PRIMARY | | 2023-03-12T19:43:18.904410Z will receive IST(seqno:178226792) | | 2023-03-12T19:43:18.913328Z | | node1 cannot find donor -2023-03-12T19:43:18.913429Z node1 cannot find donor | | +2023-03-12T19:43:18.913429Z cannot find donor | | 2023-03-12T19:43:18.913565Z | node1 cannot find donor | 2023-03-12T19:43:19.914122Z | | node1 cannot find donor -2023-03-12T19:43:19.914259Z node1 cannot find donor | | +2023-03-12T19:43:19.914259Z cannot find donor | | 2023-03-12T19:43:19.914362Z | node1 cannot find donor | 2023-03-12T19:43:20.914957Z | | (repeated x97)node1 cannot find donor -2023-03-12T19:43:20.915143Z (repeated x97)node1 cannot find donor | | +2023-03-12T19:43:20.915143Z (repeated x97)cannot find donor | | 2023-03-12T19:43:20.915262Z | (repeated x97)node1 cannot find donor | 2023-03-12T19:44:58.999603Z | | node1 cannot find donor -2023-03-12T19:44:58.999791Z node1 cannot find donor | | +2023-03-12T19:44:58.999791Z cannot find donor | | 2023-03-12T19:44:58.999891Z | node1 cannot find donor | 2023-03-12T19:44:59.817822Z timeout from donor in gtid/keyring stage | | 2023-03-12T19:44:59.839692Z SST error | | @@ -318,8 +318,8 @@ mysql version 8.0.28 8.0.28 2023-03-12T22:00:28.094664Z | | node2 left 2023-03-12T22:00:28.094708Z | | PRIMARY(n=1) -identifier 172.17.0.2 node2 node3 +identifier node1 node2 node3 current path tests/logs/upgrade/node1.log tests/logs/upgrade/node2.log tests/logs/upgrade/node3.log last known ip 172.17.0.2 172.17.0.3 172.17.0.4 -last known name node2 node3 +last known name node1 node2 node3 mysql version 8.0.28 8.0.28 8.0.28 diff --git a/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all_since b/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all_since index 7e6edb26..f22ace3f 100644 --- a/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all_since +++ b/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_all_since @@ -1,7 +1,7 @@ -identifier 172.17.0.2 node2 node3 +identifier node1 node2 node3 current path tests/logs/upgrade/node1.log tests/logs/upgrade/node2.log tests/logs/upgrade/node3.log last known ip 172.17.0.2 172.17.0.3 -last known name node2 node3 +last known name node1 node2 node3 mysql version 8.0.28 8.0.28 2023-03-12T13:13:14.886853Z | got SST from node3 | @@ -28,7 +28,7 @@ mysql version 8.0.28 8.0.28 2023-03-12T19:35:07.638676Z will receive IST(seqno:178226774) |  |  2023-03-12T19:35:07.644560Z |  |  local node will resync node1 2023-03-12T19:35:07.644570Z |  |  SYNCED -> DONOR -2023-03-12T19:35:07.644668Z node3 will resync node1 |  |  +2023-03-12T19:35:07.644668Z node3 will resync local node |  |  2023-03-12T19:35:07.644683Z PRIMARY -> JOINER |  |  2023-03-12T19:35:07.644740Z |  node3 will resync node1 |  2023-03-12T19:36:48.567087Z timeout from donor in gtid/keyring stage |  |  @@ -62,16 +62,16 @@ mysql version 8.0.28 8.0.28 2023-03-12T19:43:18.130916Z OPEN -> PRIMARY |  |  2023-03-12T19:43:18.904410Z will receive IST(seqno:178226792) |  |  2023-03-12T19:43:18.913328Z |  |  node1 cannot find donor -2023-03-12T19:43:18.913429Z node1 cannot find donor |  |  +2023-03-12T19:43:18.913429Z cannot find donor |  |  2023-03-12T19:43:18.913565Z |  node1 cannot find donor |  2023-03-12T19:43:19.914122Z |  |  node1 cannot find donor -2023-03-12T19:43:19.914259Z node1 cannot find donor |  |  +2023-03-12T19:43:19.914259Z cannot find donor |  |  2023-03-12T19:43:19.914362Z |  node1 cannot find donor |  2023-03-12T19:43:20.914957Z |  |  (repeated x97)node1 cannot find donor -2023-03-12T19:43:20.915143Z (repeated x97)node1 cannot find donor |  |  +2023-03-12T19:43:20.915143Z (repeated x97)cannot find donor |  |  2023-03-12T19:43:20.915262Z |  (repeated x97)node1 cannot find donor |  2023-03-12T19:44:58.999603Z |  |  node1 cannot find donor -2023-03-12T19:44:58.999791Z node1 cannot find donor |  |  +2023-03-12T19:44:58.999791Z cannot find donor |  |  2023-03-12T19:44:58.999891Z |  node1 cannot find donor |  2023-03-12T19:44:59.817822Z timeout from donor in gtid/keyring stage |  |  2023-03-12T19:44:59.839692Z SST error |  |  @@ -121,8 +121,8 @@ mysql version 8.0.28 8.0.28 2023-03-12T22:00:28.094664Z |  |  node2 left 2023-03-12T22:00:28.094708Z |  |  PRIMARY(n=1) -identifier 172.17.0.2 node2 node3 +identifier node1 node2 node3 current path tests/logs/upgrade/node1.log tests/logs/upgrade/node2.log tests/logs/upgrade/node3.log last known ip 172.17.0.2 172.17.0.3 -last known name node2 node3 +last known name node1 node2 node3 mysql version 8.0.28 8.0.28 diff --git a/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_sst b/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_sst index 97da1dd5..7eefe07c 100644 --- a/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_sst +++ b/src/go/pt-galera-log-explainer/tests/expected/upgrade_list_sst @@ -1,7 +1,7 @@ -identifier 172.17.0.2 node2 node3 +identifier node1 node2 node3 current path tests/logs/upgrade/node1.log tests/logs/upgrade/node2.log tests/logs/upgrade/node3.log last known ip 172.17.0.2 172.17.0.3 172.17.0.4 -last known name node2 node3 +last known name node1 node2 node3 mysql version 8.0.28 8.0.28 8.0.28 5.7.40 @@ -42,23 +42,23 @@ mysql version 8.0.28 8.0.28 2023-03-12T13:13:19.156722Z | IST received(seqno:170407338) |  2023-03-12T19:35:07.638676Z will receive IST(seqno:178226774) |  |  2023-03-12T19:35:07.644560Z |  |  local node will resync node1 -2023-03-12T19:35:07.644668Z node3 will resync node1 |  |  +2023-03-12T19:35:07.644668Z node3 will resync local node |  |  2023-03-12T19:35:07.644740Z |  node3 will resync node1 |  2023-03-12T19:36:48.567087Z timeout from donor in gtid/keyring stage |  |  2023-03-12T19:36:48.589084Z SST error |  |  2023-03-12T19:36:48.590647Z former SST cancelled |  |  2023-03-12T19:43:18.904410Z will receive IST(seqno:178226792) |  |  2023-03-12T19:43:18.913328Z |  |  node1 cannot find donor -2023-03-12T19:43:18.913429Z node1 cannot find donor |  |  +2023-03-12T19:43:18.913429Z cannot find donor |  |  2023-03-12T19:43:18.913565Z |  node1 cannot find donor |  2023-03-12T19:43:19.914122Z |  |  node1 cannot find donor -2023-03-12T19:43:19.914259Z node1 cannot find donor |  |  +2023-03-12T19:43:19.914259Z cannot find donor |  |  2023-03-12T19:43:19.914362Z |  node1 cannot find donor |  2023-03-12T19:43:20.914957Z |  |  (repeated x97)node1 cannot find donor -2023-03-12T19:43:20.915143Z (repeated x97)node1 cannot find donor |  |  +2023-03-12T19:43:20.915143Z (repeated x97)cannot find donor |  |  2023-03-12T19:43:20.915262Z |  (repeated x97)node1 cannot find donor |  2023-03-12T19:44:58.999603Z |  |  node1 cannot find donor -2023-03-12T19:44:58.999791Z node1 cannot find donor |  |  +2023-03-12T19:44:58.999791Z cannot find donor |  |  2023-03-12T19:44:58.999891Z |  node1 cannot find donor |  2023-03-12T19:44:59.817822Z timeout from donor in gtid/keyring stage |  |  2023-03-12T19:44:59.839692Z SST error |  |  @@ -76,8 +76,8 @@ mysql version 8.0.28 8.0.28 2023-03-12T22:00:27.089809Z |  SST error |  2023-03-12T22:00:27.237486Z |  former SST cancelled |  -identifier 172.17.0.2 node2 node3 +identifier node1 node2 node3 current path tests/logs/upgrade/node1.log tests/logs/upgrade/node2.log tests/logs/upgrade/node3.log last known ip 172.17.0.2 172.17.0.3 172.17.0.4 -last known name node2 node3 +last known name node1 node2 node3 mysql version 8.0.28 8.0.28 8.0.28 diff --git a/src/go/pt-galera-log-explainer/types/ctx.go b/src/go/pt-galera-log-explainer/types/ctx.go index f42ea7fd..76d25aed 100644 --- a/src/go/pt-galera-log-explainer/types/ctx.go +++ b/src/go/pt-galera-log-explainer/types/ctx.go @@ -2,13 +2,16 @@ package types import ( "encoding/json" + "time" "github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/utils" ) -// LogCtx is a context for a given file. -// It is the principal storage of this tool -// Everything relevant will be stored here +// LogCtx is the main context storage for a node. +// It is the principal storage of this tool, this is the source of truth to merge logs and take decisions +// It is stored along wih each single log line we matched, and copied for each new log line. +// It is NOT meant to be used as a singleton by pointer, it must keep its original state for each log lines +// If not, every informaiton would be overwritten (states, sst, version, membercount, ...) and we would not be able to give the history of changes type LogCtx struct { FilePath string FileType string @@ -20,21 +23,38 @@ type LogCtx struct { statePostProcessingLog string stateBackupLog string Version string - SST SST - MyIdx string - MemberCount int - Desynced bool - HashToIP map[string]string - HashToNodeName map[string]string - IPToHostname map[string]string - IPToMethod map[string]string - IPToNodeName map[string]string - minVerbosity Verbosity - Conflicts Conflicts + + // SSTs where key is donor name, as it will always be known. + // is meant to be shared with a deep copy, there's no sense to share the pointer + // because it is meant to store a state at a specific time + SSTs map[string]SST + MyIdx string + MemberCount int + Desynced bool + minVerbosity Verbosity + Conflicts Conflicts + + // translation maps, the only elements that can be shared and copied by pointer + HashToIP map[string]string + HashToNodeName map[string]string + IPToHostname map[string]string + IPToMethod map[string]string + IPToNodeName map[string]string } func NewLogCtx() LogCtx { - return LogCtx{minVerbosity: Debug, HashToIP: map[string]string{}, IPToHostname: map[string]string{}, IPToMethod: map[string]string{}, IPToNodeName: map[string]string{}, HashToNodeName: map[string]string{}} + ctx := LogCtx{minVerbosity: Debug} + ctx.InitMaps() + return ctx +} + +func (ctx *LogCtx) InitMaps() { + ctx.SSTs = map[string]SST{} + ctx.HashToIP = map[string]string{} + ctx.IPToHostname = map[string]string{} + ctx.IPToMethod = map[string]string{} + ctx.IPToNodeName = map[string]string{} + ctx.HashToNodeName = map[string]string{} } // State will return the wsrep state of the current file type @@ -234,6 +254,34 @@ func (base *LogCtx) Inherit(ctx LogCtx) { base.MergeMapsWith([]LogCtx{ctx}) } +func (ctx *LogCtx) SetSSTTypeMaybe(ssttype string) { + for key, sst := range ctx.SSTs { + if len(ctx.SSTs) == 1 || (ctx.State() == "DONOR" && utils.SliceContains(ctx.OwnNames, key)) || (ctx.State() == "JOINER" && utils.SliceContains(ctx.OwnNames, sst.Joiner)) { + sst.Type = ssttype + ctx.SSTs[key] = sst + return + } + } +} + +func (ctx *LogCtx) ConfirmSSTMetadata(shiftTimestamp time.Time) { + if ctx.State() != "DONOR" && ctx.State() != "JOINER" { + return + } + for key, sst := range ctx.SSTs { + if sst.MustHaveHappenedLocally(shiftTimestamp) { + if ctx.State() == "DONOR" { + ctx.AddOwnName(key) + } + if ctx.State() == "JOINER" { + ctx.AddOwnName(sst.Joiner) + } + } + } + + return +} + func (l LogCtx) MarshalJSON() ([]byte, error) { return json.Marshal(struct { FilePath string @@ -246,7 +294,7 @@ func (l LogCtx) MarshalJSON() ([]byte, error) { StatePostProcessingLog string StateBackupLog string Version string - SST SST + SSTs map[string]SST MyIdx string MemberCount int Desynced bool @@ -267,7 +315,7 @@ func (l LogCtx) MarshalJSON() ([]byte, error) { StatePostProcessingLog: l.statePostProcessingLog, StateBackupLog: l.stateBackupLog, Version: l.Version, - SST: l.SST, + SSTs: l.SSTs, MyIdx: l.MyIdx, MemberCount: l.MemberCount, Desynced: l.Desynced, diff --git a/src/go/pt-galera-log-explainer/types/sst.go b/src/go/pt-galera-log-explainer/types/sst.go index 97986812..3ab249f6 100644 --- a/src/go/pt-galera-log-explainer/types/sst.go +++ b/src/go/pt-galera-log-explainer/types/sst.go @@ -1,15 +1,23 @@ package types +import "time" + type SST struct { - Method string - Type string - ResyncingNode string - ResyncedFromNode string + Method string + Type string + Joiner string + Donor string + SelectionTimestamp *time.Time } -func (s *SST) Reset() { - s.Method = "" - s.Type = "" - s.ResyncedFromNode = "" - s.ResyncingNode = "" +// MustHaveHappenedLocally use the "selected x as donor" timestamp +// and compare it to the timestamp of donor/joiner wsrep status shift +// Usually, when it is selected, joiner/donor take a few milliseconds to shift their status +// This is the most solid way so far to correctly map donor and joiners when concurrents SSTs +// are running +func (sst SST) MustHaveHappenedLocally(shiftTimestamp time.Time) bool { + if sst.SelectionTimestamp == nil { + return false + } + return shiftTimestamp.Sub(*sst.SelectionTimestamp).Seconds() <= 0.01 }