From 76954f1969159ded2bccf8325f3efbeb855ee78e Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Thu, 24 Oct 2024 20:02:52 +0000 Subject: [PATCH 01/19] success, fail, perf load test --- cmd/tradeclient/internal/console.go | 188 +++++++++++++++++---------- cmd/tradeclient/loadtest/README.md | 32 +++++ cmd/tradeclient/loadtest/loadtest.go | 112 ++++++++++++++++ cmd/tradeclient/tradeclient.go | 119 ++++++++++++++++- go.mod | 2 +- 5 files changed, 374 insertions(+), 79 deletions(-) create mode 100644 cmd/tradeclient/loadtest/README.md create mode 100644 cmd/tradeclient/loadtest/loadtest.go diff --git a/cmd/tradeclient/internal/console.go b/cmd/tradeclient/internal/console.go index 8db8de1..5c85dcd 100644 --- a/cmd/tradeclient/internal/console.go +++ b/cmd/tradeclient/internal/console.go @@ -18,6 +18,7 @@ package internal import ( "bufio" "fmt" + "math/rand" "time" "github.com/quickfixgo/enum" @@ -91,8 +92,9 @@ func QueryAction() (string, error) { fmt.Println() fmt.Println("1) Enter Order") fmt.Println("2) Cancel Order") - fmt.Println("3) Request Market Test") - fmt.Println("4) Quit") + fmt.Println("3) Request Market Data") + fmt.Println("4) Run Load Test") + fmt.Println("5) Quit") // Updated the option for quitting fmt.Print("Action: ") scanner := bufio.NewScanner(os.Stdin) scanner.Scan() @@ -100,36 +102,39 @@ func QueryAction() (string, error) { } func queryVersion() (string, error) { - fmt.Println() - fmt.Println("1) FIX.4.0") - fmt.Println("2) FIX.4.1") - fmt.Println("3) FIX.4.2") - fmt.Println("4) FIX.4.3") - fmt.Println("5) FIX.4.4") - fmt.Println("6) FIXT.1.1 (FIX.5.0)") - fmt.Print("BeginString: ") - - scanner := bufio.NewScanner(os.Stdin) - if !scanner.Scan() { - return "", scanner.Err() - } + /* + fmt.Println() + fmt.Println("1) FIX.4.0") + fmt.Println("2) FIX.4.1") + fmt.Println("3) FIX.4.2") + fmt.Println("4) FIX.4.3") + fmt.Println("5) FIX.4.4") + fmt.Println("6) FIXT.1.1 (FIX.5.0)") + fmt.Print("BeginString: ") + + scanner := bufio.NewScanner(os.Stdin) + if !scanner.Scan() { + return "", scanner.Err() + } - switch scanner.Text() { - case "1": - return quickfix.BeginStringFIX40, nil - case "2": - return quickfix.BeginStringFIX41, nil - case "3": - return quickfix.BeginStringFIX42, nil - case "4": - return quickfix.BeginStringFIX43, nil - case "5": - return quickfix.BeginStringFIX44, nil - case "6": - return quickfix.BeginStringFIXT11, nil - } + switch scanner.Text() { + case "1": + return quickfix.BeginStringFIX40, nil + case "2": + return quickfix.BeginStringFIX41, nil + case "3": + return quickfix.BeginStringFIX42, nil + case "4": + return quickfix.BeginStringFIX43, nil + case "5": + return quickfix.BeginStringFIX44, nil + case "6": + return quickfix.BeginStringFIXT11, nil + } - return "", fmt.Errorf("unknown BeginString choice: %v", scanner.Text()) + return "", fmt.Errorf("unknown BeginString choice: %v", scanner.Text()) + */ + return quickfix.BeginStringFIX44, nil } func queryClOrdID() field.ClOrdIDField { @@ -245,13 +250,24 @@ type header interface { } func queryHeader(h header) { - h.Set(querySenderCompID()) - h.Set(queryTargetCompID()) - if ok := queryConfirm("Use a TargetSubID"); !ok { - return - } + /* + h.Set(querySenderCompID()) + h.Set(queryTargetCompID()) + if ok := queryConfirm("Use a TargetSubID"); !ok { + return + } - h.Set(queryTargetSubID()) + h.Set(queryTargetSubID()) + */ + //h.Set(field.NewSenderCompID(senderCompId)) + //h.Set(field.NewTargetCompID(targetCompId)) + h.Set(field.NewSenderCompID("CLIENT1_Order")) + h.Set(field.NewTargetCompID("ANCHOR")) +} + +func setHeader(h header, senderCompId string, targetCompId string) { + h.Set(field.NewSenderCompID(senderCompId)) + h.Set(field.NewTargetCompID(targetCompId)) } func queryNewOrderSingle40() fix40nos.NewOrderSingle { @@ -269,7 +285,7 @@ func queryNewOrderSingle40() fix40nos.NewOrderSingle { } order.Set(queryTimeInForce()) - queryHeader(order.Header.Header) + queryHeader(order.Header) return order } @@ -340,26 +356,32 @@ func queryNewOrderSingle43() (msg *quickfix.Message) { return } -func queryNewOrderSingle44() (msg *quickfix.Message) { - var ordType field.OrdTypeField - order := fix44nos.New(queryClOrdID(), querySide(), field.NewTransactTime(time.Now()), queryOrdType(&ordType)) +func queryNewOrderSingle44(senderCompId, targetCompId, side, symbol, qty, price string) (msg *quickfix.Message) { + var ordType = enum.OrdType_LIMIT + order := fix44nos.New(field.NewClOrdID(strconv.Itoa(time.Now().Nanosecond())), + field.NewSide(enum.Side(side)), + field.NewTransactTime(time.Now()), + field.NewOrdType(ordType)) order.SetHandlInst("1") - order.Set(querySymbol()) - order.Set(queryOrderQty()) - - switch ordType.Value() { - case enum.OrdType_LIMIT, enum.OrdType_STOP_LIMIT: - order.Set(queryPrice()) - } - - switch ordType.Value() { - case enum.OrdType_STOP, enum.OrdType_STOP_LIMIT: + order.Set(field.NewSymbol(symbol)) + ordqty, _ := decimal.NewFromString(qty) + order.Set(field.NewOrderQty(ordqty, 4)) + order.Set(field.NewTimeInForce(enum.TimeInForce_FILL_OR_KILL)) + + switch ordType { + case enum.OrdType_LIMIT: + px, _ := decimal.NewFromString(price) + order.Set(field.NewPrice(px, 5)) + case enum.OrdType_STOP_LIMIT: + px, _ := decimal.NewFromString("3000.00") + order.Set(field.NewPrice(px, 5)) order.Set(queryStopPx()) + case enum.OrdType_STOP: + } - order.Set(queryTimeInForce()) msg = order.ToMessage() - queryHeader(&msg.Header) + setHeader(&msg.Header, senderCompId, targetCompId) return } @@ -475,21 +497,25 @@ func queryMarketDataRequest43() fix43mdr.MarketDataRequest { return request } -func queryMarketDataRequest44() fix44mdr.MarketDataRequest { - request := fix44mdr.New(field.NewMDReqID("MARKETDATAID"), - field.NewSubscriptionRequestType(enum.SubscriptionRequestType_SNAPSHOT), +func queryMarketDataRequest44(senderCompId, targetCompId string) fix44mdr.MarketDataRequest { + request := fix44mdr.New(field.NewMDReqID(strconv.Itoa(time.Now().Nanosecond())), + field.NewSubscriptionRequestType(enum.SubscriptionRequestType_SNAPSHOT_PLUS_UPDATES), field.NewMarketDepth(0), ) + request.SetMDUpdateType(enum.MDUpdateType_INCREMENTAL_REFRESH) entryTypes := fix44mdr.NewNoMDEntryTypesRepeatingGroup() + //noOfMDEntryTypes := entryTypes.Add() entryTypes.Add().SetMDEntryType(enum.MDEntryType_BID) + entryTypes.Add().SetMDEntryType(enum.MDEntryType_OFFER) request.SetNoMDEntryTypes(entryTypes) relatedSym := fix44mdr.NewNoRelatedSymRepeatingGroup() - relatedSym.Add().SetSymbol("LNUX") + // relatedSym.Add().SetSymbol("ETH-USD") + relatedSym.Add().SetSymbol("BTC-USD") request.SetNoRelatedSym(relatedSym) - queryHeader(request.Header) + setHeader(request.Header, senderCompId, targetCompId) return request } @@ -511,18 +537,19 @@ func queryMarketDataRequest50() fix50mdr.MarketDataRequest { return request } -func QueryEnterOrder() (err error) { +func QueryEnterOrder(senderCompId, targetCompId string) (err error) { defer func() { if e := recover(); e != nil { err = e.(error) } }() - var beginString string - beginString, err = queryVersion() - if err != nil { - return err - } + var beginString string = "FIX.4.4" + /* + beginString, err = queryVersion() + if err != nil { + return err + }*/ var order quickfix.Messagable switch beginString { @@ -539,8 +566,26 @@ func QueryEnterOrder() (err error) { order = queryNewOrderSingle43() case quickfix.BeginStringFIX44: - order = queryNewOrderSingle44() + symbol := "BTC-USD" + price := "60000" + var side, qty string + + midsize := 0.01 + for i := range 1 { + if i%2 == 0 { + side = "2" + qty = fmt.Sprintf("%f", midsize+float64(rand.Intn(10))/1000.0) + } else { + side = "2" + qty = fmt.Sprintf("%f", midsize-float64(rand.Intn(10))/1000.0) + } + //fmt.Printf("qty=%v,symbol=%s\n", qty,symbol) + order = queryNewOrderSingle44(senderCompId, targetCompId, side, symbol, qty, price) + quickfix.Send(order) + time.Sleep(1000 * time.Millisecond) + } + return case quickfix.BeginStringFIXT11: order = queryNewOrderSingle50() } @@ -589,7 +634,7 @@ func QueryCancelOrder() (err error) { return } -func QueryMarketDataRequest() error { +func QueryMarketDataRequest(senderCompId, targetCompId string) error { beginString, err := queryVersion() if err != nil { return err @@ -604,18 +649,19 @@ func QueryMarketDataRequest() error { req = queryMarketDataRequest43() case quickfix.BeginStringFIX44: - req = queryMarketDataRequest44() + req = queryMarketDataRequest44(senderCompId, targetCompId) case quickfix.BeginStringFIXT11: req = queryMarketDataRequest50() default: - return fmt.Errorf("No test for version %v", beginString) + return fmt.Errorf("no test for version %v", beginString) } - if queryConfirm("Send MarketDataRequest") { - return quickfix.Send(req) - } + //if queryConfirm("Send MarketDataRequest") { + fmt.Println("quickfix.Send(req)=>") + return quickfix.Send(req) + //} - return nil + //return nil } diff --git a/cmd/tradeclient/loadtest/README.md b/cmd/tradeclient/loadtest/README.md new file mode 100644 index 0000000..bb1e74e --- /dev/null +++ b/cmd/tradeclient/loadtest/README.md @@ -0,0 +1,32 @@ + +# Load Test for TradeClient + +## Overview +This load test evaluates the performance of the TradeClient by simulating the submission of multiple orders in a specified time frame. The primary focus is to measure the success/failure percentage of the orders processed, while performance analysis will be derived from log files. + +## Types of Tests Running +- **Load Test**: Simulates the submission of multiple orders to evaluate the success and failure rates. +- **Performance Metrics**: Uses existing logs to analyze response times and latencies for orders processed. + +## How to Run the Tests +1. **Build the TradeClient**: + - Use one of the following commands: + ```make build``` + or + ```make clean build``` + +2. **Run the TradeClient**: + - Execute the following command: + ```./bin/qf tradeclient``` + +3. **Select Load Test**: + - You will be prompted with the following options: + 1) Enter Order + 2) Cancel Order + 3) Request Market Data + 4) Run Load Test + 5) Quit + - Choose **4** to initiate the load test. + +## Outputs +- The results of the load test, including success and failure rates, will be logged to `output.log`. diff --git a/cmd/tradeclient/loadtest/loadtest.go b/cmd/tradeclient/loadtest/loadtest.go new file mode 100644 index 0000000..fb087f3 --- /dev/null +++ b/cmd/tradeclient/loadtest/loadtest.go @@ -0,0 +1,112 @@ +package loadtest + +import ( + "fmt" + "log" + "os" + "sync" + "time" + + "github.com/quickfixgo/examples/cmd/tradeclient/internal" +) + +// LoadTestConfig holds configuration for the load test. +type LoadTestConfig struct { + OrdersPerSecond int + TotalOrders int + SenderCompID string + TargetCompID string +} + +// OrderTimestamp holds the sent, response, and local arrival time of an order. +type OrderTimestamp struct { + SentTime time.Time + ResponseTime time.Time + LocalArrival time.Time // Time when the response is received + Latency time.Duration // Latency calculated +} + +// RunLoadTest runs the load test based on the provided configuration. +func RunLoadTest(cfg LoadTestConfig) { + outputFile, err := os.OpenFile("output.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666) + if err != nil { + log.Fatalf("error opening output.log: %v", err) + } + defer outputFile.Close() + + var wg sync.WaitGroup + successCount := 0 + failureCount := 0 + timestamps := make([]OrderTimestamp, 0, cfg.TotalOrders) + + startTime := time.Now() + + // Launch goroutines to send orders + for i := 0; i < cfg.TotalOrders; i++ { + wg.Add(1) + go func(orderID int) { + defer wg.Done() + sentTime := time.Now() + err := internal.QueryEnterOrder(cfg.SenderCompID, cfg.TargetCompID) + responseTime := time.Now() + + // Simulate local arrival time (could be the same as response time for simplicity) + localArrival := responseTime + + // Calculate latency + latency := localArrival.Sub(sentTime) + + timestamps = append(timestamps, OrderTimestamp{ + SentTime: sentTime, + ResponseTime: responseTime, + LocalArrival: localArrival, + Latency: latency, + }) + + if err != nil { + failureCount++ + return + } + successCount++ + }(i) + + time.Sleep(time.Second / time.Duration(cfg.OrdersPerSecond)) + } + + // Wait for all goroutines to finish + wg.Wait() + totalTime := time.Since(startTime) + + // Log results only after all orders are processed + successRate := float64(successCount) / float64(cfg.TotalOrders) * 100 + failRate := float64(failureCount) / float64(cfg.TotalOrders) * 100 + + // Prepare detailed results for logging + resultSummary := fmt.Sprintf("Sent %d orders in %s\nSuccess Rate: %.2f%%\nFailure Rate: %.2f%%\n", + cfg.TotalOrders, totalTime, successRate, failRate) + + // Log the results to output.log + if _, err := outputFile.WriteString(resultSummary); err != nil { + log.Fatalf("error writing to output.log: %v", err) + } + + // Print only a simple message to the console + fmt.Println("Load test complete.") + + // Analyze the timestamps and log intervals + for i, ts := range timestamps { + if i > 0 { + interval := ts.ResponseTime.Sub(timestamps[i-1].ResponseTime) + if _, err := outputFile.WriteString(fmt.Sprintf("Order %d - Interval from previous response: %v\n", i+1, interval)); err != nil { + log.Fatalf("error writing to output.log: %v", err) + } + } + responseTime := ts.ResponseTime.Sub(ts.SentTime) + if _, err := outputFile.WriteString(fmt.Sprintf("Order %d - Time taken to process: %v\n", i+1, responseTime)); err != nil { + log.Fatalf("error writing to output.log: %v", err) + } + if _, err := outputFile.WriteString(fmt.Sprintf("Order %d - Latency: %v\n", i+1, ts.Latency)); err != nil { + log.Fatalf("error writing to output.log: %v", err) + } + } +} diff --git a/cmd/tradeclient/tradeclient.go b/cmd/tradeclient/tradeclient.go index 9f17d53..74835a6 100644 --- a/cmd/tradeclient/tradeclient.go +++ b/cmd/tradeclient/tradeclient.go @@ -17,16 +17,21 @@ package tradeclient import ( "bytes" + "crypto/ed25519" + "encoding/hex" "fmt" "io" "os" "path" + "strconv" "github.com/quickfixgo/examples/cmd/tradeclient/internal" + "github.com/quickfixgo/examples/cmd/tradeclient/loadtest" "github.com/quickfixgo/examples/cmd/utils" - "github.com/spf13/cobra" - + "github.com/quickfixgo/field" + "github.com/quickfixgo/fix44/logon" "github.com/quickfixgo/quickfix" + "github.com/spf13/cobra" ) // TradeClient implements the quickfix.Application interface @@ -34,21 +39,90 @@ type TradeClient struct { } // OnCreate implemented as part of Application interface -func (e TradeClient) OnCreate(sessionID quickfix.SessionID) {} +func (e TradeClient) OnCreate(sessionID quickfix.SessionID) { + fmt.Printf("initiator session Id: %s\n", sessionID) +} // OnLogon implemented as part of Application interface func (e TradeClient) OnLogon(sessionID quickfix.SessionID) {} // OnLogout implemented as part of Application interface -func (e TradeClient) OnLogout(sessionID quickfix.SessionID) {} +func (e TradeClient) OnLogout(sessionID quickfix.SessionID) { + fmt.Printf("OnLogout: %s\n", sessionID) +} // FromAdmin implemented as part of Application interface func (e TradeClient) FromAdmin(msg *quickfix.Message, sessionID quickfix.SessionID) (reject quickfix.MessageRejectError) { + utils.PrintInfo(fmt.Sprintf("FromAdmin: %s\n", msg.String())) return nil } +const ( + FIX_SEP = "\u0001" + + Publickey = "c" + + Privatekey = "b" + + APIKey = "a" +) + // ToAdmin implemented as part of Application interface -func (e TradeClient) ToAdmin(msg *quickfix.Message, sessionID quickfix.SessionID) {} +func (e TradeClient) ToAdmin(msg *quickfix.Message, sessionID quickfix.SessionID) { + msgType, err := msg.MsgType() + if err != nil { + println("wrong message type") + } + + if msgType == "A" { + msg.Body.Set(field.NewPassword(APIKey)) + signature, err := e.sign(msg) + if err != nil { + println("error in signing the message") + } + msg.Body.Set(field.NewRawData(signature)) + } + + utils.PrintInfo(fmt.Sprintf("ToAdmin: %s", msg.String())) +} + +func (e TradeClient) sign(logonmsg *quickfix.Message) (string, error) { + msg := logon.FromMessage(logonmsg) + + sendingTime, err := msg.GetSendingTime() + if err != nil { + println("error in getting SendingTime from the logon") + return "", &quickfix.RejectLogon{Text: "invalid SendingTime"} + } + + seqNum, err := msg.GetMsgSeqNum() + if err != nil { + println("error in getting MsgSeqNum from the logon") + return "", &quickfix.RejectLogon{Text: "invalid MsgSeqNum"} + } + + senderCompID, err := msg.GetSenderCompID() + if err != nil { + println("error in getting SenderCompID from the logon") + return "", &quickfix.RejectLogon{Text: "invalid SenderCompID"} + } + + targetCompID, err := msg.GetTargetCompID() + if err != nil { + println("error in getting TargetCompID from the logon") + return "", &quickfix.RejectLogon{Text: "invalid TargetCompID"} + } + + msgToSign := sendingTime.Format("20060102-15:04:05.000") + FIX_SEP + + strconv.Itoa(seqNum) + FIX_SEP + + senderCompID + FIX_SEP + + targetCompID + + privateKeyBytes, _ := hex.DecodeString(Privatekey) + ed25519PrivateKey := ed25519.PrivateKey(privateKeyBytes) + signature := ed25519.Sign(ed25519PrivateKey, []byte(msgToSign)) + return hex.EncodeToString(signature), nil +} // ToApp implemented as part of Application interface func (e TradeClient) ToApp(msg *quickfix.Message, sessionID quickfix.SessionID) (err error) { @@ -144,15 +218,46 @@ Loop: switch action { case "1": - err = internal.QueryEnterOrder() + err = internal.QueryEnterOrder("CUST2_Order", "ANCHORAGE") case "2": err = internal.QueryCancelOrder() case "3": - err = internal.QueryMarketDataRequest() + err = internal.QueryMarketDataRequest("CUST2_Marketdata", "ANCHORAGE") case "4": + var ordersPerSecond int + var totalOrders int + + // Prompt the user for orders per second + fmt.Print("Enter orders per second: ") + _, err := fmt.Scanf("%d", &ordersPerSecond) + if err != nil { + utils.PrintBad("Invalid input for orders per second") + break + } + + // Prompt the user for total number of orders + fmt.Print("Enter total number of orders: ") + _, err = fmt.Scanf("%d", &totalOrders) + if err != nil { + utils.PrintBad("Invalid input for total orders") + break + } + + // Create load test configuration + loadTestConfig := loadtest.LoadTestConfig{ + OrdersPerSecond: ordersPerSecond, + TotalOrders: totalOrders, + SenderCompID: "CUST2_Order", + TargetCompID: "ANCHORAGE", + } + + // Run the load test + loadtest.RunLoadTest(loadTestConfig) + + case "5": //quit break Loop diff --git a/go.mod b/go.mod index 1cfecdc..cf4800b 100644 --- a/go.mod +++ b/go.mod @@ -1,6 +1,6 @@ module github.com/quickfixgo/examples -go 1.21 +go 1.23.1 require ( github.com/fatih/color v1.16.0 From ec8eb5dff0f2e8311da9a73cca62d38ff7015a78 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Mon, 28 Oct 2024 12:31:00 +0000 Subject: [PATCH 02/19] load test wip --- cmd/tradeclient/tradeclient.go | 6 ++--- config/tradeclient.cfg | 41 ++++++++++++++++++++++------------ 2 files changed, 30 insertions(+), 17 deletions(-) diff --git a/cmd/tradeclient/tradeclient.go b/cmd/tradeclient/tradeclient.go index 74835a6..9bb72e6 100644 --- a/cmd/tradeclient/tradeclient.go +++ b/cmd/tradeclient/tradeclient.go @@ -60,11 +60,11 @@ func (e TradeClient) FromAdmin(msg *quickfix.Message, sessionID quickfix.Session const ( FIX_SEP = "\u0001" - Publickey = "c" + Publickey = "Publickey" - Privatekey = "b" + Privatekey = "Privatekey" - APIKey = "a" + APIKey = "APIKey" ) // ToAdmin implemented as part of Application interface diff --git a/config/tradeclient.cfg b/config/tradeclient.cfg index 52737fc..38bf9ab 100644 --- a/config/tradeclient.cfg +++ b/config/tradeclient.cfg @@ -1,27 +1,40 @@ [DEFAULT] -SocketConnectHost=127.0.0.1 -SocketConnectPort=5001 +SocketConnectHost=localhost HeartBtInt=30 -SenderCompID=TW -TargetCompID=ISLD ResetOnLogon=Y FileLogPath=tmp +#SocketPrivateKeyFile=config/client0.key +#SocketCertificateFile=config/client0.crt +#SocketCAFile=config/ca.crt -[SESSION] -BeginString=FIX.4.0 +#[SESSION] +#BeginString=FIX.4.0 -[SESSION] -BeginString=FIX.4.1 +#[SESSION] +#BeginString=FIX.4.1 -[SESSION] -BeginString=FIX.4.2 +#[SESSION] +#BeginString=FIX.4.2 -[SESSION] -BeginString=FIX.4.3 +#[SESSION] +#BeginString=FIX.4.3 [SESSION] +SocketConnectPort=5002 BeginString=FIX.4.4 +#SenderCompID=CUST1_Marketdata +SenderCompID=CUST2_Marketdata +#SenderCompID=CLIENT1_MD +TargetCompID=ANCHORAGE [SESSION] -BeginString=FIXT.1.1 -DefaultApplVerID=7 +SocketConnectPort=5001 +BeginString=FIX.4.4 +#SenderCompID=CUST1_Order +SenderCompID=CUST2_Order +#SenderCompID=CLIENT1_Order +TargetCompID=ANCHORAGE + +#[SESSION] +#BeginString=FIXT.1.1 +#DefaultApplVerID=7 From 909530309d52a7e49c456a7fcbba4e829e00cbc6 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Mon, 28 Oct 2024 14:13:30 +0000 Subject: [PATCH 03/19] reading metrics --- cmd/cmd.go | 2 + cmd/readmetrics/README.md | 47 +++++++++++ cmd/readmetrics/readmetrics.go | 117 +++++++++++++++++++++++++++ cmd/tradeclient/loadtest/loadtest.go | 66 ++++++++------- 4 files changed, 202 insertions(+), 30 deletions(-) create mode 100644 cmd/readmetrics/README.md create mode 100644 cmd/readmetrics/readmetrics.go diff --git a/cmd/cmd.go b/cmd/cmd.go index 24f30be..91f1204 100644 --- a/cmd/cmd.go +++ b/cmd/cmd.go @@ -18,6 +18,7 @@ package cmd import ( "github.com/quickfixgo/examples/cmd/executor" "github.com/quickfixgo/examples/cmd/ordermatch" + "github.com/quickfixgo/examples/cmd/readmetrics" "github.com/quickfixgo/examples/cmd/tradeclient" "github.com/quickfixgo/examples/version" "github.com/spf13/cobra" @@ -45,6 +46,7 @@ func Execute() error { c.AddCommand(executor.Cmd) c.AddCommand(ordermatch.Cmd) c.AddCommand(tradeclient.Cmd) + c.AddCommand(readmetrics.Cmd) // Add readmetrics command c.Flags().BoolVarP(&versionF, "version", "v", false, "show the version and exit") return c.Execute() } diff --git a/cmd/readmetrics/README.md b/cmd/readmetrics/README.md new file mode 100644 index 0000000..b637baa --- /dev/null +++ b/cmd/readmetrics/README.md @@ -0,0 +1,47 @@ +# ReadMetrics + +The `readmetrics` command is a tool for reading and processing metrics from a FIX log file. It calculates the latency and intervals between messages and logs them to a separate metrics file for analysis. + +## Features + +- Reads FIX log files and extracts relevant timestamps. +- Calculates latency and interval in milliseconds. +- Outputs metrics to a `metrics.log` file. + +## Usage + +To use the `readmetrics` command, run the following command in your terminal: + +``` +./bin/qf readmetrics +``` + +Replace `` with the path to your FIX log file. + +## Output + +The results will be written to a file named `metrics.log` in the current directory. The log will contain entries formatted as follows: + +``` +Message 1: Interval = X.XXXms, Latency = Y.YYYms +``` + +Where `X.XXX` is the interval between messages, and `Y.YYY` is the calculated latency. + +## Example + +Assuming you have a FIX log file named `example.log`, you can run: + +``` +./bin/qf readmetrics example.log +``` + +After execution, you can check the contents of `metrics.log`: + +You should see output similar to: + +``` +Message 1: Interval = 1.000ms, Latency = 0.647ms +Message 2: Interval = 1.000ms, Latency = 0.685ms +... +``` \ No newline at end of file diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go new file mode 100644 index 0000000..c8314e9 --- /dev/null +++ b/cmd/readmetrics/readmetrics.go @@ -0,0 +1,117 @@ +// readmetrics.go +// Package readmetrics provides functionality to read and process metrics from a FIX log file. + +package readmetrics + +import ( + "bufio" + "fmt" + "os" + "path/filepath" + "strings" + "time" + + "github.com/spf13/cobra" +) + +// Define the command +var Cmd = &cobra.Command{ + Use: "readmetrics [file]", + Short: "Read metrics from a FIX log file", + Args: cobra.ExactArgs(1), + RunE: execute, +} + +// Struct to hold timestamps +type TestTS struct { + LTime time.Time + TTime time.Time +} + +const ( + LTimeLayout = "15:04:05.999999" + TTimeLayout = "15:04:05.999" +) + +// Execute the readmetrics command +func execute(cmd *cobra.Command, args []string) error { + testFileArg := args[0] + + // Create the metrics log file + metricsLogFile := "metrics.log" + metricsLog, err := os.Create(metricsLogFile) + if err != nil { + return fmt.Errorf("error creating metrics log file: %v", err) + } + defer metricsLog.Close() + + // Open the input log file + dir, err := os.Getwd() + if err != nil { + return fmt.Errorf("error getting working directory: %v", err) + } + + testFile, err := os.Open(filepath.Join(dir, testFileArg)) + if err != nil { + return fmt.Errorf("error opening %v: %v", testFileArg, err) + } + defer testFile.Close() + + // Create a scanner to read the file + scanner := bufio.NewScanner(testFile) + + // Read the file line by line and process the timestamps + times := make([]TestTS, 0) + for scanner.Scan() { + line := scanner.Text() + if strings.Contains(line, "35=D") { // Modify this condition based on your message type + sub1 := strings.Split(line, " ") + if len(sub1) > 2 { + localTime := sub1[1] + parsedLTime, err := time.Parse(LTimeLayout, localTime) + if err != nil { + return fmt.Errorf("error parsing local time: %v", err) + } + + sub2 := strings.Split(sub1[2], "\u0001") + if len(sub2) > 5 { + if strings.Contains(sub2[5], "52=") { + sub3 := strings.Split(sub2[5], "-") + if len(sub3) > 1 { + talosTime := sub3[1] + parsedTTime, err := time.Parse(TTimeLayout, talosTime) + if err != nil { + return fmt.Errorf("error parsing talos time: %v", err) + } + + testTS := TestTS{ + LTime: parsedLTime, + TTime: parsedTTime, + } + times = append(times, testTS) + } + } + } + } + } + } + + // Check for errors during scanning + if err := scanner.Err(); err != nil { + return fmt.Errorf("error reading file: %v", err) + } + + // Calculate latencies and write to the metrics log + for i := 1; i < len(times); i++ { + t := times[i] + t0 := times[i-1] + + // Convert latency and interval to milliseconds + latency := float64(t.LTime.Sub(t.TTime)) / float64(time.Millisecond) + interval := float64(t.TTime.Sub(t0.TTime)) / float64(time.Millisecond) + fmt.Fprintf(metricsLog, "Message %d: Interval = %.3fms, Latency = %.3fms\n", i, interval, latency) + } + + fmt.Println("Latency metrics logged to metrics.log") + return nil +} diff --git a/cmd/tradeclient/loadtest/loadtest.go b/cmd/tradeclient/loadtest/loadtest.go index fb087f3..13ee4cc 100644 --- a/cmd/tradeclient/loadtest/loadtest.go +++ b/cmd/tradeclient/loadtest/loadtest.go @@ -1,6 +1,7 @@ package loadtest import ( + "encoding/json" "fmt" "log" "os" @@ -20,10 +21,12 @@ type LoadTestConfig struct { // OrderTimestamp holds the sent, response, and local arrival time of an order. type OrderTimestamp struct { - SentTime time.Time - ResponseTime time.Time - LocalArrival time.Time // Time when the response is received - Latency time.Duration // Latency calculated + SentTime time.Time + ResponseTime time.Time + LocalArrival time.Time // Time when the response is received + Latency time.Duration // Latency calculated + Status string // "success" or "failure" + ErrorMessage string // Detailed error message in case of failure } // RunLoadTest runs the load test based on the provided configuration. @@ -35,6 +38,7 @@ func RunLoadTest(cfg LoadTestConfig) { defer outputFile.Close() var wg sync.WaitGroup + var mu sync.Mutex // Mutex for safely accessing shared resources successCount := 0 failureCount := 0 timestamps := make([]OrderTimestamp, 0, cfg.TotalOrders) @@ -55,19 +59,33 @@ func RunLoadTest(cfg LoadTestConfig) { // Calculate latency latency := localArrival.Sub(sentTime) + status := "success" + errorMessage := "" + // Log failure details if error occurs + if err != nil { + status = "failure" + errorMessage = err.Error() + mu.Lock() + failureCount++ + mu.Unlock() + } else { + mu.Lock() + successCount++ + mu.Unlock() + } + + // Append order timestamp with status + mu.Lock() timestamps = append(timestamps, OrderTimestamp{ SentTime: sentTime, ResponseTime: responseTime, LocalArrival: localArrival, Latency: latency, + Status: status, + ErrorMessage: errorMessage, }) - - if err != nil { - failureCount++ - return - } - successCount++ + mu.Unlock() }(i) time.Sleep(time.Second / time.Duration(cfg.OrdersPerSecond)) @@ -77,36 +95,24 @@ func RunLoadTest(cfg LoadTestConfig) { wg.Wait() totalTime := time.Since(startTime) - // Log results only after all orders are processed + // Calculate success and failure rates successRate := float64(successCount) / float64(cfg.TotalOrders) * 100 failRate := float64(failureCount) / float64(cfg.TotalOrders) * 100 - // Prepare detailed results for logging + // Prepare result summary resultSummary := fmt.Sprintf("Sent %d orders in %s\nSuccess Rate: %.2f%%\nFailure Rate: %.2f%%\n", cfg.TotalOrders, totalTime, successRate, failRate) - - // Log the results to output.log if _, err := outputFile.WriteString(resultSummary); err != nil { log.Fatalf("error writing to output.log: %v", err) } - // Print only a simple message to the console - fmt.Println("Load test complete.") - - // Analyze the timestamps and log intervals - for i, ts := range timestamps { - if i > 0 { - interval := ts.ResponseTime.Sub(timestamps[i-1].ResponseTime) - if _, err := outputFile.WriteString(fmt.Sprintf("Order %d - Interval from previous response: %v\n", i+1, interval)); err != nil { - log.Fatalf("error writing to output.log: %v", err) - } - } - responseTime := ts.ResponseTime.Sub(ts.SentTime) - if _, err := outputFile.WriteString(fmt.Sprintf("Order %d - Time taken to process: %v\n", i+1, responseTime)); err != nil { - log.Fatalf("error writing to output.log: %v", err) - } - if _, err := outputFile.WriteString(fmt.Sprintf("Order %d - Latency: %v\n", i+1, ts.Latency)); err != nil { + // Log detailed results in JSON format for easy parsing + for _, ts := range timestamps { + tsJson, _ := json.Marshal(ts) + if _, err := outputFile.WriteString(fmt.Sprintf("%s\n", tsJson)); err != nil { log.Fatalf("error writing to output.log: %v", err) } } + + fmt.Println("Load test complete.") } From a96c416fcb58fd7e185294152da40b619a90b6a1 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Mon, 28 Oct 2024 14:36:54 +0000 Subject: [PATCH 04/19] read metrics after loadtest --- Makefile | 4 +++- cmd/cmd.go | 2 -- cmd/readmetrics/readmetrics.go | 19 ++----------------- cmd/tradeclient/loadtest/loadtest.go | 20 ++++++++++++++------ cmd/tradeclient/tradeclient.go | 6 +++--- 5 files changed, 22 insertions(+), 29 deletions(-) diff --git a/Makefile b/Makefile index ac2c5bc..26b1aab 100644 --- a/Makefile +++ b/Makefile @@ -15,6 +15,8 @@ clean: rm -rf ./bin rm -rf ./tmp rm -rf ./dist + rm -f output.log + rm -f metrics.log # Commands for docker images. # ---------------------------- @@ -22,4 +24,4 @@ build-linux: GOOS=linux GOARCH=amd64 go build -v -o ./bin/qf . build-docker: clean build-linux - docker build -t quickfixgo/qf:latest . \ No newline at end of file + docker build -t quickfixgo/qf:latest . diff --git a/cmd/cmd.go b/cmd/cmd.go index 91f1204..24f30be 100644 --- a/cmd/cmd.go +++ b/cmd/cmd.go @@ -18,7 +18,6 @@ package cmd import ( "github.com/quickfixgo/examples/cmd/executor" "github.com/quickfixgo/examples/cmd/ordermatch" - "github.com/quickfixgo/examples/cmd/readmetrics" "github.com/quickfixgo/examples/cmd/tradeclient" "github.com/quickfixgo/examples/version" "github.com/spf13/cobra" @@ -46,7 +45,6 @@ func Execute() error { c.AddCommand(executor.Cmd) c.AddCommand(ordermatch.Cmd) c.AddCommand(tradeclient.Cmd) - c.AddCommand(readmetrics.Cmd) // Add readmetrics command c.Flags().BoolVarP(&versionF, "version", "v", false, "show the version and exit") return c.Execute() } diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index c8314e9..bc61524 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -1,6 +1,3 @@ -// readmetrics.go -// Package readmetrics provides functionality to read and process metrics from a FIX log file. - package readmetrics import ( @@ -10,18 +7,8 @@ import ( "path/filepath" "strings" "time" - - "github.com/spf13/cobra" ) -// Define the command -var Cmd = &cobra.Command{ - Use: "readmetrics [file]", - Short: "Read metrics from a FIX log file", - Args: cobra.ExactArgs(1), - RunE: execute, -} - // Struct to hold timestamps type TestTS struct { LTime time.Time @@ -33,10 +20,8 @@ const ( TTimeLayout = "15:04:05.999" ) -// Execute the readmetrics command -func execute(cmd *cobra.Command, args []string) error { - testFileArg := args[0] - +// Execute reads metrics from a specified FIX log file. +func Execute(testFileArg string) error { // Create the metrics log file metricsLogFile := "metrics.log" metricsLog, err := os.Create(metricsLogFile) diff --git a/cmd/tradeclient/loadtest/loadtest.go b/cmd/tradeclient/loadtest/loadtest.go index 13ee4cc..3f4261a 100644 --- a/cmd/tradeclient/loadtest/loadtest.go +++ b/cmd/tradeclient/loadtest/loadtest.go @@ -8,6 +8,7 @@ import ( "sync" "time" + "github.com/quickfixgo/examples/cmd/readmetrics" "github.com/quickfixgo/examples/cmd/tradeclient/internal" ) @@ -21,12 +22,12 @@ type LoadTestConfig struct { // OrderTimestamp holds the sent, response, and local arrival time of an order. type OrderTimestamp struct { - SentTime time.Time - ResponseTime time.Time - LocalArrival time.Time // Time when the response is received - Latency time.Duration // Latency calculated - Status string // "success" or "failure" - ErrorMessage string // Detailed error message in case of failure + SentTime time.Time + ResponseTime time.Time + LocalArrival time.Time // Time when the response is received + Latency time.Duration // Latency calculated + Status string // "success" or "failure" + ErrorMessage string // Detailed error message in case of failure } // RunLoadTest runs the load test based on the provided configuration. @@ -115,4 +116,11 @@ func RunLoadTest(cfg LoadTestConfig) { } fmt.Println("Load test complete.") + + // Call readmetrics after the load test + logFile := "tmp/FIX.4.4-CUST2_Order-ANCHORAGE.messages.current.log" // Specify the path to your log file + err = readmetrics.Execute(logFile) + if err != nil { + log.Fatalf("Error executing readmetrics: %v", err) + } } diff --git a/cmd/tradeclient/tradeclient.go b/cmd/tradeclient/tradeclient.go index 9bb72e6..648a450 100644 --- a/cmd/tradeclient/tradeclient.go +++ b/cmd/tradeclient/tradeclient.go @@ -60,11 +60,11 @@ func (e TradeClient) FromAdmin(msg *quickfix.Message, sessionID quickfix.Session const ( FIX_SEP = "\u0001" - Publickey = "Publickey" + Publickey = "2e8fea3e981fe67995454becedecdd74bfcdc346d83a3660cbf71a26e513f014" - Privatekey = "Privatekey" + Privatekey = "7284a20e7c9f033aacf6b8184eb651679e499fb29447cc9f462fbd8155c99d042e8fea3e981fe67995454becedecdd74bfcdc346d83a3660cbf71a26e513f014" - APIKey = "APIKey" + APIKey = "4044a57206f7494b8692079e720aa911f3234e4d61079db28d36a405ae3630cb" ) // ToAdmin implemented as part of Application interface From 5d3dd3b61d72d8199d1edaa703bbb15776d5fd90 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Mon, 28 Oct 2024 14:39:54 +0000 Subject: [PATCH 05/19] clean tc --- cmd/tradeclient/tradeclient.go | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/cmd/tradeclient/tradeclient.go b/cmd/tradeclient/tradeclient.go index 648a450..fb92762 100644 --- a/cmd/tradeclient/tradeclient.go +++ b/cmd/tradeclient/tradeclient.go @@ -60,11 +60,11 @@ func (e TradeClient) FromAdmin(msg *quickfix.Message, sessionID quickfix.Session const ( FIX_SEP = "\u0001" - Publickey = "2e8fea3e981fe67995454becedecdd74bfcdc346d83a3660cbf71a26e513f014" + Publickey = "a" - Privatekey = "7284a20e7c9f033aacf6b8184eb651679e499fb29447cc9f462fbd8155c99d042e8fea3e981fe67995454becedecdd74bfcdc346d83a3660cbf71a26e513f014" + Privatekey = "b" - APIKey = "4044a57206f7494b8692079e720aa911f3234e4d61079db28d36a405ae3630cb" + APIKey = "c" ) // ToAdmin implemented as part of Application interface From 42e411e8cdbb9eb7067cc4103ec7442cbe73ffd9 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Mon, 28 Oct 2024 20:51:47 +0000 Subject: [PATCH 06/19] minor change, log format --- .gitignore | 2 + cmd/readmetrics/readmetrics.go | 92 ++++++++++++++++------------ cmd/tradeclient/loadtest/loadtest.go | 12 +--- 3 files changed, 57 insertions(+), 49 deletions(-) diff --git a/.gitignore b/.gitignore index e7295d0..cbc412a 100644 --- a/.gitignore +++ b/.gitignore @@ -4,3 +4,5 @@ vendor bin .exe dist/ +metrics.log +output.log \ No newline at end of file diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index bc61524..08aac12 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -18,38 +18,37 @@ type TestTS struct { const ( LTimeLayout = "15:04:05.999999" TTimeLayout = "15:04:05.999" + LogFilePath = "tmp/FIX.4.4-CUST2_Order-ANCHORAGE.messages.current.log" ) -// Execute reads metrics from a specified FIX log file. -func Execute(testFileArg string) error { - // Create the metrics log file - metricsLogFile := "metrics.log" - metricsLog, err := os.Create(metricsLogFile) - if err != nil { - return fmt.Errorf("error creating metrics log file: %v", err) - } - defer metricsLog.Close() - - // Open the input log file +// Execute reads and processes metrics from a FIX log file +func Execute() error { + // Open the log file dir, err := os.Getwd() if err != nil { return fmt.Errorf("error getting working directory: %v", err) } - testFile, err := os.Open(filepath.Join(dir, testFileArg)) + logFile, err := os.Open(filepath.Join(dir, LogFilePath)) if err != nil { - return fmt.Errorf("error opening %v: %v", testFileArg, err) + return fmt.Errorf("error opening log file: %v", err) } - defer testFile.Close() + defer logFile.Close() - // Create a scanner to read the file - scanner := bufio.NewScanner(testFile) + // Open metrics log file + metricsLogFile := "metrics.log" + metricsLog, err := os.Create(metricsLogFile) + if err != nil { + return fmt.Errorf("error creating metrics log file: %v", err) + } + defer metricsLog.Close() - // Read the file line by line and process the timestamps + // Read log lines and parse timestamps + scanner := bufio.NewScanner(logFile) times := make([]TestTS, 0) for scanner.Scan() { line := scanner.Text() - if strings.Contains(line, "35=D") { // Modify this condition based on your message type + if strings.Contains(line, "35=D") { // Filter based on message type sub1 := strings.Split(line, " ") if len(sub1) > 2 { localTime := sub1[1] @@ -59,44 +58,57 @@ func Execute(testFileArg string) error { } sub2 := strings.Split(sub1[2], "\u0001") - if len(sub2) > 5 { - if strings.Contains(sub2[5], "52=") { - sub3 := strings.Split(sub2[5], "-") - if len(sub3) > 1 { - talosTime := sub3[1] - parsedTTime, err := time.Parse(TTimeLayout, talosTime) - if err != nil { - return fmt.Errorf("error parsing talos time: %v", err) - } - - testTS := TestTS{ - LTime: parsedLTime, - TTime: parsedTTime, - } - times = append(times, testTS) + if len(sub2) > 5 && strings.Contains(sub2[5], "52=") { + sub3 := strings.Split(sub2[5], "-") + if len(sub3) > 1 { + talosTime := sub3[1] + parsedTTime, err := time.Parse(TTimeLayout, talosTime) + if err != nil { + return fmt.Errorf("error parsing talos time: %v", err) } + + times = append(times, TestTS{LTime: parsedLTime, TTime: parsedTTime}) } } } } } - // Check for errors during scanning - if err := scanner.Err(); err != nil { - return fmt.Errorf("error reading file: %v", err) - } + // Variables for calculating averages + var totalInterval float64 + var totalLatency float64 - // Calculate latencies and write to the metrics log + // Calculate latency and throughput, then write to metrics log for i := 1; i < len(times); i++ { t := times[i] t0 := times[i-1] - // Convert latency and interval to milliseconds latency := float64(t.LTime.Sub(t.TTime)) / float64(time.Millisecond) interval := float64(t.TTime.Sub(t0.TTime)) / float64(time.Millisecond) + + totalLatency += latency + totalInterval += interval + + // Logging the individual message metrics fmt.Fprintf(metricsLog, "Message %d: Interval = %.3fms, Latency = %.3fms\n", i, interval, latency) } - fmt.Println("Latency metrics logged to metrics.log") + // Calculate averages + avgLatency := totalLatency / float64(len(times)-1) + avgInterval := totalInterval / float64(len(times)-1) + + // Throughput Measurement + totalMessages := len(times) - 1 // Total messages should exclude the first (which has no interval) + totalDuration := times[len(times)-1].TTime.Sub(times[0].TTime).Seconds() + throughput := float64(totalMessages) / totalDuration + + // Write averages and throughput to metrics log + fmt.Fprintf(metricsLog, "Average Interval = %.3fms, Average Latency = %.3fms\n", avgInterval, avgLatency) + fmt.Fprintf(metricsLog, "Throughput: %.2f messages per second\n", throughput) + + // Print overall metrics to console + fmt.Printf("Average Interval = %.3fms, Average Latency = %.3fms\n", avgInterval, avgLatency) + fmt.Printf("Throughput: %.2f messages per second\n", throughput) + fmt.Println("Latency and throughput metrics logged to metrics.log") return nil } diff --git a/cmd/tradeclient/loadtest/loadtest.go b/cmd/tradeclient/loadtest/loadtest.go index 3f4261a..76759ea 100644 --- a/cmd/tradeclient/loadtest/loadtest.go +++ b/cmd/tradeclient/loadtest/loadtest.go @@ -39,7 +39,7 @@ func RunLoadTest(cfg LoadTestConfig) { defer outputFile.Close() var wg sync.WaitGroup - var mu sync.Mutex // Mutex for safely accessing shared resources + var mu sync.Mutex successCount := 0 failureCount := 0 timestamps := make([]OrderTimestamp, 0, cfg.TotalOrders) @@ -55,15 +55,11 @@ func RunLoadTest(cfg LoadTestConfig) { err := internal.QueryEnterOrder(cfg.SenderCompID, cfg.TargetCompID) responseTime := time.Now() - // Simulate local arrival time (could be the same as response time for simplicity) localArrival := responseTime - - // Calculate latency latency := localArrival.Sub(sentTime) status := "success" errorMessage := "" - // Log failure details if error occurs if err != nil { status = "failure" errorMessage = err.Error() @@ -76,7 +72,6 @@ func RunLoadTest(cfg LoadTestConfig) { mu.Unlock() } - // Append order timestamp with status mu.Lock() timestamps = append(timestamps, OrderTimestamp{ SentTime: sentTime, @@ -107,7 +102,7 @@ func RunLoadTest(cfg LoadTestConfig) { log.Fatalf("error writing to output.log: %v", err) } - // Log detailed results in JSON format for easy parsing + // Log detailed results in JSON format for _, ts := range timestamps { tsJson, _ := json.Marshal(ts) if _, err := outputFile.WriteString(fmt.Sprintf("%s\n", tsJson)); err != nil { @@ -118,8 +113,7 @@ func RunLoadTest(cfg LoadTestConfig) { fmt.Println("Load test complete.") // Call readmetrics after the load test - logFile := "tmp/FIX.4.4-CUST2_Order-ANCHORAGE.messages.current.log" // Specify the path to your log file - err = readmetrics.Execute(logFile) + err = readmetrics.Execute() if err != nil { log.Fatalf("Error executing readmetrics: %v", err) } From 79c52d95b6d613319a34e661ba0e770b46ac505a Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Tue, 29 Oct 2024 20:09:07 +0000 Subject: [PATCH 07/19] better logging --- .gitignore | 3 +- cmd/readmetrics/readmetrics.go | 105 ++++++++++++++++++--------- cmd/tradeclient/loadtest/loadtest.go | 21 ++---- 3 files changed, 76 insertions(+), 53 deletions(-) diff --git a/.gitignore b/.gitignore index cbc412a..3a0506a 100644 --- a/.gitignore +++ b/.gitignore @@ -4,5 +4,4 @@ vendor bin .exe dist/ -metrics.log -output.log \ No newline at end of file +loadtest_metrics \ No newline at end of file diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index 08aac12..d67cd3d 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -3,27 +3,45 @@ package readmetrics import ( "bufio" "fmt" + "math" "os" "path/filepath" "strings" "time" ) -// Struct to hold timestamps type TestTS struct { LTime time.Time TTime time.Time } const ( - LTimeLayout = "15:04:05.999999" - TTimeLayout = "15:04:05.999" - LogFilePath = "tmp/FIX.4.4-CUST2_Order-ANCHORAGE.messages.current.log" + LTimeLayout = "15:04:05.999999" + TTimeLayout = "15:04:05.999" + LogFilePath = "tmp/FIX.4.4-CUST2_Order-ANCHORAGE.messages.current.log" + MetricsFolder = "loadtest_metrics" ) // Execute reads and processes metrics from a FIX log file func Execute() error { - // Open the log file + // Create metrics folder if it doesn't exist + if _, err := os.Stat(MetricsFolder); os.IsNotExist(err) { + err = os.Mkdir(MetricsFolder, 0755) + if err != nil { + return fmt.Errorf("error creating metrics folder: %v", err) + } + } + + // Define metrics log file path with a timestamp for uniqueness + timestamp := time.Now().Format("20060102_150405") + metricsLogFile := filepath.Join(MetricsFolder, fmt.Sprintf("metrics_%s.log", timestamp)) + metricsLog, err := os.Create(metricsLogFile) + if err != nil { + return fmt.Errorf("error creating metrics log file: %v", err) + } + defer metricsLog.Close() + + // Open the log file to read dir, err := os.Getwd() if err != nil { return fmt.Errorf("error getting working directory: %v", err) @@ -35,38 +53,38 @@ func Execute() error { } defer logFile.Close() - // Open metrics log file - metricsLogFile := "metrics.log" - metricsLog, err := os.Create(metricsLogFile) - if err != nil { - return fmt.Errorf("error creating metrics log file: %v", err) - } - defer metricsLog.Close() - - // Read log lines and parse timestamps + // Initialize a scanner to read the file line by line scanner := bufio.NewScanner(logFile) times := make([]TestTS, 0) + + // Process each line in the log file for scanner.Scan() { line := scanner.Text() - if strings.Contains(line, "35=D") { // Filter based on message type + + // Check for specific message type "35=D" to filter relevant messages + if strings.Contains(line, "35=D") { sub1 := strings.Split(line, " ") if len(sub1) > 2 { + // Extract and parse the local timestamp (LTime) localTime := sub1[1] parsedLTime, err := time.Parse(LTimeLayout, localTime) if err != nil { return fmt.Errorf("error parsing local time: %v", err) } + // Process message body to isolate field-value pairs sub2 := strings.Split(sub1[2], "\u0001") if len(sub2) > 5 && strings.Contains(sub2[5], "52=") { + // Extract and parse the timestamp (TTime) from "52=" sub3 := strings.Split(sub2[5], "-") if len(sub3) > 1 { - talosTime := sub3[1] - parsedTTime, err := time.Parse(TTimeLayout, talosTime) + orderTimestamp := sub3[1] + parsedTTime, err := time.Parse(TTimeLayout, orderTimestamp) if err != nil { - return fmt.Errorf("error parsing talos time: %v", err) + return fmt.Errorf("error parsing time: %v", err) } + // Store parsed timestamps in TestTS struct times = append(times, TestTS{LTime: parsedLTime, TTime: parsedTTime}) } } @@ -74,11 +92,22 @@ func Execute() error { } } - // Variables for calculating averages + // Error check for scanner + if err := scanner.Err(); err != nil { + return fmt.Errorf("error reading log file: %v", err) + } + + // Calculate metrics first + totalMessages := len(times) + if totalMessages == 0 { + return fmt.Errorf("no order messages found") + } + var totalInterval float64 var totalLatency float64 + latencies := make([]float64, 0, totalMessages-1) - // Calculate latency and throughput, then write to metrics log + // Calculate individual message intervals and latencies for i := 1; i < len(times); i++ { t := times[i] t0 := times[i-1] @@ -88,27 +117,33 @@ func Execute() error { totalLatency += latency totalInterval += interval - - // Logging the individual message metrics - fmt.Fprintf(metricsLog, "Message %d: Interval = %.3fms, Latency = %.3fms\n", i, interval, latency) + latencies = append(latencies, latency) // Store latencies for later calculations } - // Calculate averages - avgLatency := totalLatency / float64(len(times)-1) - avgInterval := totalInterval / float64(len(times)-1) - - // Throughput Measurement - totalMessages := len(times) - 1 // Total messages should exclude the first (which has no interval) + // Calculate final metrics totalDuration := times[len(times)-1].TTime.Sub(times[0].TTime).Seconds() throughput := float64(totalMessages) / totalDuration + avgLatency := totalLatency / float64(len(latencies)) + avgInterval := totalInterval / float64(len(latencies)) + + // Calculate min and max latencies + minLatency := math.MaxFloat64 + maxLatency := 0.0 + for _, latency := range latencies { + if latency < minLatency { + minLatency = latency + } + if latency > maxLatency { + maxLatency = latency + } + } - // Write averages and throughput to metrics log - fmt.Fprintf(metricsLog, "Average Interval = %.3fms, Average Latency = %.3fms\n", avgInterval, avgLatency) + // Print metrics fmt.Fprintf(metricsLog, "Throughput: %.2f messages per second\n", throughput) + fmt.Fprintf(metricsLog, "Average Interval = %.3fms, Average Latency = %.3fms\n", avgInterval, avgLatency) + fmt.Fprintf(metricsLog, "Message Metrics: Min Latency = %.3fms, Max Latency = %.3fms\n", + minLatency, maxLatency) - // Print overall metrics to console - fmt.Printf("Average Interval = %.3fms, Average Latency = %.3fms\n", avgInterval, avgLatency) - fmt.Printf("Throughput: %.2f messages per second\n", throughput) - fmt.Println("Latency and throughput metrics logged to metrics.log") + fmt.Printf("Metrics logged to %s\n", metricsLogFile) return nil } diff --git a/cmd/tradeclient/loadtest/loadtest.go b/cmd/tradeclient/loadtest/loadtest.go index 76759ea..f5a8384 100644 --- a/cmd/tradeclient/loadtest/loadtest.go +++ b/cmd/tradeclient/loadtest/loadtest.go @@ -4,7 +4,6 @@ import ( "encoding/json" "fmt" "log" - "os" "sync" "time" @@ -32,12 +31,6 @@ type OrderTimestamp struct { // RunLoadTest runs the load test based on the provided configuration. func RunLoadTest(cfg LoadTestConfig) { - outputFile, err := os.OpenFile("output.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666) - if err != nil { - log.Fatalf("error opening output.log: %v", err) - } - defer outputFile.Close() - var wg sync.WaitGroup var mu sync.Mutex successCount := 0 @@ -95,25 +88,21 @@ func RunLoadTest(cfg LoadTestConfig) { successRate := float64(successCount) / float64(cfg.TotalOrders) * 100 failRate := float64(failureCount) / float64(cfg.TotalOrders) * 100 - // Prepare result summary + // Print result summary to the console (instead of output.log) resultSummary := fmt.Sprintf("Sent %d orders in %s\nSuccess Rate: %.2f%%\nFailure Rate: %.2f%%\n", cfg.TotalOrders, totalTime, successRate, failRate) - if _, err := outputFile.WriteString(resultSummary); err != nil { - log.Fatalf("error writing to output.log: %v", err) - } + fmt.Println(resultSummary) - // Log detailed results in JSON format + // Print detailed results in JSON format to the console for _, ts := range timestamps { tsJson, _ := json.Marshal(ts) - if _, err := outputFile.WriteString(fmt.Sprintf("%s\n", tsJson)); err != nil { - log.Fatalf("error writing to output.log: %v", err) - } + fmt.Println(string(tsJson)) } fmt.Println("Load test complete.") // Call readmetrics after the load test - err = readmetrics.Execute() + err := readmetrics.Execute() if err != nil { log.Fatalf("Error executing readmetrics: %v", err) } From 97c2eb4493069dab13727e5f07dd34e85ed965b4 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Tue, 5 Nov 2024 11:41:53 +0000 Subject: [PATCH 08/19] save json --- cmd/readmetrics/readmetrics.go | 149 +++++++++------------------ cmd/tradeclient/loadtest/loadtest.go | 84 ++------------- 2 files changed, 57 insertions(+), 176 deletions(-) diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index d67cd3d..ae52fad 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -2,46 +2,26 @@ package readmetrics import ( "bufio" + "encoding/json" "fmt" - "math" "os" "path/filepath" "strings" - "time" ) -type TestTS struct { - LTime time.Time - TTime time.Time -} +// Constants for file paths +const LogFilePath = "tmp/FIX.4.4-CUST2_Order-ANCHORAGE.messages.current.log" +const OutputFilePath = "tmp/log_data.json" -const ( - LTimeLayout = "15:04:05.999999" - TTimeLayout = "15:04:05.999" - LogFilePath = "tmp/FIX.4.4-CUST2_Order-ANCHORAGE.messages.current.log" - MetricsFolder = "loadtest_metrics" -) +// LogEntry represents a structure for the relevant log information +type LogEntry struct { + MessageType string `json:"message_type"` + Timestamp string `json:"timestamp"` + Fields map[string]string `json:"fields"` +} -// Execute reads and processes metrics from a FIX log file +// Execute reads the log file, extracts relevant information, and saves it as JSON func Execute() error { - // Create metrics folder if it doesn't exist - if _, err := os.Stat(MetricsFolder); os.IsNotExist(err) { - err = os.Mkdir(MetricsFolder, 0755) - if err != nil { - return fmt.Errorf("error creating metrics folder: %v", err) - } - } - - // Define metrics log file path with a timestamp for uniqueness - timestamp := time.Now().Format("20060102_150405") - metricsLogFile := filepath.Join(MetricsFolder, fmt.Sprintf("metrics_%s.log", timestamp)) - metricsLog, err := os.Create(metricsLogFile) - if err != nil { - return fmt.Errorf("error creating metrics log file: %v", err) - } - defer metricsLog.Close() - - // Open the log file to read dir, err := os.Getwd() if err != nil { return fmt.Errorf("error getting working directory: %v", err) @@ -53,97 +33,70 @@ func Execute() error { } defer logFile.Close() - // Initialize a scanner to read the file line by line scanner := bufio.NewScanner(logFile) - times := make([]TestTS, 0) + entries := make([]LogEntry, 0) - // Process each line in the log file for scanner.Scan() { line := scanner.Text() - // Check for specific message type "35=D" to filter relevant messages - if strings.Contains(line, "35=D") { - sub1 := strings.Split(line, " ") - if len(sub1) > 2 { - // Extract and parse the local timestamp (LTime) - localTime := sub1[1] - parsedLTime, err := time.Parse(LTimeLayout, localTime) - if err != nil { - return fmt.Errorf("error parsing local time: %v", err) - } + if strings.Contains(line, "35=D") || strings.Contains(line, "35=8") { + entry := LogEntry{ + Fields: make(map[string]string), + } - // Process message body to isolate field-value pairs - sub2 := strings.Split(sub1[2], "\u0001") - if len(sub2) > 5 && strings.Contains(sub2[5], "52=") { - // Extract and parse the timestamp (TTime) from "52=" - sub3 := strings.Split(sub2[5], "-") - if len(sub3) > 1 { - orderTimestamp := sub3[1] - parsedTTime, err := time.Parse(TTimeLayout, orderTimestamp) - if err != nil { - return fmt.Errorf("error parsing time: %v", err) + parts := strings.Split(line, " ") + if len(parts) > 2 { + entry.MessageType = strings.Split(parts[2], "\u0001")[0] + entry.Timestamp = parts[1] + + // Extract fields + for _, part := range parts { + if strings.Contains(part, "=") { + keyValue := strings.SplitN(part, "=", 2) + if len(keyValue) == 2 { + entry.Fields[keyValue[0]] = keyValue[1] } - - // Store parsed timestamps in TestTS struct - times = append(times, TestTS{LTime: parsedLTime, TTime: parsedTTime}) } } } + + entries = append(entries, entry) } } - // Error check for scanner if err := scanner.Err(); err != nil { return fmt.Errorf("error reading log file: %v", err) } - // Calculate metrics first - totalMessages := len(times) - if totalMessages == 0 { - return fmt.Errorf("no order messages found") + if err := saveToJSON(entries); err != nil { + return fmt.Errorf("error saving to JSON: %v", err) } - var totalInterval float64 - var totalLatency float64 - latencies := make([]float64, 0, totalMessages-1) - - // Calculate individual message intervals and latencies - for i := 1; i < len(times); i++ { - t := times[i] - t0 := times[i-1] - - latency := float64(t.LTime.Sub(t.TTime)) / float64(time.Millisecond) - interval := float64(t.TTime.Sub(t0.TTime)) / float64(time.Millisecond) + fmt.Printf("Data saved to %s\n", OutputFilePath) + return nil +} - totalLatency += latency - totalInterval += interval - latencies = append(latencies, latency) // Store latencies for later calculations +// saveToJSON converts entries to JSON format and saves to a file +func saveToJSON(entries []LogEntry) error { + jsonData, err := json.MarshalIndent(entries, "", " ") + if err != nil { + return fmt.Errorf("error converting to JSON: %v", err) } - // Calculate final metrics - totalDuration := times[len(times)-1].TTime.Sub(times[0].TTime).Seconds() - throughput := float64(totalMessages) / totalDuration - avgLatency := totalLatency / float64(len(latencies)) - avgInterval := totalInterval / float64(len(latencies)) - - // Calculate min and max latencies - minLatency := math.MaxFloat64 - maxLatency := 0.0 - for _, latency := range latencies { - if latency < minLatency { - minLatency = latency - } - if latency > maxLatency { - maxLatency = latency - } + dir, err := os.Getwd() + if err != nil { + return fmt.Errorf("error getting working directory: %v", err) + } + outputFile, err := os.Create(filepath.Join(dir, OutputFilePath)) + if err != nil { + return fmt.Errorf("error creating output file: %v", err) } + defer outputFile.Close() - // Print metrics - fmt.Fprintf(metricsLog, "Throughput: %.2f messages per second\n", throughput) - fmt.Fprintf(metricsLog, "Average Interval = %.3fms, Average Latency = %.3fms\n", avgInterval, avgLatency) - fmt.Fprintf(metricsLog, "Message Metrics: Min Latency = %.3fms, Max Latency = %.3fms\n", - minLatency, maxLatency) + _, err = outputFile.Write(jsonData) + if err != nil { + return fmt.Errorf("error writing to output file: %v", err) + } - fmt.Printf("Metrics logged to %s\n", metricsLogFile) return nil } diff --git a/cmd/tradeclient/loadtest/loadtest.go b/cmd/tradeclient/loadtest/loadtest.go index f5a8384..5807e40 100644 --- a/cmd/tradeclient/loadtest/loadtest.go +++ b/cmd/tradeclient/loadtest/loadtest.go @@ -1,109 +1,37 @@ package loadtest import ( - "encoding/json" "fmt" - "log" "sync" "time" - "github.com/quickfixgo/examples/cmd/readmetrics" "github.com/quickfixgo/examples/cmd/tradeclient/internal" ) // LoadTestConfig holds configuration for the load test. type LoadTestConfig struct { - OrdersPerSecond int - TotalOrders int + OrdersPerSecond int // Rate of orders per second + TotalOrders int // Total number of orders to send SenderCompID string TargetCompID string } -// OrderTimestamp holds the sent, response, and local arrival time of an order. -type OrderTimestamp struct { - SentTime time.Time - ResponseTime time.Time - LocalArrival time.Time // Time when the response is received - Latency time.Duration // Latency calculated - Status string // "success" or "failure" - ErrorMessage string // Detailed error message in case of failure -} - -// RunLoadTest runs the load test based on the provided configuration. +// RunLoadTest sends orders based on the provided configuration. func RunLoadTest(cfg LoadTestConfig) { var wg sync.WaitGroup - var mu sync.Mutex - successCount := 0 - failureCount := 0 - timestamps := make([]OrderTimestamp, 0, cfg.TotalOrders) - startTime := time.Now() - - // Launch goroutines to send orders + // Launch goroutines to send orders at the specified rate for i := 0; i < cfg.TotalOrders; i++ { wg.Add(1) go func(orderID int) { defer wg.Done() - sentTime := time.Now() err := internal.QueryEnterOrder(cfg.SenderCompID, cfg.TargetCompID) - responseTime := time.Now() - - localArrival := responseTime - latency := localArrival.Sub(sentTime) - status := "success" - errorMessage := "" - if err != nil { - status = "failure" - errorMessage = err.Error() - mu.Lock() - failureCount++ - mu.Unlock() - } else { - mu.Lock() - successCount++ - mu.Unlock() + fmt.Printf("Order %d failed: %v\n", orderID, err) } - - mu.Lock() - timestamps = append(timestamps, OrderTimestamp{ - SentTime: sentTime, - ResponseTime: responseTime, - LocalArrival: localArrival, - Latency: latency, - Status: status, - ErrorMessage: errorMessage, - }) - mu.Unlock() }(i) + // Delay to maintain order rate time.Sleep(time.Second / time.Duration(cfg.OrdersPerSecond)) } - - // Wait for all goroutines to finish - wg.Wait() - totalTime := time.Since(startTime) - - // Calculate success and failure rates - successRate := float64(successCount) / float64(cfg.TotalOrders) * 100 - failRate := float64(failureCount) / float64(cfg.TotalOrders) * 100 - - // Print result summary to the console (instead of output.log) - resultSummary := fmt.Sprintf("Sent %d orders in %s\nSuccess Rate: %.2f%%\nFailure Rate: %.2f%%\n", - cfg.TotalOrders, totalTime, successRate, failRate) - fmt.Println(resultSummary) - - // Print detailed results in JSON format to the console - for _, ts := range timestamps { - tsJson, _ := json.Marshal(ts) - fmt.Println(string(tsJson)) - } - - fmt.Println("Load test complete.") - - // Call readmetrics after the load test - err := readmetrics.Execute() - if err != nil { - log.Fatalf("Error executing readmetrics: %v", err) - } } From 3966cb361ca1943c72ea0776dc6b0ee4a75cd808 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Tue, 5 Nov 2024 14:22:15 +0000 Subject: [PATCH 09/19] better latency calculation --- cmd/readmetrics/readmetrics.go | 95 +++++++++++++++++++++++++++++++++- 1 file changed, 94 insertions(+), 1 deletion(-) diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index ae52fad..116332f 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -7,6 +7,7 @@ import ( "os" "path/filepath" "strings" + "time" ) // Constants for file paths @@ -20,6 +21,13 @@ type LogEntry struct { Fields map[string]string `json:"fields"` } +// Struct to store log entries +type LogMetricsEntry struct { + timestamp time.Time + msgType string + clOrdID string +} + // Execute reads the log file, extracts relevant information, and saves it as JSON func Execute() error { dir, err := os.Getwd() @@ -72,7 +80,8 @@ func Execute() error { return fmt.Errorf("error saving to JSON: %v", err) } - fmt.Printf("Data saved to %s\n", OutputFilePath) + CalculateLatenciesToFile(LogFilePath) + fmt.Printf("Raw Data saved to %s\n", OutputFilePath) return nil } @@ -100,3 +109,87 @@ func saveToJSON(entries []LogEntry) error { return nil } + +// parseFIXMessage parses a FIX message from a log line. +func parseFIXMessage(line string) (LogMetricsEntry, error) { + fields := strings.Split(line, "") + msg := LogMetricsEntry{} + timestampStr := line[:26] + timestamp, err := time.Parse("2006/01/02 15:04:05.000000", timestampStr) + if err != nil { + return msg, err + } + msg.timestamp = timestamp + + for _, field := range fields { + if strings.HasPrefix(field, "35=") { + msg.msgType = strings.TrimPrefix(field, "35=") + } else if strings.HasPrefix(field, "11=") { + msg.clOrdID = strings.TrimPrefix(field, "11=") + } + } + return msg, nil +} + +// CalculateLatenciesToFile reads a log file, calculates latencies for 35=D messages, +// and writes the latencies to a file in the /tmp directory. +func CalculateLatenciesToFile(logFilePath string) error { + file, err := os.Open(logFilePath) + if err != nil { + return fmt.Errorf("error opening file: %v", err) + } + defer file.Close() + + dMessages := make(map[string]LogMetricsEntry) + latencies := []string{} + + scanner := bufio.NewScanner(file) + for scanner.Scan() { + line := scanner.Text() + msg, err := parseFIXMessage(line) + if err != nil { + fmt.Println("Error parsing line:", err) + continue + } + + if msg.msgType == "D" { + // Store 35=D message by ClOrdID + dMessages[msg.clOrdID] = msg + } else if msg.msgType == "8" && msg.clOrdID != "" { + // Calculate latency if a matching 35=D exists + if dMsg, found := dMessages[msg.clOrdID]; found { + latency := msg.timestamp.Sub(dMsg.timestamp) + latencyMs := latency.Milliseconds() + latencies = append(latencies, fmt.Sprintf("ClOrdID: %s, Latency: %d ms", msg.clOrdID, latencyMs)) + + // Remove entry to ensure only one latency per ClOrdID + delete(dMessages, msg.clOrdID) + } + } + } + + if err := scanner.Err(); err != nil { + return fmt.Errorf("error reading file: %v", err) + } + + dir, err := os.Getwd() + if err != nil { + return fmt.Errorf("error getting working directory: %v", err) + } + outputFile, err := os.Create(filepath.Join(dir, "tmp/log_metrics.txt")) + if err != nil { + return fmt.Errorf("error creating log file: %v", err) + } + defer outputFile.Close() + + writer := bufio.NewWriter(outputFile) + for _, latency := range latencies { + _, err := writer.WriteString(latency + "\n") + if err != nil { + return fmt.Errorf("error writing to log file: %v", err) + } + } + writer.Flush() + + return nil +} From 6d87557fa2b8ac89fa541c0bf5ccbee260f91d2d Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Tue, 5 Nov 2024 15:45:17 +0000 Subject: [PATCH 10/19] refined throughtput --- cmd/readmetrics/readmetrics.go | 28 ++++++++++++++++++++++------ 1 file changed, 22 insertions(+), 6 deletions(-) diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index 116332f..f22a1da 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -132,7 +132,7 @@ func parseFIXMessage(line string) (LogMetricsEntry, error) { } // CalculateLatenciesToFile reads a log file, calculates latencies for 35=D messages, -// and writes the latencies to a file in the /tmp directory. +// and writes the latencies and throughput to a file in the /tmp directory. func CalculateLatenciesToFile(logFilePath string) error { file, err := os.Open(logFilePath) if err != nil { @@ -142,6 +142,7 @@ func CalculateLatenciesToFile(logFilePath string) error { dMessages := make(map[string]LogMetricsEntry) latencies := []string{} + throughputCounts := make(map[time.Time]int) scanner := bufio.NewScanner(file) for scanner.Scan() { @@ -152,18 +153,20 @@ func CalculateLatenciesToFile(logFilePath string) error { continue } + // Track 35=D message timestamps for latency and throughput if msg.msgType == "D" { - // Store 35=D message by ClOrdID dMessages[msg.clOrdID] = msg + + // Round down timestamp to the nearest minute for throughput calculation + minute := msg.timestamp.Truncate(time.Minute) + throughputCounts[minute]++ } else if msg.msgType == "8" && msg.clOrdID != "" { - // Calculate latency if a matching 35=D exists + // Calculate latency if dMsg, found := dMessages[msg.clOrdID]; found { latency := msg.timestamp.Sub(dMsg.timestamp) latencyMs := latency.Milliseconds() latencies = append(latencies, fmt.Sprintf("ClOrdID: %s, Latency: %d ms", msg.clOrdID, latencyMs)) - - // Remove entry to ensure only one latency per ClOrdID - delete(dMessages, msg.clOrdID) + delete(dMessages, msg.clOrdID) // Remove to avoid multiple calculations for same ClOrdID } } } @@ -172,6 +175,7 @@ func CalculateLatenciesToFile(logFilePath string) error { return fmt.Errorf("error reading file: %v", err) } + // Write output to the log_metrics file dir, err := os.Getwd() if err != nil { return fmt.Errorf("error getting working directory: %v", err) @@ -183,12 +187,24 @@ func CalculateLatenciesToFile(logFilePath string) error { defer outputFile.Close() writer := bufio.NewWriter(outputFile) + + // Write latency data for _, latency := range latencies { _, err := writer.WriteString(latency + "\n") if err != nil { return fmt.Errorf("error writing to log file: %v", err) } } + + // Write throughput data + for minute, count := range throughputCounts { + throughputStr := fmt.Sprintf("Minute: %s, Throughput: %d orders/min", minute.Format("2006-01-02 15:04"), count) + _, err := writer.WriteString(throughputStr + "\n") + if err != nil { + return fmt.Errorf("error writing throughput to log file: %v", err) + } + } + writer.Flush() return nil From f102d2da9188bac27ad233a223410db9e00dad7c Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Tue, 5 Nov 2024 17:45:59 +0000 Subject: [PATCH 11/19] refactor avg lat --- cmd/readmetrics/readmetrics.go | 33 +++++++++++++++++++++++++-------- 1 file changed, 25 insertions(+), 8 deletions(-) diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index f22a1da..0498494 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -80,7 +80,10 @@ func Execute() error { return fmt.Errorf("error saving to JSON: %v", err) } - CalculateLatenciesToFile(LogFilePath) + if err := CalculateLatenciesToFile(LogFilePath); err != nil { + return fmt.Errorf("error calculating latencies: %v", err) + } + fmt.Printf("Raw Data saved to %s\n", OutputFilePath) return nil } @@ -141,7 +144,7 @@ func CalculateLatenciesToFile(logFilePath string) error { defer file.Close() dMessages := make(map[string]LogMetricsEntry) - latencies := []string{} + latencies := []int64{} // Store latencies in an array for average calculation throughputCounts := make(map[time.Time]int) scanner := bufio.NewScanner(file) @@ -163,9 +166,8 @@ func CalculateLatenciesToFile(logFilePath string) error { } else if msg.msgType == "8" && msg.clOrdID != "" { // Calculate latency if dMsg, found := dMessages[msg.clOrdID]; found { - latency := msg.timestamp.Sub(dMsg.timestamp) - latencyMs := latency.Milliseconds() - latencies = append(latencies, fmt.Sprintf("ClOrdID: %s, Latency: %d ms", msg.clOrdID, latencyMs)) + latency := msg.timestamp.Sub(dMsg.timestamp).Milliseconds() + latencies = append(latencies, latency) delete(dMessages, msg.clOrdID) // Remove to avoid multiple calculations for same ClOrdID } } @@ -190,16 +192,31 @@ func CalculateLatenciesToFile(logFilePath string) error { // Write latency data for _, latency := range latencies { - _, err := writer.WriteString(latency + "\n") + _, err := writer.WriteString(fmt.Sprintf("Latency: %d ms\n", latency)) if err != nil { return fmt.Errorf("error writing to log file: %v", err) } } + // Calculate average latency + averageLatency := float64(0) + if len(latencies) > 0 { + for _, latency := range latencies { + averageLatency += float64(latency) + } + averageLatency /= float64(len(latencies)) + } + + // Write the average latency to the log file + _, err = writer.WriteString(fmt.Sprintf("Average Latency: %.2f ms\n", averageLatency)) + if err != nil { + return fmt.Errorf("error writing average latency to log file: %v", err) + } + // Write throughput data for minute, count := range throughputCounts { - throughputStr := fmt.Sprintf("Minute: %s, Throughput: %d orders/min", minute.Format("2006-01-02 15:04"), count) - _, err := writer.WriteString(throughputStr + "\n") + throughputStr := fmt.Sprintf("Minute: %s, Throughput: %d orders/min\n", minute.Format("2006-01-02 15:04"), count) + _, err := writer.WriteString(throughputStr) if err != nil { return fmt.Errorf("error writing throughput to log file: %v", err) } From b8b5fc72eb13f2b7e614db95ad0e57f7f1d98767 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Tue, 5 Nov 2024 18:21:35 +0000 Subject: [PATCH 12/19] better loggin --- cmd/readmetrics/readmetrics.go | 34 ++++++++++++++++++++++------------ 1 file changed, 22 insertions(+), 12 deletions(-) diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index 0498494..d27eee2 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -135,7 +135,7 @@ func parseFIXMessage(line string) (LogMetricsEntry, error) { } // CalculateLatenciesToFile reads a log file, calculates latencies for 35=D messages, -// and writes the latencies and throughput to a file in the /tmp directory. +// and writes the latencies and throughput to separate files in the /tmp directory. func CalculateLatenciesToFile(logFilePath string) error { file, err := os.Open(logFilePath) if err != nil { @@ -177,24 +177,24 @@ func CalculateLatenciesToFile(logFilePath string) error { return fmt.Errorf("error reading file: %v", err) } - // Write output to the log_metrics file + // Write latencies to a separate file dir, err := os.Getwd() if err != nil { return fmt.Errorf("error getting working directory: %v", err) } - outputFile, err := os.Create(filepath.Join(dir, "tmp/log_metrics.txt")) + latencyFile, err := os.Create(filepath.Join(dir, "tmp/latencies.txt")) if err != nil { - return fmt.Errorf("error creating log file: %v", err) + return fmt.Errorf("error creating latencies file: %v", err) } - defer outputFile.Close() + defer latencyFile.Close() - writer := bufio.NewWriter(outputFile) + writer := bufio.NewWriter(latencyFile) // Write latency data for _, latency := range latencies { _, err := writer.WriteString(fmt.Sprintf("Latency: %d ms\n", latency)) if err != nil { - return fmt.Errorf("error writing to log file: %v", err) + return fmt.Errorf("error writing to latencies file: %v", err) } } @@ -207,22 +207,32 @@ func CalculateLatenciesToFile(logFilePath string) error { averageLatency /= float64(len(latencies)) } - // Write the average latency to the log file - _, err = writer.WriteString(fmt.Sprintf("Average Latency: %.2f ms\n", averageLatency)) + // Write output for average latency and throughput to another file + metricsFile, err := os.Create(filepath.Join(dir, "tmp/metrics.txt")) + if err != nil { + return fmt.Errorf("error creating metrics file: %v", err) + } + defer metricsFile.Close() + + metricsWriter := bufio.NewWriter(metricsFile) + + // Write the average latency to the metrics file + _, err = metricsWriter.WriteString(fmt.Sprintf("Average Latency: %.2f ms\n", averageLatency)) if err != nil { - return fmt.Errorf("error writing average latency to log file: %v", err) + return fmt.Errorf("error writing average latency to metrics file: %v", err) } // Write throughput data for minute, count := range throughputCounts { throughputStr := fmt.Sprintf("Minute: %s, Throughput: %d orders/min\n", minute.Format("2006-01-02 15:04"), count) - _, err := writer.WriteString(throughputStr) + _, err := metricsWriter.WriteString(throughputStr) if err != nil { - return fmt.Errorf("error writing throughput to log file: %v", err) + return fmt.Errorf("error writing throughput to metrics file: %v", err) } } writer.Flush() + metricsWriter.Flush() return nil } From eb92d31606090bfb4f4946f915256ab2307e49bc Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Tue, 5 Nov 2024 19:41:50 +0000 Subject: [PATCH 13/19] filled percent --- cmd/readmetrics/readmetrics.go | 79 +++++++++++++++++++++++++++++++++- 1 file changed, 77 insertions(+), 2 deletions(-) diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index d27eee2..acdb897 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -84,6 +84,16 @@ func Execute() error { return fmt.Errorf("error calculating latencies: %v", err) } + // Calculate success and failure percentages and write to metrics file + filledPct, rejectedPct, err := calculateSuccessFailure() + if err != nil { + return fmt.Errorf("error calculating success/failure percentages: %v", err) + } + + if err := writeMetricsToFile(dir, filledPct, rejectedPct); err != nil { + return fmt.Errorf("error writing metrics to file: %v", err) + } + fmt.Printf("Raw Data saved to %s\n", OutputFilePath) return nil } @@ -191,8 +201,8 @@ func CalculateLatenciesToFile(logFilePath string) error { writer := bufio.NewWriter(latencyFile) // Write latency data - for _, latency := range latencies { - _, err := writer.WriteString(fmt.Sprintf("Latency: %d ms\n", latency)) + for index, latency := range latencies { + _, err := writer.WriteString(fmt.Sprintf("Latency %d: %d ms\n", index+1, latency)) if err != nil { return fmt.Errorf("error writing to latencies file: %v", err) } @@ -236,3 +246,68 @@ func CalculateLatenciesToFile(logFilePath string) error { return nil } + +// calculateSuccessFailure reads a FIX log file and calculates the success (filled) and failure (rejected) percentages +func calculateSuccessFailure() (float64, float64, error) { + file, err := os.Open(LogFilePath) + if err != nil { + return 0, 0, fmt.Errorf("failed to open log file: %v", err) + } + defer file.Close() + + var filledCount, rejectedCount, totalCount int + + scanner := bufio.NewScanner(file) + for scanner.Scan() { + line := scanner.Text() + + // Check if the message type is an Execution Report (35=8) + if strings.Contains(line, "35=8") { + totalCount++ + + // Check for filled (150=F) or rejected (150=8) execution status + if strings.Contains(line, "150=F") { + filledCount++ + } else if strings.Contains(line, "150=8") { + rejectedCount++ + } + } + } + + if err := scanner.Err(); err != nil { + return 0, 0, fmt.Errorf("failed to scan log file: %v", err) + } + + if totalCount == 0 { + return 0, 0, fmt.Errorf("no execution reports found in log") + } + + filledPercentage := (float64(filledCount) / float64(totalCount)) * 100 + rejectedPercentage := (float64(rejectedCount) / float64(totalCount)) * 100 + + return filledPercentage, rejectedPercentage, nil +} + +// writeMetricsToFile writes the filled and rejected percentages to the metrics file +func writeMetricsToFile(dir string, filledPct, rejectedPct float64) error { + metricsFile, err := os.OpenFile(filepath.Join(dir, "tmp/metrics.txt"), os.O_APPEND|os.O_WRONLY, 0644) + if err != nil { + return fmt.Errorf("error opening metrics file: %v", err) + } + defer metricsFile.Close() + + metricsWriter := bufio.NewWriter(metricsFile) + + // Write filled and rejected percentages to the metrics file + _, err = metricsWriter.WriteString(fmt.Sprintf("Filled Percentage: %.2f%%\n", filledPct)) + if err != nil { + return fmt.Errorf("error writing filled percentage to metrics file: %v", err) + } + + _, err = metricsWriter.WriteString(fmt.Sprintf("Rejected Percentage: %.2f%%\n", rejectedPct)) + if err != nil { + return fmt.Errorf("error writing rejected percentage to metrics file: %v", err) + } + + return metricsWriter.Flush() +} From b6378d8724d5eddb74d2187cd3b93fd0d5f47640 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Wed, 6 Nov 2024 14:48:15 +0000 Subject: [PATCH 14/19] unit test --- cmd/readmetrics/readmetrics.go | 46 ++++++++----------- cmd/readmetrics/readmetrics_test.go | 48 ++++++++++++++++++++ cmd/readmetrics/test_data/test_data.json | 58 ++++++++++++++++++++++++ cmd/tradeclient/internal/console.go | 3 +- cmd/tradeclient/tradeclient.go | 25 +++++++--- 5 files changed, 146 insertions(+), 34 deletions(-) create mode 100644 cmd/readmetrics/readmetrics_test.go create mode 100644 cmd/readmetrics/test_data/test_data.json diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index acdb897..f6e190a 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -10,10 +10,6 @@ import ( "time" ) -// Constants for file paths -const LogFilePath = "tmp/FIX.4.4-CUST2_Order-ANCHORAGE.messages.current.log" -const OutputFilePath = "tmp/log_data.json" - // LogEntry represents a structure for the relevant log information type LogEntry struct { MessageType string `json:"message_type"` @@ -29,13 +25,13 @@ type LogMetricsEntry struct { } // Execute reads the log file, extracts relevant information, and saves it as JSON -func Execute() error { +func Execute(logFilePath, outputFilePath, tmpDir string) error { dir, err := os.Getwd() if err != nil { return fmt.Errorf("error getting working directory: %v", err) } - logFile, err := os.Open(filepath.Join(dir, LogFilePath)) + logFile, err := os.Open(filepath.Join(dir, logFilePath)) if err != nil { return fmt.Errorf("error opening log file: %v", err) } @@ -76,30 +72,30 @@ func Execute() error { return fmt.Errorf("error reading log file: %v", err) } - if err := saveToJSON(entries); err != nil { + if err := saveToJSON(entries, outputFilePath); err != nil { return fmt.Errorf("error saving to JSON: %v", err) } - if err := CalculateLatenciesToFile(LogFilePath); err != nil { + if err := CalculateLatenciesToFile(logFilePath, tmpDir); err != nil { return fmt.Errorf("error calculating latencies: %v", err) } // Calculate success and failure percentages and write to metrics file - filledPct, rejectedPct, err := calculateSuccessFailure() + filledPct, rejectedPct, err := calculateSuccessFailure(logFilePath) if err != nil { return fmt.Errorf("error calculating success/failure percentages: %v", err) } - if err := writeMetricsToFile(dir, filledPct, rejectedPct); err != nil { + if err := writeMetricsToFile(tmpDir, filledPct, rejectedPct); err != nil { return fmt.Errorf("error writing metrics to file: %v", err) } - fmt.Printf("Raw Data saved to %s\n", OutputFilePath) + fmt.Printf("Raw Data saved to %s\n", outputFilePath) return nil } // saveToJSON converts entries to JSON format and saves to a file -func saveToJSON(entries []LogEntry) error { +func saveToJSON(entries []LogEntry, outputFilePath string) error { jsonData, err := json.MarshalIndent(entries, "", " ") if err != nil { return fmt.Errorf("error converting to JSON: %v", err) @@ -109,7 +105,7 @@ func saveToJSON(entries []LogEntry) error { if err != nil { return fmt.Errorf("error getting working directory: %v", err) } - outputFile, err := os.Create(filepath.Join(dir, OutputFilePath)) + outputFile, err := os.Create(filepath.Join(dir, outputFilePath)) if err != nil { return fmt.Errorf("error creating output file: %v", err) } @@ -145,8 +141,8 @@ func parseFIXMessage(line string) (LogMetricsEntry, error) { } // CalculateLatenciesToFile reads a log file, calculates latencies for 35=D messages, -// and writes the latencies and throughput to separate files in the /tmp directory. -func CalculateLatenciesToFile(logFilePath string) error { +// and writes the latencies and throughput to separate files in the specified directory. +func CalculateLatenciesToFile(logFilePath, tmpDir string) error { file, err := os.Open(logFilePath) if err != nil { return fmt.Errorf("error opening file: %v", err) @@ -187,12 +183,8 @@ func CalculateLatenciesToFile(logFilePath string) error { return fmt.Errorf("error reading file: %v", err) } - // Write latencies to a separate file - dir, err := os.Getwd() - if err != nil { - return fmt.Errorf("error getting working directory: %v", err) - } - latencyFile, err := os.Create(filepath.Join(dir, "tmp/latencies.txt")) + // Write latencies to a separate file in the tmpDir directory + latencyFile, err := os.Create(filepath.Join(tmpDir, "latencies.txt")) if err != nil { return fmt.Errorf("error creating latencies file: %v", err) } @@ -217,8 +209,8 @@ func CalculateLatenciesToFile(logFilePath string) error { averageLatency /= float64(len(latencies)) } - // Write output for average latency and throughput to another file - metricsFile, err := os.Create(filepath.Join(dir, "tmp/metrics.txt")) + // Write output for average latency and throughput to another file in tmpDir + metricsFile, err := os.Create(filepath.Join(tmpDir, "metrics.txt")) if err != nil { return fmt.Errorf("error creating metrics file: %v", err) } @@ -248,8 +240,8 @@ func CalculateLatenciesToFile(logFilePath string) error { } // calculateSuccessFailure reads a FIX log file and calculates the success (filled) and failure (rejected) percentages -func calculateSuccessFailure() (float64, float64, error) { - file, err := os.Open(LogFilePath) +func calculateSuccessFailure(logFilePath string) (float64, float64, error) { + file, err := os.Open(logFilePath) if err != nil { return 0, 0, fmt.Errorf("failed to open log file: %v", err) } @@ -289,8 +281,8 @@ func calculateSuccessFailure() (float64, float64, error) { } // writeMetricsToFile writes the filled and rejected percentages to the metrics file -func writeMetricsToFile(dir string, filledPct, rejectedPct float64) error { - metricsFile, err := os.OpenFile(filepath.Join(dir, "tmp/metrics.txt"), os.O_APPEND|os.O_WRONLY, 0644) +func writeMetricsToFile(tmpDir string, filledPct, rejectedPct float64) error { + metricsFile, err := os.OpenFile(filepath.Join(tmpDir, "metrics.txt"), os.O_APPEND|os.O_WRONLY, 0644) if err != nil { return fmt.Errorf("error opening metrics file: %v", err) } diff --git a/cmd/readmetrics/readmetrics_test.go b/cmd/readmetrics/readmetrics_test.go new file mode 100644 index 0000000..5d3921d --- /dev/null +++ b/cmd/readmetrics/readmetrics_test.go @@ -0,0 +1,48 @@ +package readmetrics + +import ( + "os" + "path/filepath" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// Mock function to simulate reading from a fixed logfile and generating expected latencies +func TestCalculateLatenciesToFile(t *testing.T) { + logFilePath := "test_data/test.log" + tmpDir := "test_data" + + // Ensure the tmpDir exists or create it for this test + err := os.MkdirAll(tmpDir, os.ModePerm) + require.NoError(t, err) + + // Call the function under test + err = CalculateLatenciesToFile(logFilePath, tmpDir) + require.NoError(t, err) + + // Read the generated latencies.txt file + latenciesFilePath := filepath.Join(tmpDir, "latencies.txt") + latenciesData, err := os.ReadFile(latenciesFilePath) + require.NoError(t, err) + + // Define the expected latencies based on the mock data + expectedLatencies := []string{ + "Latency 1: 151 ms\n", + "Latency 2: 156 ms\n", + } + + // Assert that the latencies file contains the expected latencies + for i, expected := range expectedLatencies { + assert.Contains(t, string(latenciesData), expected, "Missing or incorrect latency at index %d", i+1) + } + + // Read the generated metrics.txt file to ensure it contains the expected average latency and throughput + metricsFilePath := filepath.Join(tmpDir, "metrics.txt") + metricsData, err := os.ReadFile(metricsFilePath) + require.NoError(t, err) + + // Verify that the average latency is present and matches the expected value + assert.Contains(t, string(metricsData), "Average Latency: 153.50 ms\n", "Average latency is incorrect") +} diff --git a/cmd/readmetrics/test_data/test_data.json b/cmd/readmetrics/test_data/test_data.json new file mode 100644 index 0000000..3bd5e22 --- /dev/null +++ b/cmd/readmetrics/test_data/test_data.json @@ -0,0 +1,58 @@ +[ + { + "message_type": "8=FIX.4.4", + "timestamp": "13:48:13.861610", + "fields": { + "8": "FIX.4.4\u00019=157\u000135=D\u000134=2\u000149=test_order\u000152=20241106-13:48:13.861\u000156=test_target\u000111=111111111\u000121=1\u000138=0.0190\u000140=2\u000144=60000.00000\u000154=2\u000155=BTC-USD\u000159=4\u000160=20241106-13:48:13.861\u000110=086\u0001" + } + }, + { + "message_type": "8=FIX.4.4", + "timestamp": "13:48:13.862631", + "fields": { + "8": "FIX.4.4\u00019=157\u000135=D\u000134=3\u000149=test_order\u000152=20241106-13:48:13.862\u000156=test_target\u000111=222222222\u000121=1\u000138=0.0150\u000140=2\u000144=60000.00000\u000154=2\u000155=BTC-USD\u000159=4\u000160=20241106-13:48:13.862\u000110=078\u0001" + } + }, + { + "message_type": "8=FIX.4.4", + "timestamp": "13:48:14.012654", + "fields": { + "8": "FIX.4.4\u00019=272\u000135=8\u000134=2\u000149=test_target\u000152=20241106-13:48:13.979\u000156=test_order\u00011=default\u00016=0.0000\u000111=111111111\u000114=0.00000000\u000117=11111112-4444-4444-4444-111111111111\u000131=0.0000\u000132=0.00000000\u000137=11111111-2222-3333-4444-555555555555\u000138=0.02\u000139=A\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=A\u0001151=0.01900000\u000110=050\u0001" + } + }, + { + "message_type": "8=FIX.4.4", + "timestamp": "13:48:14.019403", + "fields": { + "8": "FIX.4.4\u00019=272\u000135=8\u000134=3\u000149=test_target\u000152=20241106-13:48:13.987\u000156=test_order\u00011=default\u00016=0.0000\u000111=222222222\u000114=0.00000000\u000117=11111113-4444-4444-4444-111111111111\u000131=0.0000\u000132=0.00000000\u000137=22222222-3333-4444-5555-666666666666\u000138=0.02\u000139=A\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=A\u0001151=0.01500000\u000110=228\u0001" + } + }, + { + "message_type": "8=FIX.4.4", + "timestamp": "13:48:14.033887", + "fields": { + "8": "FIX.4.4\u00019=272\u000135=8\u000134=4\u000149=test_target\u000152=20241106-13:48:13.999\u000156=test_order\u00011=default\u00016=0.0000\u000111=111111111\u000114=0.00000000\u000117=11111114-4444-4444-4444-111111111111\u000131=0.0000\u000132=0.00000000\u000137=11111111-2222-3333-4444-555555555555\u000138=0.02\u000139=0\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=0\u0001151=0.01900000\u000110=143\u0001" + } + }, + { + "message_type": "8=FIX.4.4", + "timestamp": "13:48:14.043048", + "fields": { + "8": "FIX.4.4\u00019=280\u000135=8\u000134=5\u000149=test_target\u000152=20241106-13:48:14.009\u000156=test_order\u00011=default\u00016=73940.6300\u000111=111111111\u000114=0.01900000\u000117=11111115-4444-4444-4444-111111111111\u000131=73940.6300\u000132=0.01900000\u000137=11111111-2222-3333-4444-555555555555\u000138=0.02\u000139=2\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=F\u0001151=0.00000000\u000110=097\u0001" + } + }, + { + "message_type": "8=FIX.4.4", + "timestamp": "13:48:14.052181", + "fields": { + "8": "FIX.4.4\u00019=272\u000135=8\u000134=6\u000149=test_target\u000152=20241106-13:48:14.018\u000156=test_order\u00011=default\u00016=0.0000\u000111=222222222\u000114=0.00000000\u000117=11111116-4444-4444-4444-111111111111\u000131=0.0000\u000132=0.00000000\u000137=22222222-3333-4444-5555-666666666666\u000138=0.02\u000139=0\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=0\u0001151=0.01500000\u000110=192\u0001" + } + }, + { + "message_type": "8=FIX.4.4", + "timestamp": "13:48:14.060262", + "fields": { + "8": "FIX.4.4\u00019=280\u000135=8\u000134=7\u000149=test_target\u000152=20241106-13:48:14.027\u000156=test_order\u00011=default\u00016=73941.0700\u000111=222222222\u000114=0.01500000\u000117=11111117-4444-4444-4444-111111111111\u000131=73941.0700\u000132=0.01500000\u000137=22222222-3333-4444-5555-666666666666\u000138=0.02\u000139=2\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=F\u0001151=0.00000000\u000110=135\u0001" + } + } +] \ No newline at end of file diff --git a/cmd/tradeclient/internal/console.go b/cmd/tradeclient/internal/console.go index 5c85dcd..68f21e2 100644 --- a/cmd/tradeclient/internal/console.go +++ b/cmd/tradeclient/internal/console.go @@ -94,7 +94,8 @@ func QueryAction() (string, error) { fmt.Println("2) Cancel Order") fmt.Println("3) Request Market Data") fmt.Println("4) Run Load Test") - fmt.Println("5) Quit") // Updated the option for quitting + fmt.Println("5) Read metrics") + fmt.Println("6) Quit") fmt.Print("Action: ") scanner := bufio.NewScanner(os.Stdin) scanner.Scan() diff --git a/cmd/tradeclient/tradeclient.go b/cmd/tradeclient/tradeclient.go index fb92762..3b4af9c 100644 --- a/cmd/tradeclient/tradeclient.go +++ b/cmd/tradeclient/tradeclient.go @@ -21,10 +21,12 @@ import ( "encoding/hex" "fmt" "io" + "log" "os" "path" "strconv" + "github.com/quickfixgo/examples/cmd/readmetrics" "github.com/quickfixgo/examples/cmd/tradeclient/internal" "github.com/quickfixgo/examples/cmd/tradeclient/loadtest" "github.com/quickfixgo/examples/cmd/utils" @@ -40,7 +42,7 @@ type TradeClient struct { // OnCreate implemented as part of Application interface func (e TradeClient) OnCreate(sessionID quickfix.SessionID) { - fmt.Printf("initiator session Id: %s\n", sessionID) + // fmt.Printf("initiator session Id: %s\n", sessionID) } // OnLogon implemented as part of Application interface @@ -48,12 +50,12 @@ func (e TradeClient) OnLogon(sessionID quickfix.SessionID) {} // OnLogout implemented as part of Application interface func (e TradeClient) OnLogout(sessionID quickfix.SessionID) { - fmt.Printf("OnLogout: %s\n", sessionID) + // fmt.Printf("OnLogout: %s\n", sessionID) } // FromAdmin implemented as part of Application interface func (e TradeClient) FromAdmin(msg *quickfix.Message, sessionID quickfix.SessionID) (reject quickfix.MessageRejectError) { - utils.PrintInfo(fmt.Sprintf("FromAdmin: %s\n", msg.String())) + // utils.PrintInfo(fmt.Sprintf("FromAdmin: %s\n", msg.String())) return nil } @@ -64,7 +66,11 @@ const ( Privatekey = "b" - APIKey = "c" + APIKey = "4b" + // Constants for file paths + LogFilePath = "tmp/FIX.4.4-CUST2_Order-ANCHORAGE.messages.current.log" + OutputFilePath = "tmp/log_data.json" + TmpDir = "tmp/" ) // ToAdmin implemented as part of Application interface @@ -83,7 +89,7 @@ func (e TradeClient) ToAdmin(msg *quickfix.Message, sessionID quickfix.SessionID msg.Body.Set(field.NewRawData(signature)) } - utils.PrintInfo(fmt.Sprintf("ToAdmin: %s", msg.String())) + // utils.PrintInfo(fmt.Sprintf("ToAdmin: %s", msg.String())) } func (e TradeClient) sign(logonmsg *quickfix.Message) (string, error) { @@ -132,7 +138,7 @@ func (e TradeClient) ToApp(msg *quickfix.Message, sessionID quickfix.SessionID) // FromApp implemented as part of Application interface. This is the callback for all Application level messages from the counter party. func (e TradeClient) FromApp(msg *quickfix.Message, sessionID quickfix.SessionID) (reject quickfix.MessageRejectError) { - utils.PrintInfo(fmt.Sprintf("FromApp: %s", msg.String())) + // utils.PrintInfo(fmt.Sprintf("FromApp: %s", msg.String())) return } @@ -258,6 +264,13 @@ Loop: loadtest.RunLoadTest(loadTestConfig) case "5": + // Call readmetrics after the load test + err := readmetrics.Execute(LogFilePath, OutputFilePath, TmpDir) + if err != nil { + log.Fatalf("Error executing readmetrics: %v", err) + } + + case "6": //quit break Loop From 9b58288659c9756f050f668f2716b9d685fd4e82 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Wed, 6 Nov 2024 15:44:32 +0000 Subject: [PATCH 15/19] unit test - and success rate --- cmd/readmetrics/readmetrics.go | 64 +++++++++++++++-------------- cmd/readmetrics/readmetrics_test.go | 6 +++ cmd/readmetrics/test_data/test.log | 12 ++++++ go.mod | 6 +++ go.sum | 18 ++++++-- 5 files changed, 72 insertions(+), 34 deletions(-) create mode 100644 cmd/readmetrics/test_data/test.log diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index f6e190a..ebafb39 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -80,13 +80,14 @@ func Execute(logFilePath, outputFilePath, tmpDir string) error { return fmt.Errorf("error calculating latencies: %v", err) } - // Calculate success and failure percentages and write to metrics file - filledPct, rejectedPct, err := calculateSuccessFailure(logFilePath) + // Count filled and new orders and calculate success rate + filledCount, newOrderCount, successRate, err := countFilledOrders(logFilePath) if err != nil { return fmt.Errorf("error calculating success/failure percentages: %v", err) } - if err := writeMetricsToFile(tmpDir, filledPct, rejectedPct); err != nil { + // Write metrics (new orders, filled orders, success rate) to the metrics file + if err := writeMetricsToFile(tmpDir, filledCount, newOrderCount, successRate); err != nil { return fmt.Errorf("error writing metrics to file: %v", err) } @@ -239,49 +240,47 @@ func CalculateLatenciesToFile(logFilePath, tmpDir string) error { return nil } -// calculateSuccessFailure reads a FIX log file and calculates the success (filled) and failure (rejected) percentages -func calculateSuccessFailure(logFilePath string) (float64, float64, error) { +// countFilledOrders reads a FIX log file and counts how many orders were filled (150=F), +// as well as the number of new orders (35=D), and calculates the success rate. +func countFilledOrders(logFilePath string) (int, int, float64, error) { file, err := os.Open(logFilePath) if err != nil { - return 0, 0, fmt.Errorf("failed to open log file: %v", err) + return 0, 0, 0, fmt.Errorf("failed to open log file: %v", err) } defer file.Close() - var filledCount, rejectedCount, totalCount int + var filledCount, newOrderCount int scanner := bufio.NewScanner(file) for scanner.Scan() { line := scanner.Text() - // Check if the message type is an Execution Report (35=8) - if strings.Contains(line, "35=8") { - totalCount++ + // Check if the line contains 35=D (new order) + if strings.Contains(line, "35=D") { + newOrderCount++ + } - // Check for filled (150=F) or rejected (150=8) execution status - if strings.Contains(line, "150=F") { - filledCount++ - } else if strings.Contains(line, "150=8") { - rejectedCount++ - } + // Check if the line contains 150=F (filled order) + if strings.Contains(line, "150=F") { + filledCount++ } } if err := scanner.Err(); err != nil { - return 0, 0, fmt.Errorf("failed to scan log file: %v", err) + return 0, 0, 0, fmt.Errorf("failed to scan log file: %v", err) } - if totalCount == 0 { - return 0, 0, fmt.Errorf("no execution reports found in log") + // Calculate success rate (if newOrderCount > 0 to avoid division by zero) + var successRate float64 + if newOrderCount > 0 { + successRate = float64(filledCount) / float64(newOrderCount) * 100 } - filledPercentage := (float64(filledCount) / float64(totalCount)) * 100 - rejectedPercentage := (float64(rejectedCount) / float64(totalCount)) * 100 - - return filledPercentage, rejectedPercentage, nil + return filledCount, newOrderCount, successRate, nil } -// writeMetricsToFile writes the filled and rejected percentages to the metrics file -func writeMetricsToFile(tmpDir string, filledPct, rejectedPct float64) error { +// writeMetricsToFile writes the filled and new orders count, and the success rate to the metrics file +func writeMetricsToFile(tmpDir string, filledCount, newOrderCount int, successRate float64) error { metricsFile, err := os.OpenFile(filepath.Join(tmpDir, "metrics.txt"), os.O_APPEND|os.O_WRONLY, 0644) if err != nil { return fmt.Errorf("error opening metrics file: %v", err) @@ -290,15 +289,20 @@ func writeMetricsToFile(tmpDir string, filledPct, rejectedPct float64) error { metricsWriter := bufio.NewWriter(metricsFile) - // Write filled and rejected percentages to the metrics file - _, err = metricsWriter.WriteString(fmt.Sprintf("Filled Percentage: %.2f%%\n", filledPct)) + // Write filled and new orders count, and success rate to the metrics file + _, err = metricsWriter.WriteString(fmt.Sprintf("Total New Orders: %v\n", newOrderCount)) + if err != nil { + return fmt.Errorf("error writing new orders count to metrics file: %v", err) + } + + _, err = metricsWriter.WriteString(fmt.Sprintf("Total Orders Successfully Filled: %v\n", filledCount)) if err != nil { - return fmt.Errorf("error writing filled percentage to metrics file: %v", err) + return fmt.Errorf("error writing filled orders count to metrics file: %v", err) } - _, err = metricsWriter.WriteString(fmt.Sprintf("Rejected Percentage: %.2f%%\n", rejectedPct)) + _, err = metricsWriter.WriteString(fmt.Sprintf("Success Rate: %.2f%%\n", successRate)) if err != nil { - return fmt.Errorf("error writing rejected percentage to metrics file: %v", err) + return fmt.Errorf("error writing success rate to metrics file: %v", err) } return metricsWriter.Flush() diff --git a/cmd/readmetrics/readmetrics_test.go b/cmd/readmetrics/readmetrics_test.go index 5d3921d..418d697 100644 --- a/cmd/readmetrics/readmetrics_test.go +++ b/cmd/readmetrics/readmetrics_test.go @@ -11,6 +11,7 @@ import ( // Mock function to simulate reading from a fixed logfile and generating expected latencies func TestCalculateLatenciesToFile(t *testing.T) { + // Prepare paths for log and temp directory logFilePath := "test_data/test.log" tmpDir := "test_data" @@ -28,6 +29,8 @@ func TestCalculateLatenciesToFile(t *testing.T) { require.NoError(t, err) // Define the expected latencies based on the mock data + // Latency 1: Time difference between first D message and first 8 message + // Latency 2: Time difference between second D message and second 8 message expectedLatencies := []string{ "Latency 1: 151 ms\n", "Latency 2: 156 ms\n", @@ -45,4 +48,7 @@ func TestCalculateLatenciesToFile(t *testing.T) { // Verify that the average latency is present and matches the expected value assert.Contains(t, string(metricsData), "Average Latency: 153.50 ms\n", "Average latency is incorrect") + + // Verify that the throughput data is correct + assert.Contains(t, string(metricsData), "Minute: 2024-11-06 13:48, Throughput: 2 orders/min", "Throughput data is incorrect") } diff --git a/cmd/readmetrics/test_data/test.log b/cmd/readmetrics/test_data/test.log new file mode 100644 index 0000000..eab2316 --- /dev/null +++ b/cmd/readmetrics/test_data/test.log @@ -0,0 +1,12 @@ +2024/11/06 13:47:56.002111 8=FIX.4.49=28235=A34=149=test_order52=20241106-13:47:56.00056=test_target96=c986f9e97370bfa6d15ec1a7667ba8c9aca9ccae7c9a047844fc4e71a8f0195b2fceb97dcfcbb997c3de93c897d716402be1bb17569b2c2eeee3d35db9daff0d98=0108=30141=Y554=4044a57206f7494b8692079e720aa911f3234e4d61079db28d36a405ae3630cb10=003 +2024/11/06 13:47:56.252103 8=FIX.4.49=8135=A34=149=test_target52=20241106-13:47:56.21056=test_order98=0108=30141=Y10=125 +2024/11/06 13:48:13.861610 8=FIX.4.49=15735=D34=249=test_order52=20241106-13:48:13.86156=test_target11=11111111121=138=0.019040=244=60000.0000054=255=BTC-USD59=460=20241106-13:48:13.86110=086 +2024/11/06 13:48:13.862631 8=FIX.4.49=15735=D34=349=test_order52=20241106-13:48:13.86256=test_target11=22222222221=138=0.015040=244=60000.0000054=255=BTC-USD59=460=20241106-13:48:13.86210=078 +2024/11/06 13:48:14.012654 8=FIX.4.49=27235=834=249=test_target52=20241106-13:48:13.97956=test_order1=default6=0.000011=11111111114=0.0000000017=11111112-4444-4444-4444-11111111111131=0.000032=0.0000000037=11111111-2222-3333-4444-55555555555538=0.0239=A40=254=255=BTC-USD58=150=A151=0.0190000010=050 +2024/11/06 13:48:14.019403 8=FIX.4.49=27235=834=349=test_target52=20241106-13:48:13.98756=test_order1=default6=0.000011=22222222214=0.0000000017=11111113-4444-4444-4444-11111111111131=0.000032=0.0000000037=22222222-3333-4444-5555-66666666666638=0.0239=A40=254=255=BTC-USD58=150=A151=0.0150000010=228 +2024/11/06 13:48:14.033887 8=FIX.4.49=27235=834=449=test_target52=20241106-13:48:13.99956=test_order1=default6=0.000011=11111111114=0.0000000017=11111114-4444-4444-4444-11111111111131=0.000032=0.0000000037=11111111-2222-3333-4444-55555555555538=0.0239=040=254=255=BTC-USD58=150=0151=0.0190000010=143 +2024/11/06 13:48:14.043048 8=FIX.4.49=28035=834=549=test_target52=20241106-13:48:14.00956=test_order1=default6=73940.630011=11111111114=0.0190000017=11111115-4444-4444-4444-11111111111131=73940.630032=0.0190000037=11111111-2222-3333-4444-55555555555538=0.0239=240=254=255=BTC-USD58=150=F151=0.0000000010=097 +2024/11/06 13:48:14.052181 8=FIX.4.49=27235=834=649=test_target52=20241106-13:48:14.01856=test_order1=default6=0.000011=22222222214=0.0000000017=11111116-4444-4444-4444-11111111111131=0.000032=0.0000000037=22222222-3333-4444-5555-66666666666638=0.0239=040=254=255=BTC-USD58=150=0151=0.0150000010=192 +2024/11/06 13:48:14.060262 8=FIX.4.49=28035=834=749=test_target52=20241106-13:48:14.02756=test_order1=default6=73941.070011=22222222214=0.0150000017=11111117-4444-4444-4444-11111111111131=73941.070032=0.0150000037=22222222-3333-4444-5555-66666666666638=0.0239=240=254=255=BTC-USD58=150=F151=0.0000000010=135 +2024/11/06 13:48:18.238506 8=FIX.4.49=6335=534=449=test_order52=20241106-13:48:18.23856=test_target10=055 +2024/11/06 13:48:18.305700 8=FIX.4.49=6335=534=849=test_target52=20241106-13:48:18.27056=test_order10=055 \ No newline at end of file diff --git a/go.mod b/go.mod index cf4800b..b469ab5 100644 --- a/go.mod +++ b/go.mod @@ -17,18 +17,24 @@ require ( github.com/quickfixgo/tag v0.1.0 github.com/shopspring/decimal v1.3.1 github.com/spf13/cobra v1.8.0 + github.com/stretchr/testify v1.9.0 ) require ( github.com/armon/go-proxyproto v0.1.0 // indirect + github.com/davecgh/go-spew v1.1.1 // indirect github.com/inconshreveable/mousetrap v1.1.0 // indirect + github.com/kr/pretty v0.3.1 // indirect github.com/mattn/go-colorable v0.1.13 // indirect github.com/mattn/go-isatty v0.0.20 // indirect github.com/mattn/go-runewidth v0.0.15 // indirect github.com/pkg/errors v0.9.1 // indirect + github.com/pmezard/go-difflib v1.0.0 // indirect github.com/quickfixgo/fixt11 v0.1.0 // indirect github.com/rivo/uniseg v0.4.4 // indirect github.com/spf13/pflag v1.0.5 // indirect + github.com/stretchr/objx v0.5.2 // indirect golang.org/x/net v0.18.0 // indirect golang.org/x/sys v0.14.0 // indirect + gopkg.in/yaml.v3 v3.0.1 // indirect ) diff --git a/go.sum b/go.sum index 4e86b54..ab459de 100644 --- a/go.sum +++ b/go.sum @@ -1,6 +1,7 @@ github.com/armon/go-proxyproto v0.1.0 h1:TWWcSsjco7o2itn6r25/5AqKBiWmsiuzsUDLT/MTl7k= github.com/armon/go-proxyproto v0.1.0/go.mod h1:Xj90dce2VKbHzRAeiVQAMBtj4M5oidoXJ8lmgyW21mw= github.com/cpuguy83/go-md2man/v2 v2.0.3/go.mod h1:tgQtvFlXSQOSOSIRvRPT7W67SCa46tRHOmNcaadrF8o= +github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E= github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c= github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38= github.com/fatih/color v1.16.0 h1:zmkK9Ngbjj+K0yRhTVONQh1p/HknKYSlNT+vZCzyokM= @@ -9,6 +10,10 @@ github.com/gosuri/uitable v0.0.4 h1:IG2xLKRvErL3uhY6e1BylFzG+aJiwQviDDTfOKeKTpY= github.com/gosuri/uitable v0.0.4/go.mod h1:tKR86bXuXPZazfOTG1FIzvjIdXzd0mo4Vtn16vt0PJo= github.com/inconshreveable/mousetrap v1.1.0 h1:wN+x4NVGpMsO7ErUn/mUI3vEoE6Jt13X2s0bqwp9tc8= github.com/inconshreveable/mousetrap v1.1.0/go.mod h1:vpF70FUmC8bwa3OWnCshd2FqLfsEA9PFc4w1p2J65bw= +github.com/kr/pretty v0.3.1 h1:flRD4NNwYAUpkphVc1HcthR4KEIFJ65n8Mw5qdRn3LE= +github.com/kr/pretty v0.3.1/go.mod h1:hoEshYVHaxMs3cyo3Yncou5ZscifuDolrwPKZanG3xk= +github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= +github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA= github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg= github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM= @@ -16,6 +21,7 @@ github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWE github.com/mattn/go-isatty v0.0.20/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= github.com/mattn/go-runewidth v0.0.15 h1:UNAjwbU9l54TA3KzvqLGxwWjHmMgBUVhBiTjelZgg3U= github.com/mattn/go-runewidth v0.0.15/go.mod h1:Jdepj2loyihRzMpdS35Xk/zdY8IAYHsh153qUoGf23w= +github.com/pkg/diff v0.0.0-20210226163009-20ebb0f2a09e/go.mod h1:pJLUxLENpZxwdsKMEsNbx1VGcRFpLqf3715MtcvvzbA= github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4= github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= @@ -45,6 +51,8 @@ github.com/quickfixgo/tag v0.1.0/go.mod h1:l/drB1eO3PwN9JQTDC9Vt2EqOcaXk3kGJ+eeC github.com/rivo/uniseg v0.2.0/go.mod h1:J6wj4VEh+S6ZtnVlnTBMWIodfgj8LQOQFoIToxlJtxc= github.com/rivo/uniseg v0.4.4 h1:8TfxU8dW6PdqD27gjM8MVNuicgxIjxpm4K7x4jp8sis= github.com/rivo/uniseg v0.4.4/go.mod h1:FN3SvrM+Zdj16jyLfmOkMNblXMcoc8DfTHruCPUcx88= +github.com/rogpeppe/go-internal v1.9.0 h1:73kH8U+JUqXU8lRuOHeVHaa/SZPifC7BkcraZVejAe8= +github.com/rogpeppe/go-internal v1.9.0/go.mod h1:WtVeX8xhTBvf0smdhujwtBcq4Qrzq/fJaraNFVN+nFs= github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= github.com/shopspring/decimal v1.3.1 h1:2Usl1nmF/WZucqkFZhnfFYxxxu8LG21F6nPQBE5gKV8= github.com/shopspring/decimal v1.3.1/go.mod h1:DKyhrW/HYNuLGql+MJL6WCR6knT2jwCFRcu2hWCYk4o= @@ -52,10 +60,10 @@ github.com/spf13/cobra v1.8.0 h1:7aJaZx1B85qltLMc546zn58BxxfZdR/W22ej9CFoEf0= github.com/spf13/cobra v1.8.0/go.mod h1:WXLWApfZ71AjXPya3WOlMsY9yMs7YeiHhFVlvLyhcho= github.com/spf13/pflag v1.0.5 h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA= github.com/spf13/pflag v1.0.5/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg= -github.com/stretchr/objx v0.5.0 h1:1zr/of2m5FGMsad5YfcqgdqdWrIhu+EBEJRhR1U7z/c= -github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo= -github.com/stretchr/testify v1.8.4 h1:CcVxjf3Q8PM0mHUKJCdn+eZZtm5yQwehR5yeSVQQcUk= -github.com/stretchr/testify v1.8.4/go.mod h1:sz/lmYIOXD/1dqDmKjjqLyZ2RngseejIcXlSw2iwfAo= +github.com/stretchr/objx v0.5.2 h1:xuMeJ0Sdp5ZMRXx/aWO6RZxdr3beISkG5/G/aIRr3pY= +github.com/stretchr/objx v0.5.2/go.mod h1:FRsXN1f5AsAjCGJKqEizvkpNtU+EGNCLh3NxZ/8L+MA= +github.com/stretchr/testify v1.9.0 h1:HtqpIVDClZ4nwg75+f6Lvsy/wHu+3BoSGCbBAcpTsTg= +github.com/stretchr/testify v1.9.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY= golang.org/x/net v0.18.0 h1:mIYleuAkSbHh0tCv7RvjL3F6ZVbLjq4+R7zbOn3Kokg= golang.org/x/net v0.18.0/go.mod h1:/czyP5RqHAH4odGYxBJ1qz0+CE5WZ+2j1YgoEo8F2jQ= golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= @@ -63,5 +71,7 @@ golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/sys v0.14.0 h1:Vz7Qs629MkJkGyHxUlRHizWJRG2j8fbQKjELVSNhy7Q= golang.org/x/sys v0.14.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA= gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0= +gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntNwaWcugrBjAiHlqqRiVk= +gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EVd6muEfDQjcINNoR0C8j2r3qZ4Q= gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA= gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM= From b1b9113404779f6672a6fa09eff0848ca5cf03f8 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Wed, 6 Nov 2024 18:34:56 +0000 Subject: [PATCH 16/19] lower price --- Makefile | 2 -- cmd/tradeclient/internal/console.go | 2 +- 2 files changed, 1 insertion(+), 3 deletions(-) diff --git a/Makefile b/Makefile index 26b1aab..6d59dde 100644 --- a/Makefile +++ b/Makefile @@ -15,8 +15,6 @@ clean: rm -rf ./bin rm -rf ./tmp rm -rf ./dist - rm -f output.log - rm -f metrics.log # Commands for docker images. # ---------------------------- diff --git a/cmd/tradeclient/internal/console.go b/cmd/tradeclient/internal/console.go index 68f21e2..072b722 100644 --- a/cmd/tradeclient/internal/console.go +++ b/cmd/tradeclient/internal/console.go @@ -568,7 +568,7 @@ func QueryEnterOrder(senderCompId, targetCompId string) (err error) { case quickfix.BeginStringFIX44: symbol := "BTC-USD" - price := "60000" + price := "60" var side, qty string midsize := 0.01 From ca21f14cdfa28d69bb0f9f1e850ea0001f990d5e Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Wed, 6 Nov 2024 18:36:42 +0000 Subject: [PATCH 17/19] remove log --- cmd/tradeclient/tradeclient.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/cmd/tradeclient/tradeclient.go b/cmd/tradeclient/tradeclient.go index 3b4af9c..5b8aa09 100644 --- a/cmd/tradeclient/tradeclient.go +++ b/cmd/tradeclient/tradeclient.go @@ -70,7 +70,7 @@ const ( // Constants for file paths LogFilePath = "tmp/FIX.4.4-CUST2_Order-ANCHORAGE.messages.current.log" OutputFilePath = "tmp/log_data.json" - TmpDir = "tmp/" + TmpDir = "tmp/" ) // ToAdmin implemented as part of Application interface @@ -132,7 +132,7 @@ func (e TradeClient) sign(logonmsg *quickfix.Message) (string, error) { // ToApp implemented as part of Application interface func (e TradeClient) ToApp(msg *quickfix.Message, sessionID quickfix.SessionID) (err error) { - utils.PrintInfo(fmt.Sprintf("Sending: %s", msg.String())) + // utils.PrintInfo(fmt.Sprintf("Sending: %s", msg.String())) return } From d257947a9025cf844339cd479c4dccb339fe8c72 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Thu, 7 Nov 2024 13:10:51 +0000 Subject: [PATCH 18/19] documentation --- cmd/readmetrics/README.md | 47 ------------ cmd/readmetrics/readmetrics.go | 92 ++++++++++++++---------- cmd/readmetrics/test_data/test_data.json | 58 --------------- cmd/tradeclient/loadtest/README.md | 16 ++--- 4 files changed, 63 insertions(+), 150 deletions(-) delete mode 100644 cmd/readmetrics/README.md delete mode 100644 cmd/readmetrics/test_data/test_data.json diff --git a/cmd/readmetrics/README.md b/cmd/readmetrics/README.md deleted file mode 100644 index b637baa..0000000 --- a/cmd/readmetrics/README.md +++ /dev/null @@ -1,47 +0,0 @@ -# ReadMetrics - -The `readmetrics` command is a tool for reading and processing metrics from a FIX log file. It calculates the latency and intervals between messages and logs them to a separate metrics file for analysis. - -## Features - -- Reads FIX log files and extracts relevant timestamps. -- Calculates latency and interval in milliseconds. -- Outputs metrics to a `metrics.log` file. - -## Usage - -To use the `readmetrics` command, run the following command in your terminal: - -``` -./bin/qf readmetrics -``` - -Replace `` with the path to your FIX log file. - -## Output - -The results will be written to a file named `metrics.log` in the current directory. The log will contain entries formatted as follows: - -``` -Message 1: Interval = X.XXXms, Latency = Y.YYYms -``` - -Where `X.XXX` is the interval between messages, and `Y.YYY` is the calculated latency. - -## Example - -Assuming you have a FIX log file named `example.log`, you can run: - -``` -./bin/qf readmetrics example.log -``` - -After execution, you can check the contents of `metrics.log`: - -You should see output similar to: - -``` -Message 1: Interval = 1.000ms, Latency = 0.647ms -Message 2: Interval = 1.000ms, Latency = 0.685ms -... -``` \ No newline at end of file diff --git a/cmd/readmetrics/readmetrics.go b/cmd/readmetrics/readmetrics.go index ebafb39..ffa33b8 100644 --- a/cmd/readmetrics/readmetrics.go +++ b/cmd/readmetrics/readmetrics.go @@ -10,50 +10,57 @@ import ( "time" ) -// LogEntry represents a structure for the relevant log information +// LogEntry represents the structure of a log entry parsed from the raw log. type LogEntry struct { - MessageType string `json:"message_type"` - Timestamp string `json:"timestamp"` - Fields map[string]string `json:"fields"` + MessageType string `json:"message_type"` // Type of message (e.g., "D", "8"). + Timestamp string `json:"timestamp"` // Timestamp of the log entry. + Fields map[string]string `json:"fields"` // Additional fields in the log. } -// Struct to store log entries +// LogMetricsEntry stores parsed information for latency and throughput calculations. type LogMetricsEntry struct { - timestamp time.Time - msgType string - clOrdID string + timestamp time.Time // Timestamp of the message. + msgType string // Type of message (e.g., "D", "8"). + clOrdID string // Client Order ID. } -// Execute reads the log file, extracts relevant information, and saves it as JSON +// Execute processes the log file, calculates metrics, and saves them to output files. func Execute(logFilePath, outputFilePath, tmpDir string) error { + // Get the current working directory dir, err := os.Getwd() if err != nil { return fmt.Errorf("error getting working directory: %v", err) } + // Open the log file logFile, err := os.Open(filepath.Join(dir, logFilePath)) if err != nil { return fmt.Errorf("error opening log file: %v", err) } defer logFile.Close() + // Prepare a scanner to read the log file line by line scanner := bufio.NewScanner(logFile) entries := make([]LogEntry, 0) + // Read each line in the log file and parse relevant entries for scanner.Scan() { line := scanner.Text() + // Filter lines that are message type "D" or "8" if strings.Contains(line, "35=D") || strings.Contains(line, "35=8") { entry := LogEntry{ Fields: make(map[string]string), } + // Split the line by spaces and process the parts parts := strings.Split(line, " ") if len(parts) > 2 { + // Extract message type and timestamp entry.MessageType = strings.Split(parts[2], "\u0001")[0] entry.Timestamp = parts[1] - // Extract fields + // Extract fields (key-value pairs) from the log for _, part := range parts { if strings.Contains(part, "=") { keyValue := strings.SplitN(part, "=", 2) @@ -64,7 +71,7 @@ func Execute(logFilePath, outputFilePath, tmpDir string) error { } } - entries = append(entries, entry) + entries = append(entries, entry) // Add the entry to the list } } @@ -72,21 +79,23 @@ func Execute(logFilePath, outputFilePath, tmpDir string) error { return fmt.Errorf("error reading log file: %v", err) } + // Save the parsed entries to a JSON file if err := saveToJSON(entries, outputFilePath); err != nil { return fmt.Errorf("error saving to JSON: %v", err) } + // Calculate latencies and save them if err := CalculateLatenciesToFile(logFilePath, tmpDir); err != nil { return fmt.Errorf("error calculating latencies: %v", err) } - // Count filled and new orders and calculate success rate + // Calculate success rates for orders filledCount, newOrderCount, successRate, err := countFilledOrders(logFilePath) if err != nil { - return fmt.Errorf("error calculating success/failure percentages: %v", err) + return fmt.Errorf("error calculating success percentages: %v", err) } - // Write metrics (new orders, filled orders, success rate) to the metrics file + // Write the calculated metrics to file if err := writeMetricsToFile(tmpDir, filledCount, newOrderCount, successRate); err != nil { return fmt.Errorf("error writing metrics to file: %v", err) } @@ -95,23 +104,28 @@ func Execute(logFilePath, outputFilePath, tmpDir string) error { return nil } -// saveToJSON converts entries to JSON format and saves to a file +// saveToJSON saves the parsed log entries to a JSON file. func saveToJSON(entries []LogEntry, outputFilePath string) error { + // Marshal entries into JSON format jsonData, err := json.MarshalIndent(entries, "", " ") if err != nil { return fmt.Errorf("error converting to JSON: %v", err) } + // Get the current working directory to create the output file path dir, err := os.Getwd() if err != nil { return fmt.Errorf("error getting working directory: %v", err) } + + // Create and open the output file outputFile, err := os.Create(filepath.Join(dir, outputFilePath)) if err != nil { return fmt.Errorf("error creating output file: %v", err) } defer outputFile.Close() + // Write the JSON data to the file _, err = outputFile.Write(jsonData) if err != nil { return fmt.Errorf("error writing to output file: %v", err) @@ -120,10 +134,13 @@ func saveToJSON(entries []LogEntry, outputFilePath string) error { return nil } -// parseFIXMessage parses a FIX message from a log line. +// parseFIXMessage parses a single FIX message and returns the relevant data. func parseFIXMessage(line string) (LogMetricsEntry, error) { + // Split the line by the FIX field delimiter fields := strings.Split(line, "") msg := LogMetricsEntry{} + + // Parse the timestamp from the first 26 characters of the line timestampStr := line[:26] timestamp, err := time.Parse("2006/01/02 15:04:05.000000", timestampStr) if err != nil { @@ -131,6 +148,7 @@ func parseFIXMessage(line string) (LogMetricsEntry, error) { } msg.timestamp = timestamp + // Extract message type and client order ID for _, field := range fields { if strings.HasPrefix(field, "35=") { msg.msgType = strings.TrimPrefix(field, "35=") @@ -141,19 +159,21 @@ func parseFIXMessage(line string) (LogMetricsEntry, error) { return msg, nil } -// CalculateLatenciesToFile reads a log file, calculates latencies for 35=D messages, -// and writes the latencies and throughput to separate files in the specified directory. +// CalculateLatenciesToFile calculates the latencies between orders and saves the results to files. func CalculateLatenciesToFile(logFilePath, tmpDir string) error { + // Open the log file for reading file, err := os.Open(logFilePath) if err != nil { return fmt.Errorf("error opening file: %v", err) } defer file.Close() + // Initialize variables for storing latency data dMessages := make(map[string]LogMetricsEntry) - latencies := []int64{} // Store latencies in an array for average calculation + latencies := []int64{} throughputCounts := make(map[time.Time]int) + // Read each line of the log and calculate latencies scanner := bufio.NewScanner(file) for scanner.Scan() { line := scanner.Text() @@ -163,28 +183,26 @@ func CalculateLatenciesToFile(logFilePath, tmpDir string) error { continue } - // Track 35=D message timestamps for latency and throughput + // Track order creation ("D") messages and calculate latency for execution ("8") messages if msg.msgType == "D" { dMessages[msg.clOrdID] = msg - - // Round down timestamp to the nearest minute for throughput calculation minute := msg.timestamp.Truncate(time.Minute) throughputCounts[minute]++ } else if msg.msgType == "8" && msg.clOrdID != "" { - // Calculate latency if dMsg, found := dMessages[msg.clOrdID]; found { latency := msg.timestamp.Sub(dMsg.timestamp).Milliseconds() latencies = append(latencies, latency) - delete(dMessages, msg.clOrdID) // Remove to avoid multiple calculations for same ClOrdID + delete(dMessages, msg.clOrdID) } } } + // Handle any errors encountered during scanning if err := scanner.Err(); err != nil { return fmt.Errorf("error reading file: %v", err) } - // Write latencies to a separate file in the tmpDir directory + // Save latencies to a file latencyFile, err := os.Create(filepath.Join(tmpDir, "latencies.txt")) if err != nil { return fmt.Errorf("error creating latencies file: %v", err) @@ -192,8 +210,6 @@ func CalculateLatenciesToFile(logFilePath, tmpDir string) error { defer latencyFile.Close() writer := bufio.NewWriter(latencyFile) - - // Write latency data for index, latency := range latencies { _, err := writer.WriteString(fmt.Sprintf("Latency %d: %d ms\n", index+1, latency)) if err != nil { @@ -210,7 +226,7 @@ func CalculateLatenciesToFile(logFilePath, tmpDir string) error { averageLatency /= float64(len(latencies)) } - // Write output for average latency and throughput to another file in tmpDir + // Save the metrics (average latency, throughput) to file metricsFile, err := os.Create(filepath.Join(tmpDir, "metrics.txt")) if err != nil { return fmt.Errorf("error creating metrics file: %v", err) @@ -218,8 +234,6 @@ func CalculateLatenciesToFile(logFilePath, tmpDir string) error { defer metricsFile.Close() metricsWriter := bufio.NewWriter(metricsFile) - - // Write the average latency to the metrics file _, err = metricsWriter.WriteString(fmt.Sprintf("Average Latency: %.2f ms\n", averageLatency)) if err != nil { return fmt.Errorf("error writing average latency to metrics file: %v", err) @@ -240,9 +254,9 @@ func CalculateLatenciesToFile(logFilePath, tmpDir string) error { return nil } -// countFilledOrders reads a FIX log file and counts how many orders were filled (150=F), -// as well as the number of new orders (35=D), and calculates the success rate. +// countFilledOrders counts the number of filled and new orders and calculates the success rate. func countFilledOrders(logFilePath string) (int, int, float64, error) { + // Open the log file for scanning file, err := os.Open(logFilePath) if err != nil { return 0, 0, 0, fmt.Errorf("failed to open log file: %v", err) @@ -251,26 +265,28 @@ func countFilledOrders(logFilePath string) (int, int, float64, error) { var filledCount, newOrderCount int + // Scan the file line by line scanner := bufio.NewScanner(file) for scanner.Scan() { line := scanner.Text() - // Check if the line contains 35=D (new order) + // Count new orders (type "D") if strings.Contains(line, "35=D") { newOrderCount++ } - // Check if the line contains 150=F (filled order) + // Count filled orders (150=F) if strings.Contains(line, "150=F") { filledCount++ } } + // Handle any errors encountered during scanning if err := scanner.Err(); err != nil { return 0, 0, 0, fmt.Errorf("failed to scan log file: %v", err) } - // Calculate success rate (if newOrderCount > 0 to avoid division by zero) + // Calculate the success rate var successRate float64 if newOrderCount > 0 { successRate = float64(filledCount) / float64(newOrderCount) * 100 @@ -279,8 +295,9 @@ func countFilledOrders(logFilePath string) (int, int, float64, error) { return filledCount, newOrderCount, successRate, nil } -// writeMetricsToFile writes the filled and new orders count, and the success rate to the metrics file +// writeMetricsToFile appends metrics data (new orders, filled orders, success rate) to a file. func writeMetricsToFile(tmpDir string, filledCount, newOrderCount int, successRate float64) error { + // Open the metrics file for appending metricsFile, err := os.OpenFile(filepath.Join(tmpDir, "metrics.txt"), os.O_APPEND|os.O_WRONLY, 0644) if err != nil { return fmt.Errorf("error opening metrics file: %v", err) @@ -289,7 +306,7 @@ func writeMetricsToFile(tmpDir string, filledCount, newOrderCount int, successRa metricsWriter := bufio.NewWriter(metricsFile) - // Write filled and new orders count, and success rate to the metrics file + // Write the metrics data (new orders, filled orders, success rate) to the file _, err = metricsWriter.WriteString(fmt.Sprintf("Total New Orders: %v\n", newOrderCount)) if err != nil { return fmt.Errorf("error writing new orders count to metrics file: %v", err) @@ -305,5 +322,6 @@ func writeMetricsToFile(tmpDir string, filledCount, newOrderCount int, successRa return fmt.Errorf("error writing success rate to metrics file: %v", err) } + // Flush the buffered writer to ensure data is written to file return metricsWriter.Flush() } diff --git a/cmd/readmetrics/test_data/test_data.json b/cmd/readmetrics/test_data/test_data.json deleted file mode 100644 index 3bd5e22..0000000 --- a/cmd/readmetrics/test_data/test_data.json +++ /dev/null @@ -1,58 +0,0 @@ -[ - { - "message_type": "8=FIX.4.4", - "timestamp": "13:48:13.861610", - "fields": { - "8": "FIX.4.4\u00019=157\u000135=D\u000134=2\u000149=test_order\u000152=20241106-13:48:13.861\u000156=test_target\u000111=111111111\u000121=1\u000138=0.0190\u000140=2\u000144=60000.00000\u000154=2\u000155=BTC-USD\u000159=4\u000160=20241106-13:48:13.861\u000110=086\u0001" - } - }, - { - "message_type": "8=FIX.4.4", - "timestamp": "13:48:13.862631", - "fields": { - "8": "FIX.4.4\u00019=157\u000135=D\u000134=3\u000149=test_order\u000152=20241106-13:48:13.862\u000156=test_target\u000111=222222222\u000121=1\u000138=0.0150\u000140=2\u000144=60000.00000\u000154=2\u000155=BTC-USD\u000159=4\u000160=20241106-13:48:13.862\u000110=078\u0001" - } - }, - { - "message_type": "8=FIX.4.4", - "timestamp": "13:48:14.012654", - "fields": { - "8": "FIX.4.4\u00019=272\u000135=8\u000134=2\u000149=test_target\u000152=20241106-13:48:13.979\u000156=test_order\u00011=default\u00016=0.0000\u000111=111111111\u000114=0.00000000\u000117=11111112-4444-4444-4444-111111111111\u000131=0.0000\u000132=0.00000000\u000137=11111111-2222-3333-4444-555555555555\u000138=0.02\u000139=A\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=A\u0001151=0.01900000\u000110=050\u0001" - } - }, - { - "message_type": "8=FIX.4.4", - "timestamp": "13:48:14.019403", - "fields": { - "8": "FIX.4.4\u00019=272\u000135=8\u000134=3\u000149=test_target\u000152=20241106-13:48:13.987\u000156=test_order\u00011=default\u00016=0.0000\u000111=222222222\u000114=0.00000000\u000117=11111113-4444-4444-4444-111111111111\u000131=0.0000\u000132=0.00000000\u000137=22222222-3333-4444-5555-666666666666\u000138=0.02\u000139=A\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=A\u0001151=0.01500000\u000110=228\u0001" - } - }, - { - "message_type": "8=FIX.4.4", - "timestamp": "13:48:14.033887", - "fields": { - "8": "FIX.4.4\u00019=272\u000135=8\u000134=4\u000149=test_target\u000152=20241106-13:48:13.999\u000156=test_order\u00011=default\u00016=0.0000\u000111=111111111\u000114=0.00000000\u000117=11111114-4444-4444-4444-111111111111\u000131=0.0000\u000132=0.00000000\u000137=11111111-2222-3333-4444-555555555555\u000138=0.02\u000139=0\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=0\u0001151=0.01900000\u000110=143\u0001" - } - }, - { - "message_type": "8=FIX.4.4", - "timestamp": "13:48:14.043048", - "fields": { - "8": "FIX.4.4\u00019=280\u000135=8\u000134=5\u000149=test_target\u000152=20241106-13:48:14.009\u000156=test_order\u00011=default\u00016=73940.6300\u000111=111111111\u000114=0.01900000\u000117=11111115-4444-4444-4444-111111111111\u000131=73940.6300\u000132=0.01900000\u000137=11111111-2222-3333-4444-555555555555\u000138=0.02\u000139=2\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=F\u0001151=0.00000000\u000110=097\u0001" - } - }, - { - "message_type": "8=FIX.4.4", - "timestamp": "13:48:14.052181", - "fields": { - "8": "FIX.4.4\u00019=272\u000135=8\u000134=6\u000149=test_target\u000152=20241106-13:48:14.018\u000156=test_order\u00011=default\u00016=0.0000\u000111=222222222\u000114=0.00000000\u000117=11111116-4444-4444-4444-111111111111\u000131=0.0000\u000132=0.00000000\u000137=22222222-3333-4444-5555-666666666666\u000138=0.02\u000139=0\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=0\u0001151=0.01500000\u000110=192\u0001" - } - }, - { - "message_type": "8=FIX.4.4", - "timestamp": "13:48:14.060262", - "fields": { - "8": "FIX.4.4\u00019=280\u000135=8\u000134=7\u000149=test_target\u000152=20241106-13:48:14.027\u000156=test_order\u00011=default\u00016=73941.0700\u000111=222222222\u000114=0.01500000\u000117=11111117-4444-4444-4444-111111111111\u000131=73941.0700\u000132=0.01500000\u000137=22222222-3333-4444-5555-666666666666\u000138=0.02\u000139=2\u000140=2\u000154=2\u000155=BTC-USD\u000158=\u0001150=F\u0001151=0.00000000\u000110=135\u0001" - } - } -] \ No newline at end of file diff --git a/cmd/tradeclient/loadtest/README.md b/cmd/tradeclient/loadtest/README.md index bb1e74e..74e606f 100644 --- a/cmd/tradeclient/loadtest/README.md +++ b/cmd/tradeclient/loadtest/README.md @@ -5,8 +5,7 @@ This load test evaluates the performance of the TradeClient by simulating the submission of multiple orders in a specified time frame. The primary focus is to measure the success/failure percentage of the orders processed, while performance analysis will be derived from log files. ## Types of Tests Running -- **Load Test**: Simulates the submission of multiple orders to evaluate the success and failure rates. -- **Performance Metrics**: Uses existing logs to analyze response times and latencies for orders processed. +- **Load Test**: Simulates the submission of a high volume of orders at configurable rates. ## How to Run the Tests 1. **Build the TradeClient**: @@ -21,12 +20,13 @@ This load test evaluates the performance of the TradeClient by simulating the su 3. **Select Load Test**: - You will be prompted with the following options: - 1) Enter Order - 2) Cancel Order - 3) Request Market Data - 4) Run Load Test - 5) Quit + 1) Enter Order + 2) Cancel Order + 3) Request Market Data + 4) Run Load Test + 5) Read metrics + 6) Quit - Choose **4** to initiate the load test. ## Outputs -- The results of the load test, including success and failure rates, will be logged to `output.log`. + - Log files will be generated in the tmp folder. To view calculated metrics based on these logs, select 5 from the menu (Read Metrics). From 514d3757e54f35edbea1f5f75b4870ea3d88608c Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Thu, 7 Nov 2024 13:47:11 +0000 Subject: [PATCH 19/19] cadency --- cmd/tradeclient/loadtest/loadtest.go | 9 +++-- cmd/tradeclient/tradeclient.go | 52 +++++++++++++++++++++++++--- 2 files changed, 54 insertions(+), 7 deletions(-) diff --git a/cmd/tradeclient/loadtest/loadtest.go b/cmd/tradeclient/loadtest/loadtest.go index 5807e40..597fe38 100644 --- a/cmd/tradeclient/loadtest/loadtest.go +++ b/cmd/tradeclient/loadtest/loadtest.go @@ -16,11 +16,11 @@ type LoadTestConfig struct { TargetCompID string } -// RunLoadTest sends orders based on the provided configuration. +// sends orders based on the provided configuration. func RunLoadTest(cfg LoadTestConfig) { var wg sync.WaitGroup - // Launch goroutines to send orders at the specified rate + // send orders at the specified rate for i := 0; i < cfg.TotalOrders; i++ { wg.Add(1) go func(orderID int) { @@ -34,4 +34,9 @@ func RunLoadTest(cfg LoadTestConfig) { // Delay to maintain order rate time.Sleep(time.Second / time.Duration(cfg.OrdersPerSecond)) } + + // Wait for all goroutines to complete + wg.Wait() + + fmt.Println("Load test finished, all orders have been processed.") } diff --git a/cmd/tradeclient/tradeclient.go b/cmd/tradeclient/tradeclient.go index 5b8aa09..033956a 100644 --- a/cmd/tradeclient/tradeclient.go +++ b/cmd/tradeclient/tradeclient.go @@ -25,6 +25,7 @@ import ( "os" "path" "strconv" + "time" "github.com/quickfixgo/examples/cmd/readmetrics" "github.com/quickfixgo/examples/cmd/tradeclient/internal" @@ -233,10 +234,8 @@ Loop: err = internal.QueryMarketDataRequest("CUST2_Marketdata", "ANCHORAGE") case "4": - var ordersPerSecond int - var totalOrders int - // Prompt the user for orders per second + var ordersPerSecond int fmt.Print("Enter orders per second: ") _, err := fmt.Scanf("%d", &ordersPerSecond) if err != nil { @@ -245,6 +244,7 @@ Loop: } // Prompt the user for total number of orders + var totalOrders int fmt.Print("Enter total number of orders: ") _, err = fmt.Scanf("%d", &totalOrders) if err != nil { @@ -252,6 +252,15 @@ Loop: break } + // Ask if the user wants to set a cadency + var setCadency string + fmt.Print("Do you want to set a cadency for the load test? (yes/no): ") + _, err = fmt.Scanf("%s", &setCadency) + if err != nil { + utils.PrintBad("Invalid input for cadency choice") + break + } + // Create load test configuration loadTestConfig := loadtest.LoadTestConfig{ OrdersPerSecond: ordersPerSecond, @@ -260,8 +269,41 @@ Loop: TargetCompID: "ANCHORAGE", } - // Run the load test - loadtest.RunLoadTest(loadTestConfig) + if setCadency == "yes" { + // Prompt the user for cadency + var cadencyInput string + fmt.Print("Enter the cadency (e.g., '10m' for 10 minutes, '1d' for every day, '3d' for every 3 days): ") + _, err = fmt.Scanf("%s", &cadencyInput) + if err != nil { + utils.PrintBad("Invalid input for cadency") + break + } + + // Parse the cadency input into a time.Duration + interval, err := time.ParseDuration(cadencyInput) + if err != nil { + utils.PrintBad("Invalid cadency format") + break + } + + // Run the load test at the specified interval + fmt.Printf("Starting load test every %v...\n", interval) + + // Loop to run the load test at the specified interval + for { + // Run the load test + loadtest.RunLoadTest(loadTestConfig) + + // Wait for the next interval + fmt.Printf("Waiting for next load test after %v...\n", interval) + time.Sleep(interval) + } + } else if setCadency == "no" { + // Run once without cadency + loadtest.RunLoadTest(loadTestConfig) + } else { + utils.PrintBad("Invalid input for cadency choice") + } case "5": // Call readmetrics after the load test