From ecd475f728c1735ffc211b42ff5b2b36d4b52981 Mon Sep 17 00:00:00 2001 From: Martin Boehm Date: Mon, 16 Apr 2018 16:40:14 +0200 Subject: [PATCH] Implement test VerifyLog of logged socket.io communication - WIP --- server/socketio_test.go | 188 ++++++++++++++++++++++++++++++++++++++++ 1 file changed, 188 insertions(+) create mode 100644 server/socketio_test.go diff --git a/server/socketio_test.go b/server/socketio_test.go new file mode 100644 index 00000000..799c2ca2 --- /dev/null +++ b/server/socketio_test.go @@ -0,0 +1,188 @@ +package server + +import ( + "bufio" + "crypto/tls" + "encoding/json" + "flag" + "os" + "sort" + "strings" + "testing" + "time" + + "github.com/gorilla/websocket" + "github.com/martinboehm/golang-socketio" + "github.com/martinboehm/golang-socketio/transport" +) + +var ( + // verifier functionality + verifylog = flag.String("verifylog", "", "path to logfile containing socket.io requests/responses") + wsurl = flag.String("wsurl", "", "URL of socket.io interface to verify") +) + +type verifyStats struct { + Count int + SuccessCount int + TotalLogNs int64 + TotalBlockbookNs int64 +} + +type logMessage struct { + ID int `json:"id"` + Et int64 `json:"et"` + Res json.RawMessage `json:"res"` + Req json.RawMessage `json:"req"` +} + +type logRequestResponse struct { + Request, Response json.RawMessage + LogElapsedTime int64 +} + +func getStat(m string, stats map[string]*verifyStats) *verifyStats { + s, ok := stats[m] + if !ok { + s = &verifyStats{} + stats[m] = s + } + return s +} + +func verifyGetInfo(t *testing.T, id int, lrs *logRequestResponse, bbRequest map[string]json.RawMessage, bbResponseS string, stat *verifyStats) { + bbResponse := resultGetInfo{} + err := json.Unmarshal([]byte(bbResponseS), &bbResponse) + if err != nil { + t.Log(id, ": error unmarshal BB request ", err) + return + } + logResponse := resultGetInfo{} + err = json.Unmarshal([]byte(lrs.Response), &logResponse) + if err != nil { + t.Log(id, ": error unmarshal log request ", err) + return + } + if logResponse.Result.Blocks <= bbResponse.Result.Blocks && + logResponse.Result.Testnet == bbResponse.Result.Testnet && + logResponse.Result.Network == bbResponse.Result.Network { + stat.SuccessCount++ + } +} + +func verifyMessage(t *testing.T, ws *gosocketio.Client, id int, lrs *logRequestResponse, stats map[string]*verifyStats) { + req := make(map[string]json.RawMessage) + err := json.Unmarshal(lrs.Request, &req) + if err != nil { + t.Log(id, ": error unmarshal request ", err) + return + } + method := strings.Trim(string(req["method"]), "\"") + if method == "" { + t.Log(id, ": there is no method specified in request") + return + } + // send the message to blockbook + start := time.Now() + res, err := ws.Ack("message", lrs.Request, time.Second*30) + if err != nil { + t.Log(id, ",", method, ": ws.Ack error ", err) + getStat("ackError", stats).Count++ + return + } + ts := time.Since(start).Nanoseconds() + t.Log(id, ",", method, ": response ", res) + stat := getStat(method, stats) + stat.Count++ + stat.TotalLogNs += lrs.LogElapsedTime + stat.TotalBlockbookNs += ts + switch method { + case "getAddressTxids": + case "getAddressHistory": + case "getBlockHeader": + case "getDetailedTransaction": + case "getInfo": + verifyGetInfo(t, id, lrs, req, res, stat) + case "estimateSmartFee": + case "estimateFee": + case "sendTransaction": + case "getMempoolEntry": + break + default: + t.Log(id, ",", method, ": unknown method", method) + } +} + +func Test_VerifyLog(t *testing.T) { + if *verifylog == "" || *wsurl == "" { + t.Skip("skipping test, flags verifylog or wsurl not specified") + } + t.Log("Verifying log", *verifylog, "against service", *wsurl) + tr := transport.GetDefaultWebsocketTransport() + tr.WebsocketDialer = websocket.Dialer{ + TLSClientConfig: &tls.Config{InsecureSkipVerify: true}, + } + ws, err := gosocketio.Dial(*wsurl, tr) + if err != nil { + t.Fatal("Dial error ", err) + return + } + defer ws.Close() + file, err := os.Open(*verifylog) + if err != nil { + t.Fatal("File read error", err) + return + } + defer file.Close() + scanner := bufio.NewScanner(file) + scanner.Split(bufio.ScanLines) + line := 0 + stats := make(map[string]*verifyStats) + pairs := make(map[int]*logRequestResponse, 0) + for scanner.Scan() { + line++ + msg := logMessage{} + err := json.Unmarshal(scanner.Bytes(), &msg) + if err != nil { + t.Log("Line ", line, ": json error ", err) + continue + } + lrs, exists := pairs[msg.ID] + if !exists { + lrs = &logRequestResponse{} + pairs[msg.ID] = lrs + } + if msg.Req != nil { + if lrs.Request != nil { + t.Log("Line ", line, ": duplicate request with id ", msg.ID) + continue + } + lrs.Request = msg.Req + } else if msg.Res != nil { + if lrs.Response != nil { + t.Log("Line ", line, ": duplicate response with id ", msg.ID) + continue + } + lrs.Response = msg.Res + lrs.LogElapsedTime = msg.Et + } + if lrs.Request != nil && lrs.Response != nil { + verifyMessage(t, ws, msg.ID, lrs, stats) + delete(pairs, msg.ID) + } + } + var keys []string + for k := range stats { + keys = append(keys, k) + } + failures := 0 + sort.Strings(keys) + for _, k := range keys { + s := stats[k] + failures += s.Count - s.SuccessCount + t.Log("Method:", k, "\tCount:", s.Count, "\tSuccess:", s.SuccessCount, "\tTime log:", s.TotalLogNs, "\tTime BB:", s.TotalBlockbookNs) + } + if failures != 0 { + t.Error("Number of failures:", failures) + } +}