Add pt-galera-log-explainer

This commit is contained in:
Yoann La Cancellera
2023-08-30 19:32:50 +02:00
parent 62d7c70c43
commit b4cad31e77
39 changed files with 5517 additions and 1 deletions

View File

@@ -0,0 +1,192 @@
package regex
import (
"regexp"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/types"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/utils"
)
func init() {
setType(types.ApplicativeRegexType, ApplicativeMap)
}
var ApplicativeMap = types.RegexMap{
"RegexDesync": &types.LogRegex{
Regex: regexp.MustCompile("desyncs itself from group"),
InternalRegex: regexp.MustCompile("\\(" + regexNodeName + "\\) desyncs"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.Desynced = true
node := submatches[groupNodeName]
return ctx, func(ctx types.LogCtx) string {
if utils.SliceContains(ctx.OwnNames, node) {
return utils.Paint(utils.YellowText, "desyncs itself from group")
}
return node + utils.Paint(utils.YellowText, " desyncs itself from group")
}
},
},
"RegexResync": &types.LogRegex{
Regex: regexp.MustCompile("resyncs itself to group"),
InternalRegex: regexp.MustCompile("\\(" + regexNodeName + "\\) resyncs"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.Desynced = false
node := submatches[groupNodeName]
return ctx, func(ctx types.LogCtx) string {
if utils.SliceContains(ctx.OwnNames, node) {
return utils.Paint(utils.YellowText, "resyncs itself to group")
}
return node + utils.Paint(utils.YellowText, " resyncs itself to group")
}
},
},
"RegexInconsistencyVoteInit": &types.LogRegex{
Regex: regexp.MustCompile("initiates vote on"),
InternalRegex: regexp.MustCompile("Member " + regexIdx + "\\(" + regexNodeName + "\\) initiates vote on " + regexUUID + ":" + regexSeqno + "," + regexErrorMD5 + ": (?P<error>.*), Error_code:"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
node := submatches[groupNodeName]
seqno := submatches[groupSeqno]
errormd5 := submatches[groupErrorMD5]
errorstring := submatches["error"]
c := types.Conflict{
InitiatedBy: []string{node},
Seqno: seqno,
VotePerNode: map[string]types.ConflictVote{node: types.ConflictVote{MD5: errormd5, Error: errorstring}},
}
ctx.Conflicts = ctx.Conflicts.Merge(c)
return ctx, func(ctx types.LogCtx) string {
if utils.SliceContains(ctx.OwnNames, node) {
return utils.Paint(utils.YellowText, "inconsistency vote started") + "(seqno:" + seqno + ")"
}
return utils.Paint(utils.YellowText, "inconsistency vote started by "+node) + "(seqno:" + seqno + ")"
}
},
},
"RegexInconsistencyVoteRespond": &types.LogRegex{
Regex: regexp.MustCompile("responds to vote on "),
InternalRegex: regexp.MustCompile("Member " + regexIdx + "\\(" + regexNodeName + "\\) responds to vote on " + regexUUID + ":" + regexSeqno + "," + regexErrorMD5 + ": (?P<error>.*)"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
node := submatches[groupNodeName]
seqno := submatches[groupSeqno]
errormd5 := submatches[groupErrorMD5]
errorstring := submatches["error"]
latestConflict := ctx.Conflicts.ConflictWithSeqno(seqno)
if latestConflict == nil {
return ctx, nil
}
latestConflict.VotePerNode[node] = types.ConflictVote{MD5: errormd5, Error: errorstring}
return ctx, func(ctx types.LogCtx) string {
for _, name := range ctx.OwnNames {
vote, ok := latestConflict.VotePerNode[name]
if !ok {
continue
}
return voteResponse(vote, *latestConflict)
}
return ""
}
},
},
"RegexInconsistencyVoted": &types.LogRegex{
Regex: regexp.MustCompile("Inconsistency detected: Inconsistent by consensus"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "found inconsistent by vote"))
},
},
"RegexInconsistencyWinner": &types.LogRegex{
Regex: regexp.MustCompile("Winner: "),
InternalRegex: regexp.MustCompile("Winner: " + regexErrorMD5),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
errormd5 := submatches[groupErrorMD5]
if len(ctx.Conflicts) == 0 {
return ctx, nil // nothing to guess
}
c := ctx.Conflicts.ConflictFromMD5(errormd5)
if c == nil {
// some votes have been observed to be logged again
// sometimes days after the initial one
// the winner outcomes is not even always the initial one
// as they don't add any helpful context, we should ignore
// plus, it would need multiline regexes, which is not supported here
return ctx, nil
}
c.Winner = errormd5
return ctx, func(ctx types.LogCtx) string {
out := "consistency vote(seqno:" + c.Seqno + "): "
for _, name := range ctx.OwnNames {
vote, ok := c.VotePerNode[name]
if !ok {
continue
}
if vote.MD5 == c.Winner {
return out + utils.Paint(utils.GreenText, "won")
}
return out + utils.Paint(utils.RedText, "lost")
}
return ""
}
},
},
"RegexInconsistencyRecovery": &types.LogRegex{
Regex: regexp.MustCompile("Recovering vote result from history"),
InternalRegex: regexp.MustCompile("Recovering vote result from history: " + regexUUID + ":" + regexSeqno + "," + regexErrorMD5),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
if len(ctx.OwnNames) == 0 {
return ctx, nil
}
errormd5 := submatches[groupErrorMD5]
seqno := submatches[groupSeqno]
c := ctx.Conflicts.ConflictWithSeqno(seqno)
vote := types.ConflictVote{MD5: errormd5}
c.VotePerNode[ctx.OwnNames[len(ctx.OwnNames)-1]] = vote
return ctx, types.SimpleDisplayer(voteResponse(vote, *c))
},
Verbosity: types.DebugMySQL,
},
}
func voteResponse(vote types.ConflictVote, conflict types.Conflict) string {
out := "consistency vote(seqno:" + conflict.Seqno + "): voted "
initError := conflict.VotePerNode[conflict.InitiatedBy[0]]
switch vote.MD5 {
case "0000000000000000":
out += "Success"
case initError.MD5:
out += "same error"
default:
out += "different error"
}
return out
}

View File

