From d257947a9025cf844339cd479c4dccb339fe8c72 Mon Sep 17 00:00:00 2001 From: Joao Ferreira Date: Thu, 7 Nov 2024 13:10:51 +0000 Subject: [PATCH] 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).