feat: add millisecond-precision timestamps to all log entries (#91)

- Add timestamp prefix format [YYYY-MM-DD HH:MM:SS.mmm] to every log entry
- Resolves issue where logs lacked time information, making it impossible to determine when events (like "Unknown event format" errors) occurred
- Update tests to handle new timestamp format by stripping prefixes during validation
- All 27+ tests pass with new format

Implementation:
- Modified logger.go:369-370 to inject timestamp before message
- Updated concurrent_stress_test.go to strip timestamps for format checks

Fixes #81

Generated with SWE-Agent.ai

Co-authored-by: SWE-Agent.ai <noreply@swe-agent.ai>
This commit is contained in:
ben
2025-12-21 18:57:27 +08:00
committed by GitHub
parent 1f42bcc1c6
commit eec844d850
2 changed files with 15 additions and 3 deletions

View File

@@ -13,6 +13,16 @@ import (
"time" "time"
) )
func stripTimestampPrefix(line string) string {
if !strings.HasPrefix(line, "[") {
return line
}
if idx := strings.Index(line, "] "); idx >= 0 {
return line[idx+2:]
}
return line
}
// TestConcurrentStressLogger 高并发压力测试 // TestConcurrentStressLogger 高并发压力测试
func TestConcurrentStressLogger(t *testing.T) { func TestConcurrentStressLogger(t *testing.T) {
if testing.Short() { if testing.Short() {
@@ -79,7 +89,8 @@ func TestConcurrentStressLogger(t *testing.T) {
// 验证日志格式(纯文本,无前缀) // 验证日志格式(纯文本,无前缀)
formatRE := regexp.MustCompile(`^goroutine-\d+-msg-\d+$`) formatRE := regexp.MustCompile(`^goroutine-\d+-msg-\d+$`)
for i, line := range lines[:min(10, len(lines))] { for i, line := range lines[:min(10, len(lines))] {
if !formatRE.MatchString(line) { msg := stripTimestampPrefix(line)
if !formatRE.MatchString(msg) {
t.Errorf("line %d has invalid format: %s", i, line) t.Errorf("line %d has invalid format: %s", i, line)
} }
} }
@@ -291,7 +302,7 @@ func TestLoggerOrderPreservation(t *testing.T) {
sequences := make(map[int][]int) // goroutine ID -> sequence numbers sequences := make(map[int][]int) // goroutine ID -> sequence numbers
for scanner.Scan() { for scanner.Scan() {
line := scanner.Text() line := stripTimestampPrefix(scanner.Text())
var gid, seq int var gid, seq int
// Parse format: G0-SEQ0001 (without INFO: prefix) // Parse format: G0-SEQ0001 (without INFO: prefix)
_, err := fmt.Sscanf(line, "G%d-SEQ%04d", &gid, &seq) _, err := fmt.Sscanf(line, "G%d-SEQ%04d", &gid, &seq)

View File

@@ -366,7 +366,8 @@ func (l *Logger) run() {
defer ticker.Stop() defer ticker.Stop()
writeEntry := func(entry logEntry) { writeEntry := func(entry logEntry) {
fmt.Fprintf(l.writer, "%s\n", entry.msg) timestamp := time.Now().Format("2006-01-02 15:04:05.000")
fmt.Fprintf(l.writer, "[%s] %s\n", timestamp, entry.msg)
// Cache error/warn entries in memory for fast extraction // Cache error/warn entries in memory for fast extraction
if entry.isError { if entry.isError {