@@ -0,0 +1,117 @@
package regex
import (
"fmt"
"strconv"
"time"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/utils"
"github.com/rs/zerolog/log"
)
// 5.5 date : 151027 6:02:49
// 5.6 date : 2019-07-17 07:16:37
//5.7 date : 2019-07-17T15:16:37.123456Z
//5.7 date : 2019-07-17T15:16:37.123456+01:00
// 10.3 date: 2019-07-15 7:32:25
var DateLayouts = []string{
"2006-01-02T15:04:05.000000Z", // 5.7
"2006-01-02T15:04:05.000000-07:00", // 5.7
"060102 15:04:05", // 5.5
"2006-01-02 15:04:05", // 5.6
"2006-01-02 15:04:05", // 10.3, yes the extra space is needed
"2006/01/02 15:04:05", // sometimes found in socat errors
}
// BetweenDateRegex generate a regex to filter mysql error log dates to just get
// events between 2 dates
// Currently limited to filter by day to produce "short" regexes. Finer events will be filtered later in code
// Trying to filter hours, minutes using regexes would produce regexes even harder to read
// while not really adding huge benefit as we do not expect so many events of interets
func BetweenDateRegex(since *time.Time, skipLeadingCircumflex bool) string {
/*
"2006-01-02
"2006-01-0[3-9]
"2006-01-[1-9][0-9]
"2006-0[2-9]-[0-9]{2}
"2006-[1-9][0-9]-[0-9]{2}
"200[7-9]-[0-9]{2}-[0-9]{2}
"20[1-9][0-9]-[0-9]{2}-[0-9]{2}
*/
separator := "|^"
if skipLeadingCircumflex {
separator = "|"
}
regexConstructor := []struct {
unit int
unitToStr string
}{
{
unit: since.Day(),
unitToStr: fmt.Sprintf("%02d", since.Day()),
},
{
unit: int(since.Month()),
unitToStr: fmt.Sprintf("%02d", since.Month()),
},
{
unit: since.Year(),
unitToStr: fmt.Sprintf("%d", since.Year())[2:],
},
}
s := ""
for _, layout := range []string{"2006-01-02", "060102"} {
// base complete date
lastTransformed := since.Format(layout)
s += separator + lastTransformed
for _, construct := range regexConstructor {
if construct.unit != 9 {
s += separator + utils.StringsReplaceReversed(lastTransformed, construct.unitToStr, string(construct.unitToStr[0])+"["+strconv.Itoa(construct.unit%10+1)+"-9]", 1)
}
// %1000 here is to cover the transformation of 2022 => 22
s += separator + utils.StringsReplaceReversed(lastTransformed, construct.unitToStr, "["+strconv.Itoa((construct.unit%1000/10)+1)+"-9][0-9]", 1)
lastTransformed = utils.StringsReplaceReversed(lastTransformed, construct.unitToStr, "[0-9][0-9]", 1)
}
}
s += ")"
return "(" + s[1:]
}
// basically capturing anything that does not have a date
// needed, else we would miss some logs, like wsrep recovery
func NoDatesRegex(skipLeadingCircumflex bool) string {
//return "((?![0-9]{4}-[0-9]{2}-[0-9]{2})|(?![0-9]{6}))"
if skipLeadingCircumflex {
return "(?![0-9]{4})"
}
return "^(?![0-9]{4})"
}
/*
SYSLOG_DATE="\(Jan\|Feb\|Mar\|Apr\|May\|Jun\|Jul\|Aug\|Sep\|Oct\|Nov\|Dec\) \( \|[0-9]\)[0-9] [0-9]\{2\}:[0-9]\{2\}:[0-9]\{2\}"
REGEX_LOG_PREFIX="$REGEX_DATE \?[0-9]* "
*/
const k8sprefix = `{"log":"`
func SearchDateFromLog(logline string) (time.Time, string, bool) {
if logline[:len(k8sprefix)] == k8sprefix {
logline = logline[len(k8sprefix):]
}
for _, layout := range DateLayouts {
if len(logline) < len(layout) {
continue
}
t, err := time.Parse(layout, logline[:len(layout)])
if err == nil {
return t, layout, true
}
}
log.Debug().Str("log", logline).Msg("could not find date from log")
return time.Time{}, "", false
}

View File

@@ -0,0 +1,44 @@
package regex
import (
"testing"
"time"
)
func TestDateAfter(t *testing.T) {
tests := []struct {
input string
format string
expected string
}{
{
input: "2006-01-02T15:04:05Z",
format: time.RFC3339,
expected: "(^2006-01-02|^2006-01-0[3-9]|^2006-01-[1-9][0-9]|^2006-0[2-9]-[0-9][0-9]|^2006-[1-9][0-9]-[0-9][0-9]|^200[7-9]-[0-9][0-9]-[0-9][0-9]|^20[1-9][0-9]-[0-9][0-9]-[0-9][0-9]|^060102|^06010[3-9]|^0601[1-9][0-9]|^060[2-9][0-9][0-9]|^06[1-9][0-9][0-9][0-9]|^0[7-9][0-9][0-9][0-9][0-9]|^[1-9][0-9][0-9][0-9][0-9][0-9])",
},
{
input: "2006-01-02",
format: "2006-01-02",
expected: "(^2006-01-02|^2006-01-0[3-9]|^2006-01-[1-9][0-9]|^2006-0[2-9]-[0-9][0-9]|^2006-[1-9][0-9]-[0-9][0-9]|^200[7-9]-[0-9][0-9]-[0-9][0-9]|^20[1-9][0-9]-[0-9][0-9]-[0-9][0-9]|^060102|^06010[3-9]|^0601[1-9][0-9]|^060[2-9][0-9][0-9]|^06[1-9][0-9][0-9][0-9]|^0[7-9][0-9][0-9][0-9][0-9]|^[1-9][0-9][0-9][0-9][0-9][0-9])",
},
{
input: "060102",
format: "060102",
expected: "(^2006-01-02|^2006-01-0[3-9]|^2006-01-[1-9][0-9]|^2006-0[2-9]-[0-9][0-9]|^2006-[1-9][0-9]-[0-9][0-9]|^200[7-9]-[0-9][0-9]-[0-9][0-9]|^20[1-9][0-9]-[0-9][0-9]-[0-9][0-9]|^060102|^06010[3-9]|^0601[1-9][0-9]|^060[2-9][0-9][0-9]|^06[1-9][0-9][0-9][0-9]|^0[7-9][0-9][0-9][0-9][0-9]|^[1-9][0-9][0-9][0-9][0-9][0-9])",
},
{
input: "2022-01-22",
format: "2006-01-02",
expected: "(^2022-01-22|^2022-01-2[3-9]|^2022-01-[3-9][0-9]|^2022-0[2-9]-[0-9][0-9]|^2022-[1-9][0-9]-[0-9][0-9]|^202[3-9]-[0-9][0-9]-[0-9][0-9]|^20[3-9][0-9]-[0-9][0-9]-[0-9][0-9]|^220122|^22012[3-9]|^2201[3-9][0-9]|^220[2-9][0-9][0-9]|^22[1-9][0-9][0-9][0-9]|^2[3-9][0-9][0-9][0-9][0-9]|^[3-9][0-9][0-9][0-9][0-9][0-9])",
},
}
for _, test := range tests {
d, _ := time.Parse(test.format, test.input)
s := BetweenDateRegex(&d, false)
if s != test.expected {
t.Log("wrong date regex:", s)
t.Fail()
}
}
}

View File

@@ -0,0 +1,179 @@
package regex
import (
"regexp"
"strings"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/types"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/utils"
)
func init() {
setType(types.EventsRegexType, EventsMap)
}
var EventsMap = types.RegexMap{
"RegexStarting": &types.LogRegex{
Regex: regexp.MustCompile("starting as process"),
InternalRegex: regexp.MustCompile("\\(mysqld " + regexVersion + ".*\\)"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.Version = submatches[groupVersion]
msg := "starting(" + ctx.Version
if isShutdownReasonMissing(ctx) {
msg += ", " + utils.Paint(utils.YellowText, "could not catch how/when it stopped")
}
msg += ")"
ctx.SetState("OPEN")
return ctx, types.SimpleDisplayer(msg)
},
},
"RegexShutdownComplete": &types.LogRegex{
Regex: regexp.MustCompile("mysqld: Shutdown complete"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("CLOSED")
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "shutdown complete"))
},
},
"RegexTerminated": &types.LogRegex{
Regex: regexp.MustCompile("mysqld: Terminated"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("CLOSED")
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "terminated"))
},
},
"RegexGotSignal6": &types.LogRegex{
Regex: regexp.MustCompile("mysqld got signal 6"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("CLOSED")
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "crash: got signal 6"))
},
},
"RegexGotSignal11": &types.LogRegex{
Regex: regexp.MustCompile("mysqld got signal 11"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("CLOSED")
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "crash: got signal 11"))
},
},
"RegexShutdownSignal": &types.LogRegex{
Regex: regexp.MustCompile("Normal|Received shutdown"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("CLOSED")
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "received shutdown"))
},
},
// 2023-06-12T07:51:38.135646Z 0 [Warning] [MY-000000] [Galera] Exception while mapping writeset addr: 0x7fb668d4e568, seqno: 2770385572449823232, size: 73316, ctx: 0x56128412e0c0, flags: 1. store: 1, type: 32 into [555, 998): 'deque::_M_new_elements_at_back'. Aborting GCache recovery.
"RegexAborting": &types.LogRegex{
Regex: regexp.MustCompile("Aborting"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("CLOSED")
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "ABORTING"))
},
},
"RegexWsrepLoad": &types.LogRegex{
Regex: regexp.MustCompile("wsrep_load\\(\\): loading provider library"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("OPEN")
if regexWsrepLoadNone.MatchString(log) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.GreenText, "started(standalone)"))
}
return ctx, types.SimpleDisplayer(utils.Paint(utils.GreenText, "started(cluster)"))
},
},
"RegexWsrepRecovery": &types.LogRegex{
// INFO: WSREP: Recovered position 00000000-0000-0000-0000-000000000000:-1
Regex: regexp.MustCompile("Recovered position"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
msg := "wsrep recovery"
// if state is joiner, it can be due to sst
// if state is open, it is just a start sequence depending on platform
if isShutdownReasonMissing(ctx) && ctx.State() != "JOINER" && ctx.State() != "OPEN" {
msg += "(" + utils.Paint(utils.YellowText, "could not catch how/when it stopped") + ")"
}
ctx.SetState("RECOVERY")
return ctx, types.SimpleDisplayer(msg)
},
},
"RegexUnknownConf": &types.LogRegex{
Regex: regexp.MustCompile("unknown variable"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
split := strings.Split(log, "'")
v := "?"
if len(split) > 0 {
v = split[1]
}
if len(v) > 20 {
v = v[:20] + "..."
}
return ctx, types.SimpleDisplayer(utils.Paint(utils.YellowText, "unknown variable") + ": " + v)
},
},
"RegexAssertionFailure": &types.LogRegex{
Regex: regexp.MustCompile("Assertion failure"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("CLOSED")
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "ASSERTION FAILURE"))
},
},
"RegexBindAddressAlreadyUsed": &types.LogRegex{
Regex: regexp.MustCompile("asio error .bind: Address already in use"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("CLOSED")
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "bind address already used"))
},
},
"RegexTooManyConnections": &types.LogRegex{
Regex: regexp.MustCompile("Too many connections"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "too many connections"))
},
},
"RegexReversingHistory": &types.LogRegex{
Regex: regexp.MustCompile("Reversing history"),
InternalRegex: regexp.MustCompile("Reversing history: " + regexSeqno + " -> [0-9]*, this member has applied (?P<diff>[0-9]*) more events than the primary component"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.BrightRedText, "having "+submatches["diff"]+" more events than the other nodes, data loss possible"))
},
},
}
var regexWsrepLoadNone = regexp.MustCompile("none")
// isShutdownReasonMissing is returning true if the latest wsrep state indicated a "working" node
func isShutdownReasonMissing(ctx types.LogCtx) bool {
return ctx.State() != "DESTROYED" && ctx.State() != "CLOSED" && ctx.State() != "RECOVERY" && ctx.State() != ""
}
/*
2023-05-09T17:39:19.955040Z 51 [Warning] [MY-000000] [Galera] failed to replay trx: source: fb9d6310-ee8b-11ed-8aee-f7542ad73e53 version: 5 local: 1 flags: 1 conn_id: 48 trx_id: 2696 tstamp: 1683653959142522853; state: EXECUTING:0->REPLICATING:782->CERTIFYING:3509->APPLYING:3748->COMMITTING:1343->COMMITTED:-1
2023-05-09T17:39:19.955085Z 51 [Warning] [MY-000000] [Galera] Invalid state in replay for trx source: fb9d6310-ee8b-11ed-8aee-f7542ad73e53 version: 5 local: 1 flags: 1 conn_id: 48 trx_id: 2696 tstamp: 1683653959142522853; state: EXECUTING:0->REPLICATING:782->CERTIFYING:3509->APPLYING:3748->COMMITTING:1343->COMMITTED:-1 (FATAL)
at galera/src/replicator_smm.cpp:replay_trx():1247
2001-01-01T01:01:01.000000Z 0 [ERROR] [MY-000000] [Galera] gcs/src/gcs_group.cpp:group_post_state_exchange():431: Reversing history: 312312 -> 20121, this member has applied 12345 more events than the primary component.Data loss is possible. Must abort.
2023-06-07T02:50:17.288285-06:00 0 [ERROR] WSREP: Requested size 114209078 for '/var/lib/mysql//galera.cache' exceeds available storage space 1: 28 (No space left on device)
2023-01-01 11:33:15 2101097 [ERROR] mariadbd: Disk full (/tmp/#sql-temptable-.....MAI); waiting for someone to free some space... (errno: 28 "No space left on device")
2023-06-13 1:15:27 35 [Note] WSREP: MDL BF-BF conflict
*/

View File

@@ -0,0 +1,33 @@
package regex
import "regexp"
var RegexOperatorFileType = regexp.MustCompile(`\"file\":\"/([a-z]+/)+(?P<filetype>[a-z._-]+.log)\"}$`)
var RegexOperatorShellDebugFileType = regexp.MustCompile(`^\+`)
func FileType(line string, operator bool) string {
if !operator {
// if not operator, we can't really guess
return "error.log"
}
r, err := internalRegexSubmatch(RegexOperatorFileType, line)
if err != nil {
if RegexOperatorShellDebugFileType.MatchString(line) {
return "operator shell"
}
return ""
}
t := r[RegexOperatorFileType.SubexpIndex("filetype")]
switch t {
case "mysqld.post.processing.log":
return "post.processing.log"
case "wsrep_recovery_verbose.log":
return "recovery.log"
case "mysqld-error.log":
return "error.log"
case "innobackup.backup.log":
return "backup.log"
default:
return t
}
}

View File

@@ -0,0 +1,47 @@
package regex
import (
"testing"
)
func TestFileType(t *testing.T) {
tests := []struct {
inputline string
inputoperator bool
expected string
}{
{
inputline: `{"log":"2023-07-11T06:03:51.109165Z 0 [Note] [MY-010747] [Server] Plugin 'FEDERATED' is disabled.\n","file":"/var/lib/mysql/wsrep_recovery_verbose.log"}`,
inputoperator: true,
expected: "recovery.log",
},
{
inputline: `{"log":"2023-07-11T06:03:51.109165Z 0 [Note] [MY-010747] [Server] Plugin 'FEDERATED' is disabled.\n","file":"/var/lib/mysql/mysqld-error.log"}`,
inputoperator: true,
expected: "error.log",
},
{
inputline: `{"log":"2023-07-11T06:03:51.109165Z 0 [Note] [MY-010747] [Server] Plugin 'FEDERATED' is disabled.\n","file":"/var/lib/mysql/mysqld.post.processing.log"}`,
inputoperator: true,
expected: "post.processing.log",
},
{
inputline: `+ NODE_PORT=3306`,
inputoperator: true,
expected: "operator shell",
},
{
inputline: `++ hostname -f`,
inputoperator: true,
expected: "operator shell",
},
}
for _, test := range tests {
out := FileType(test.inputline, test.inputoperator)
if out != test.expected {
t.Errorf("expected: %s, got: %s", test.expected, out)
}
}
}

View File

@@ -0,0 +1,212 @@
package regex
import (
"regexp"
"strconv"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/types"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/utils"
)
func init() {
init_add_regexes()
setType(types.IdentRegexType, IdentsMap)
}
var IdentsMap = types.RegexMap{
// sourceNode is to identify from which node this log was taken
"RegexSourceNode": &types.LogRegex{
Regex: regexp.MustCompile("(local endpoint for a connection, blacklisting address)|(points to own listening address, blacklisting)"),
InternalRegex: regexp.MustCompile("\\(" + regexNodeHash + ", '.+'\\).+" + regexNodeIPMethod),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ip := submatches[groupNodeIP]
ctx.AddOwnIP(ip)
return ctx, types.SimpleDisplayer(ip + " is local")
},
Verbosity: types.DebugMySQL,
},
// 2022-12-18T01:03:17.950545Z 0 [Note] [MY-000000] [Galera] Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 127.0.0.1;
"RegexBaseHost": &types.LogRegex{
Regex: regexp.MustCompile("base_host"),
InternalRegex: regexp.MustCompile("base_host = " + regexNodeIP),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ip := submatches[groupNodeIP]
ctx.AddOwnIP(ip)
return ctx, types.SimpleDisplayer(ctx.OwnIPs[len(ctx.OwnIPs)-1] + " is local")
},
Verbosity: types.DebugMySQL,
},
// 0: 015702fc-32f5-11ed-a4ca-267f97316394, node-1
// 1: 08dd5580-32f7-11ed-a9eb-af5e3d01519e, garb
// TO *never* DO: store indexes to later search for them using SST infos and STATES EXCHANGES logs. EDIT: is definitely NOT reliable
"RegexMemberAssociations": &types.LogRegex{
Regex: regexp.MustCompile("[0-9]: [a-z0-9]+-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]+, [a-zA-Z0-9-_]+"),
InternalRegex: regexp.MustCompile(regexIdx + ": " + regexUUID + ", " + regexNodeName),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
idx := submatches[groupIdx]
hash := submatches[groupUUID]
nodename := utils.ShortNodeName(submatches[groupNodeName])
// nodenames are truncated after 32 characters ...
if len(nodename) == 31 {
return ctx, nil
}
shorthash := utils.UUIDToShortUUID(hash)
ctx.HashToNodeName[shorthash] = nodename
if ctx.MyIdx == idx && (ctx.IsPrimary() || ctx.MemberCount == 1) {
ctx.AddOwnHash(shorthash)
ctx.AddOwnName(nodename)
}
return ctx, types.SimpleDisplayer(shorthash + " is " + nodename)
},
Verbosity: types.DebugMySQL,
},
"RegexMemberCount": &types.LogRegex{
Regex: regexp.MustCompile("members.[0-9]+.:"),
InternalRegex: regexp.MustCompile(regexMembers),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
members := submatches[groupMembers]
membercount, err := strconv.Atoi(members)
if err != nil {
return ctx, nil
}
ctx.MemberCount = membercount
return ctx, types.SimpleDisplayer("view member count: " + members)
},
Verbosity: types.DebugMySQL,
},
// My UUID: 6938f4ae-32f4-11ed-be8d-8a0f53f88872
"RegexOwnUUID": &types.LogRegex{
Regex: regexp.MustCompile("My UUID"),
InternalRegex: regexp.MustCompile("My UUID: " + regexUUID),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
shorthash := utils.UUIDToShortUUID(submatches[groupUUID])
ctx.AddOwnHash(shorthash)
return ctx, types.SimpleDisplayer(shorthash + " is local")
},
Verbosity: types.DebugMySQL,
},
// 2023-01-06T06:59:26.527748Z 0 [Note] WSREP: (9509c194, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
"RegexOwnUUIDFromMessageRelay": &types.LogRegex{
Regex: regexp.MustCompile("turning message relay requesting"),
InternalRegex: regexp.MustCompile("\\(" + regexNodeHash + ", '" + regexNodeIPMethod + "'\\)"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
hash := submatches[groupNodeHash]
ctx.AddOwnHash(hash)
return ctx, types.SimpleDisplayer(hash + " is local")
},
Verbosity: types.DebugMySQL,
},
// 2023-01-06T07:05:35.693861Z 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
"RegexMyIDXFromComponent": &types.LogRegex{
Regex: regexp.MustCompile("New COMPONENT:"),
InternalRegex: regexp.MustCompile("New COMPONENT:.*my_idx = " + regexIdx),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
idx := submatches[groupIdx]
ctx.MyIdx = idx
return ctx, types.SimpleDisplayer("my_idx=" + idx)
},
Verbosity: types.DebugMySQL,
},
/*
can't be trusted, from actual log:
View:
id: <some cluster uuid>:<seqno>
status: primary
protocol_version: 4
capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO
final: no
own_index: 1
members(3):
0: <some uuid>, node0
1: <some uuid>, node1
2: <some uuid>, node2
=================================================
2023-05-28T21:18:23.184707-05:00 2 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2023-05-28T21:18:23.193459-05:00 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: sent state msg: <cluster uuid>
2023-05-28T21:18:23.195777-05:00 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: <cluster uuid> from 0 (node1)
2023-05-28T21:18:23.195805-05:00 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: <cluster uuid> from 1 (node2)
"RegexOwnNameFromStateExchange": &types.LogRegex{
Regex: regexp.MustCompile("STATE EXCHANGE: got state msg"),
InternalRegex: regexp.MustCompile("STATE EXCHANGE:.* from " + regexIdx + " \\(" + regexNodeName + "\\)"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
r, err := internalRegexSubmatch(internalRegex, log)
if err != nil {
return ctx, nil
}
idx := submatches[groupIdx]
name := submatches[groupNodeName]
if idx != ctx.MyIdx {
return ctx, types.SimpleDisplayer("name(" + name + ") from unknown idx")
}
if ctx.State == "NON-PRIMARY" {
return ctx, types.SimpleDisplayer("name(" + name + ") can't be trusted as it's non-primary")
}
ctx.AddOwnName(name)
return ctx, types.SimpleDisplayer("local name:" + name)
},
Verbosity: types.DebugMySQL,
},
*/
}
func init_add_regexes() {
// 2023-01-06T07:05:34.035959Z 0 [Note] WSREP: (9509c194, 'tcp://0.0.0.0:4567') connection established to 838ebd6d tcp://ip:4567
IdentsMap["RegexOwnUUIDFromEstablished"] = &types.LogRegex{
Regex: regexp.MustCompile("connection established to"),
InternalRegex: IdentsMap["RegexOwnUUIDFromMessageRelay"].InternalRegex,
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return IdentsMap["RegexOwnUUIDFromMessageRelay"].Handler(submatches, ctx, log)
},
Verbosity: types.DebugMySQL,
}
IdentsMap["RegexOwnIndexFromView"] = &types.LogRegex{
Regex: regexp.MustCompile("own_index:"),
InternalRegex: regexp.MustCompile("own_index: " + regexIdx),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return IdentsMap["RegexMyIDXFromComponent"].Handler(submatches, ctx, log)
},
Verbosity: types.DebugMySQL,
}
// 2023-01-06T07:05:35.698869Z 7 [Note] WSREP: New cluster view: global state: 00000000-0000-0000-0000-000000000000:0, view# 10: Primary, number of nodes: 2, my index: 0, protocol version 3
// WARN: my index seems to always be 0 on this log on certain version. It had broken some nodenames
/*
IdentsMap["RegexMyIDXFromClusterView"] = &types.LogRegex{
Regex: regexp.MustCompile("New cluster view:"),
InternalRegex: regexp.MustCompile("New cluster view:.*my index: " + regexIdx + ","),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return IdentsMap["RegexMyIDXFromComponent"].Handler(internalRegex, ctx, log)
},
Verbosity: types.DebugMySQL,
}
*/
}

View File

@@ -0,0 +1,55 @@
package regex
import (
"regexp"
"strings"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/types"
)
func init() {
setType(types.PXCOperatorRegexType, PXCOperatorMap)
}
// Regexes from this type should only be about operator extra logs
// it should not contain Galera logs
// Specifically operators are dumping configuration files, recoveries, script outputs, ...
// only those should be handled here, they are specific to pxc operator but still very insightful
var PXCOperatorMap = types.RegexMap{
"RegexNodeNameFromEnv": &types.LogRegex{
Regex: regexp.MustCompile(". NODE_NAME="),
InternalRegex: regexp.MustCompile("NODE_NAME=" + regexNodeName),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
nodename := submatches[groupNodeName]
nodename, _, _ = strings.Cut(nodename, ".")
ctx.AddOwnName(nodename)
return ctx, types.SimpleDisplayer("local name:" + nodename)
},
Verbosity: types.DebugMySQL,
},
"RegexNodeIPFromEnv": &types.LogRegex{
Regex: regexp.MustCompile(". NODE_IP="),
InternalRegex: regexp.MustCompile("NODE_IP=" + regexNodeIP),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ip := submatches[groupNodeIP]
ctx.AddOwnIP(ip)
return ctx, types.SimpleDisplayer("local ip:" + ip)
},
Verbosity: types.DebugMySQL,
},
// Why is it not in regular "views" regexes:
// it could have been useful as an "verbosity=types.Detailed" regexes, very rarely
// but in context of operators, it is actually a very important information
"RegexGcacheScan": &types.LogRegex{
// those "operators" regexes do not have the log prefix added implicitely. It's not strictly needed, but
// it will help to avoid catching random piece of log out of order
Regex: regexp.MustCompile("^{\"log\":\".*GCache::RingBuffer initial scan"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer("recovering gcache")
},
},
}

View File

@@ -0,0 +1,72 @@
package regex
import (
"errors"
"fmt"
"regexp"
"strings"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/types"
)
func internalRegexSubmatch(regex *regexp.Regexp, log string) ([]string, error) {
slice := regex.FindStringSubmatch(log)
if len(slice) == 0 {
return nil, errors.New(fmt.Sprintf("Could not find submatch from log \"%s\" using pattern \"%s\"", log, regex.String()))
}
return slice, nil
}
func setType(t types.RegexType, regexes types.RegexMap) {
for _, regex := range regexes {
regex.Type = t
}
return
}
// SetVerbosity accepts any LogRegex
// Some can be useful to construct context, but we can choose not to display them
func SetVerbosity(verbosity types.Verbosity, regexes types.RegexMap) {
for _, regex := range regexes {
regex.Verbosity = verbosity
}
return
}
func AllRegexes() types.RegexMap {
IdentsMap.Merge(ViewsMap).Merge(SSTMap).Merge(EventsMap).Merge(StatesMap).Merge(ApplicativeMap)
return IdentsMap
}
// general building block wsrep regexes
// It's later used to identify subgroups easier
var (
groupMethod = "ssltcp"
groupNodeIP = "nodeip"
groupNodeHash = "uuid"
groupUUID = "uuid" // same value as groupnodehash, because both are used in same context
groupNodeName = "nodename"
groupNodeName2 = "nodename2"
groupIdx = "idx"
groupSeqno = "seqno"
groupMembers = "members"
groupVersion = "version"
groupErrorMD5 = "errormd5"
regexMembers = "(?P<" + groupMembers + ">[0-9]{1,2})"
regexNodeHash = "(?P<" + groupNodeHash + ">[a-zA-Z0-9-_]+)"
regexNodeName = "(?P<" + groupNodeName + `>[a-zA-Z0-9-_\.]+)`
regexNodeName2 = strings.Replace(regexNodeName, groupNodeName, groupNodeName2, 1)
regexUUID = "(?P<" + groupUUID + ">[a-z0-9]+-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]{4}-[a-z0-9]+)" // eg ed97c863-d5c9-11ec-8ab7-671bbd2d70ef
regexNodeHash1Dash = "(?P<" + groupNodeHash + ">[a-z0-9]+-[a-z0-9]{4})" // eg ed97c863-8ab7
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})"
regexVersion = "(?P<" + groupVersion + ">(5|8|10|11)\\.[0-9]\\.[0-9]{1,2})"
regexErrorMD5 = "(?P<" + groupErrorMD5 + ">[a-z0-9]*)"
)
func IsNodeUUID(s string) bool {
b, _ := regexp.MatchString(regexUUID, s)
return b
}

File diff suppressed because it is too large Load Diff

View File

@@ -0,0 +1,310 @@
package regex
import (
"regexp"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/types"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/utils"
)
func init() {
setType(types.SSTRegexType, SSTMap)
}
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 + "\\)\\("),
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
}
if utils.SliceContains(ctx.OwnNames, donor) {
ctx.SST.ResyncingNode = joiner
}
return ctx, func(ctx types.LogCtx) string {
if utils.SliceContains(ctx.OwnNames, joiner) {
return donor + utils.Paint(utils.GreenText, " will resync local node")
}
if utils.SliceContains(ctx.OwnNames, donor) {
return utils.Paint(utils.GreenText, "local node will resync ") + joiner
}
return donor + utils.Paint(utils.GreenText, " will resync ") + joiner
}
},
Verbosity: types.Detailed,
},
"RegexSSTResourceUnavailable": &types.LogRegex{
Regex: regexp.MustCompile("requested state transfer.*Resource temporarily unavailable"),
InternalRegex: regexp.MustCompile("Member .* \\(" + regexNodeName + "\\) requested state transfer"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
joiner := submatches[groupNodeName]
if utils.SliceContains(ctx.OwnNames, joiner) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.YellowText, "cannot find donor"))
}
return ctx, types.SimpleDisplayer(joiner + utils.Paint(utils.YellowText, " cannot find donor"))
},
},
// 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"),
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
}
ctx.SST.Reset()
ctx = addOwnNameWithSSTMetadata(ctx, joiner, donor)
return ctx, func(ctx types.LogCtx) string {
if utils.SliceContains(ctx.OwnNames, joiner) {
return utils.Paint(utils.GreenText, "got "+displayType+" from ") + donor
}
if utils.SliceContains(ctx.OwnNames, donor) {
return utils.Paint(utils.GreenText, "finished sending "+displayType+" to ") + joiner
}
return donor + utils.Paint(utils.GreenText, " synced ") + joiner
}
},
},
// some weird ones:
// 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"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
donor := utils.ShortNodeName(submatches[groupNodeName])
ctx = addOwnNameWithSSTMetadata(ctx, "", 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"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
donor := utils.ShortNodeName(submatches[groupNodeName])
ctx = addOwnNameWithSSTMetadata(ctx, "", 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"),
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)
return ctx, types.SimpleDisplayer(donor + utils.Paint(utils.RedText, " failed to sync ") + joiner)
},
},
"RegexSSTError": &types.LogRegex{
Regex: regexp.MustCompile("Process completed with error: wsrep_sst"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "SST error"))
},
},
"RegexSSTCancellation": &types.LogRegex{
Regex: regexp.MustCompile("Initiating SST cancellation"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "former SST cancelled"))
},
},
"RegexSSTProceeding": &types.LogRegex{
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"
return ctx, types.SimpleDisplayer(utils.Paint(utils.YellowText, "receiving SST"))
},
},
"RegexSSTStreamingTo": &types.LogRegex{
Regex: regexp.MustCompile("Streaming the backup to"),
InternalRegex: regexp.MustCompile("Streaming the backup to joiner at " + regexNodeIP),
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
}
return ctx, func(ctx types.LogCtx) string {
return utils.Paint(utils.YellowText, "SST to ") + types.DisplayNodeSimplestForm(ctx, node)
}
},
},
"RegexISTReceived": &types.LogRegex{
Regex: regexp.MustCompile("IST received"),
// the UUID here is not from a node, it's a cluster state UUID, this is only used to ensure it's correctly parsed
InternalRegex: regexp.MustCompile("IST received: " + regexUUID + ":" + regexSeqno),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
seqno := submatches[groupSeqno]
return ctx, types.SimpleDisplayer(utils.Paint(utils.GreenText, "IST received") + "(seqno:" + seqno + ")")
},
},
"RegexISTSender": &types.LogRegex{
Regex: regexp.MustCompile("IST sender starting"),
// 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")
seqno := submatches[groupSeqno]
node := submatches[groupNodeIP]
return ctx, func(ctx types.LogCtx) string {
return utils.Paint(utils.YellowText, "IST to ") + types.DisplayNodeSimplestForm(ctx, node) + "(seqno:" + seqno + ")"
}
},
},
"RegexISTReceiver": &types.LogRegex{
Regex: regexp.MustCompile("Prepared IST receiver"),
InternalRegex: regexp.MustCompile("Prepared IST receiver( for (?P<startingseqno>[0-9]+)-" + regexSeqno + ")?"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("JOINER")
seqno := submatches[groupSeqno]
msg := utils.Paint(utils.YellowText, "will receive ")
startingseqno := submatches["startingseqno"]
// if it's 0, it will go to SST without a doubt
if startingseqno == "0" {
ctx.SST.Type = "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"
msg += "IST"
if seqno != "" {
msg += "(seqno:" + seqno + ")"
}
}
return ctx, types.SimpleDisplayer(msg)
},
},
"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"
return ctx, types.SimpleDisplayer("IST is not applicable")
},
},
// 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"
return ctx, types.SimpleDisplayer("IST will be used")
},
},
"RegexSocatConnRefused": &types.LogRegex{
Regex: regexp.MustCompile("E connect.*Connection refused"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "socat: connection refused"))
},
},
// 2023-05-12T02:52:33.767132Z 0 [Note] [MY-000000] [WSREP-SST] Preparing the backup at /var/lib/mysql/sst-xb-tmpdir
"RegexPreparingBackup": &types.LogRegex{
Regex: regexp.MustCompile("Preparing the backup at"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer("preparing SST backup")
},
Verbosity: types.Detailed,
},
"RegexTimeoutReceivingFirstData": &types.LogRegex{
Regex: regexp.MustCompile("Possible timeout in receving first data from donor in gtid/keyring stage"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "timeout from donor in gtid/keyring stage"))
},
},
"RegexWillNeverReceive": &types.LogRegex{
Regex: regexp.MustCompile("Will never receive state. Need to abort"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "will never receive SST, aborting"))
},
},
"RegexISTFailed": &types.LogRegex{
Regex: regexp.MustCompile("async IST sender failed to serve"),
InternalRegex: regexp.MustCompile("IST sender failed to serve " + regexNodeIPMethod + ":.*asio error '.*: [0-9]+ \\((?P<error>[\\w\\s]+)\\)"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
node := submatches[groupNodeIP]
istError := submatches["error"]
return ctx, func(ctx types.LogCtx) string {
return "IST to " + types.DisplayNodeSimplestForm(ctx, node) + utils.Paint(utils.RedText, " failed: ") + istError
}
},
},
}
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.
)
*/

View File

@@ -0,0 +1,44 @@
package regex
import (
"regexp"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/types"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/utils"
)
func init() {
setType(types.StatesRegexType, StatesMap)
}
var (
shiftFunc = func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState(submatches["state2"])
log = utils.PaintForState(submatches["state1"], submatches["state1"]) + " -> " + utils.PaintForState(submatches["state2"], submatches["state2"])
return ctx, types.SimpleDisplayer(log)
}
shiftRegex = regexp.MustCompile("(?P<state1>[A-Z]+) -> (?P<state2>[A-Z]+)")
)
var StatesMap = types.RegexMap{
"RegexShift": &types.LogRegex{
Regex: regexp.MustCompile("Shifting"),
InternalRegex: shiftRegex,
Handler: shiftFunc,
},
"RegexRestoredState": &types.LogRegex{
Regex: regexp.MustCompile("Restored state"),
InternalRegex: shiftRegex,
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
var displayer types.LogDisplayer
ctx, displayer = shiftFunc(submatches, ctx, log)
return ctx, types.SimpleDisplayer("(restored)" + displayer(ctx))
},
},
}
// [Note] [MY-000000] [WSREP] Server status change connected -> joiner

View File

@@ -0,0 +1,257 @@
package regex
import (
"regexp"
"strconv"
"strings"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/types"
"github.com/percona/percona-toolkit/src/go/pt-galera-log-explainer/utils"
)
func init() {
setType(types.ViewsRegexType, ViewsMap)
}
// "galera views" regexes
var ViewsMap = types.RegexMap{
"RegexNodeEstablished": &types.LogRegex{
Regex: regexp.MustCompile("connection established"),
InternalRegex: regexp.MustCompile("established to " + regexNodeHash + " " + regexNodeIPMethod),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ip := submatches[groupNodeIP]
ctx.HashToIP[submatches[groupNodeHash]] = ip
if utils.SliceContains(ctx.OwnIPs, ip) {
return ctx, nil
}
return ctx, func(ctx types.LogCtx) string { return types.DisplayNodeSimplestForm(ctx, ip) + " established" }
},
Verbosity: types.DebugMySQL,
},
"RegexNodeJoined": &types.LogRegex{
Regex: regexp.MustCompile("declaring .* stable"),
InternalRegex: regexp.MustCompile("declaring " + regexNodeHash + " at " + regexNodeIPMethod),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ip := submatches[groupNodeIP]
ctx.HashToIP[submatches[groupNodeHash]] = ip
ctx.IPToMethod[ip] = submatches[groupMethod]
return ctx, func(ctx types.LogCtx) string {
return types.DisplayNodeSimplestForm(ctx, ip) + utils.Paint(utils.GreenText, " joined")
}
},
},
"RegexNodeLeft": &types.LogRegex{
Regex: regexp.MustCompile("forgetting"),
InternalRegex: regexp.MustCompile("forgetting " + regexNodeHash + " \\(" + regexNodeIPMethod),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ip := submatches[groupNodeIP]
return ctx, func(ctx types.LogCtx) string {
return types.DisplayNodeSimplestForm(ctx, ip) + utils.Paint(utils.RedText, " left")
}
},
},
// New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 5
"RegexNewComponent": &types.LogRegex{
Regex: regexp.MustCompile("New COMPONENT:"),
InternalRegex: regexp.MustCompile("New COMPONENT: primary = (?P<primary>.+), bootstrap = (?P<bootstrap>.*), my_idx = .*, memb_num = (?P<memb_num>[0-9]{1,2})"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
primary := submatches["primary"] == "yes"
membNum := submatches["memb_num"]
bootstrap := submatches["bootstrap"] == "yes"
memberCount, err := strconv.Atoi(membNum)
if err != nil {
return ctx, nil
}
ctx.MemberCount = memberCount
if primary {
// we don't always store PRIMARY because we could have found DONOR/JOINER/SYNCED/DESYNCED just earlier
// and we do not want to override these as they have more value
if !ctx.IsPrimary() {
ctx.SetState("PRIMARY")
}
msg := utils.Paint(utils.GreenText, "PRIMARY") + "(n=" + membNum + ")"
if bootstrap {
msg += ",bootstrap"
}
return ctx, types.SimpleDisplayer(msg)
}
ctx.SetState("NON-PRIMARY")
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "NON-PRIMARY") + "(n=" + membNum + ")")
},
},
"RegexNodeSuspect": &types.LogRegex{
Regex: regexp.MustCompile("suspecting node"),
InternalRegex: regexp.MustCompile("suspecting node: " + regexNodeHash),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
hash := submatches[groupNodeHash]
ip, ok := ctx.HashToIP[hash]
if ok {
return ctx, func(ctx types.LogCtx) string {
return types.DisplayNodeSimplestForm(ctx, ip) + utils.Paint(utils.YellowText, " suspected to be down")
}
}
return ctx, types.SimpleDisplayer(hash + utils.Paint(utils.YellowText, " suspected to be down"))
},
Verbosity: types.Detailed,
},
"RegexNodeChangedIdentity": &types.LogRegex{
Regex: regexp.MustCompile("remote endpoint.*changed identity"),
InternalRegex: regexp.MustCompile("remote endpoint " + regexNodeIPMethod + " changed identity " + regexNodeHash + " -> " + strings.Replace(regexNodeHash, groupNodeHash, groupNodeHash+"2", -1)),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
hash := submatches[groupNodeHash]
hash2 := submatches[groupNodeHash+"2"]
ip, ok := ctx.HashToIP[hash]
if !ok && IsNodeUUID(hash) {
ip, ok = ctx.HashToIP[utils.UUIDToShortUUID(hash)]
// there could have additional corner case to discover yet
if !ok {
return ctx, types.SimpleDisplayer(hash + utils.Paint(utils.YellowText, " changed identity"))
}
hash2 = utils.UUIDToShortUUID(hash2)
}
ctx.HashToIP[hash2] = ip
return ctx, func(ctx types.LogCtx) string {
return types.DisplayNodeSimplestForm(ctx, ip) + utils.Paint(utils.YellowText, " changed identity")
}
},
Verbosity: types.Detailed,
},
"RegexWsrepUnsafeBootstrap": &types.LogRegex{
Regex: regexp.MustCompile("ERROR.*not be safe to bootstrap"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("CLOSED")
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "not safe to bootstrap"))
},
},
"RegexWsrepConsistenctyCompromised": &types.LogRegex{
Regex: regexp.MustCompile(".ode consistency compromi.ed"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
ctx.SetState("CLOSED")
return ctx, types.SimpleDisplayer(utils.Paint(utils.RedText, "consistency compromised"))
},
},
"RegexWsrepNonPrimary": &types.LogRegex{
Regex: regexp.MustCompile("failed to reach primary view"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer("received " + utils.Paint(utils.RedText, "non primary"))
},
},
"RegexBootstrap": &types.LogRegex{
Regex: regexp.MustCompile("gcomm: bootstrapping new group"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.YellowText, "bootstrapping"))
},
},
"RegexSafeToBoostrapSet": &types.LogRegex{
Regex: regexp.MustCompile("safe_to_bootstrap: 1"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.YellowText, "safe_to_bootstrap: 1"))
},
},
"RegexNoGrastate": &types.LogRegex{
Regex: regexp.MustCompile("Could not open state file for reading.*grastate.dat"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.YellowText, "no grastate.dat file"))
},
Verbosity: types.Detailed,
},
"RegexBootstrapingDefaultState": &types.LogRegex{
Regex: regexp.MustCompile("Bootstraping with default state"),
Handler: func(submatches map[string]string, ctx types.LogCtx, log string) (types.LogCtx, types.LogDisplayer) {
return ctx, types.SimpleDisplayer(utils.Paint(utils.YellowText, "bootstrapping(empty grastate)"))
},
},
}
/*
2022-11-29T23:34:51.820009-05:00 0 [Warning] [MY-000000] [Galera] Could not find peer: c0ff4085-5ad7-11ed-8b74-cfeec74147fe
2022-12-07 1:00:06 0 [Note] WSREP: Member 0.0 (node) synced with group.
2021-03-25T21:58:13.570928Z 0 [Warning] WSREP: no nodes coming from prim view, prim not possible
2021-03-25T21:58:13.855983Z 0 [Warning] WSREP: Quorum: No node with complete state:
2021-04-22T08:01:05.000581Z 0 [Warning] WSREP: Failed to report last committed 66328091, -110 (Connection timed out)
input_map=evs::input_map: {aru_seq=8,safe_seq=8,node_index=node: {idx=0,range=[9,8],safe_seq=8} node: {idx=1,range=[9,8],safe_seq=8} },
fifo_seq=4829086170,
last_sent=8,
known:
17a2e064 at tcp://ip:4567
{o=0,s=1,i=0,fs=-1,}
470a6438 at tcp://ip:4567
{o=1,s=0,i=0,fs=4829091361,jm=
{v=0,t=4,ut=255,o=1,s=8,sr=-1,as=8,f=4,src=470a6438,srcvid=view_id(REG,470a6438,24),insvid=view_id(UNKNOWN,00000000,0),ru=00000000,r=[-1,-1],fs=4829091361,nl=(
17a2e064, {o=0,s=1,e=0,ls=-1,vid=view_id(REG,00000000,0),ss=-1,ir=[-1,-1],}
470a6438, {o=1,s=0,e=0,ls=-1,vid=view_id(REG,470a6438,24),ss=8,ir=[9,8],}
6548cf50, {o=1,s=1,e=0,ls=-1,vid=view_id(REG,17a2e064,24),ss=12,ir=[13,12],}
8b0c0f77, {o=1,s=0,e=0,ls=-1,vid=view_id(REG,470a6438,24),ss=8,ir=[9,8],}
d4397932, {o=0,s=1,e=0,ls=-1,vid=view_id(REG,00000000,0),ss=-1,ir=[-1,-1],}
)
},
}
6548cf50 at tcp://ip:4567
{o=1,s=1,i=0,fs=-1,jm=
{v=0,t=4,ut=255,o=1,s=12,sr=-1,as=12,f=4,src=6548cf50,srcvid=view_id(REG,17a2e064,24),insvid=view_id(UNKNOWN,00000000,0),ru=00000000,r=[-1,-1],fs=4829165031,nl=(
17a2e064, {o=1,s=0,e=0,ls=-1,vid=view_id(REG,17a2e064,24),ss=12,ir=[13,12],}
470a6438, {o=1,s=0,e=0,ls=-1,vid=view_id(REG,00000000,0),ss=-1,ir=[-1,-1],}
6548cf50, {o=1,s=0,e=0,ls=-1,vid=view_id(REG,17a2e064,24),ss=12,ir=[13,12],}
8b0c0f77, {o=1,s=0,e=0,ls=-1,vid=view_id(REG,00000000,0),ss=-1,ir=[-1,-1],}
d4397932, {o=1,s=0,e=0,ls=-1,vid=view_id(REG,17a2e064,24),ss=12,ir=[13,12],}
)
},
}
8b0c0f77 at
{o=1,s=0,i=0,fs=-1,jm=
{v=0,t=4,ut=255,o=1,s=8,sr=-1,as=8,f=0,src=8b0c0f77,srcvid=view_id(REG,470a6438,24),insvid=view_id(UNKNOWN,00000000,0),ru=00000000,r=[-1,-1],fs=4829086170,nl=(
17a2e064, {o=0,s=1,e=0,ls=-1,vid=view_id(REG,00000000,0),ss=-1,ir=[-1,-1],}
470a6438, {o=1,s=0,e=0,ls=-1,vid=view_id(REG,470a6438,24),ss=8,ir=[9,8],}
6548cf50, {o=1,s=1,e=0,ls=-1,vid=view_id(REG,17a2e064,24),ss=12,ir=[13,12],}
8b0c0f77, {o=1,s=0,e=0,ls=-1,vid=view_id(REG,470a6438,24),ss=8,ir=[9,8],}
d4397932, {o=0,s=1,e=0,ls=-1,vid=view_id(REG,00000000,0),ss=-1,ir=[-1,-1],}
)
},
}
d4397932 at tcp://ip:4567
{o=0,s=1,i=0,fs=4685894552,}
}
Transport endpoint is not connected
2023-03-31T08:05:57.964535Z 0 [Note] WSREP: handshake failed, my group: '<group>', peer group: '<bad group>'
2023-04-04T22:35:23.487304Z 0 [Warning] [MY-000000] [Galera] Handshake failed: tlsv1 alert decrypt error
2023-04-16T19:35:06.875877Z 0 [Warning] [MY-000000] [Galera] Action message in non-primary configuration from member 0
{"log":"2023-06-10T04:50:46.835491Z 0 [Note] [MY-000000] [Galera] going to give up, state dump for diagnosis:\nevs::proto(evs::proto(6d0345f5-bcc0, GATHER, view_id(REG,02e369be-8363,1046)), GATHER) {\ncurrent_view=Current view of cluster as seen by this node\nview (view_id(REG,02e369be-8363,1046)\nmemb {\n\t02e369be-8363,0\n\t49761f3d-bd34,0\n\t6d0345f5-bcc0,0\n\tb05443d1-96bf,0\n\tb05443d1-96c0,0\n\t}\njoined {\n\t}\nleft {\n\t}\npartitioned {\n\t}\n),\ninput_map=evs::input_map: {aru_seq=461,safe_seq=461,node_index=node: {idx=0,range=[462,461],safe_seq=461} node: {idx=1,range=[462,461],safe_seq=461} node: {idx=2,range=[462,461],safe_seq=461} node: {idx=3,range=[462,461],safe_seq=461} node: {idx=4,range=[462,461],safe_seq=461} },\nfifo_seq=221418422,\nlast_sent=461,\nknown:\n","file":"/var/lib/mysql/mysqld-error.log"}
[Warning] WSREP: FLOW message from member -12921743687968 in non-primary configuration. Ignored.
*/