diff --git a/internal/api/middleware/request_logging.go b/internal/api/middleware/request_logging.go index 49f28f52..2c9fdbdd 100644 --- a/internal/api/middleware/request_logging.go +++ b/internal/api/middleware/request_logging.go @@ -8,6 +8,7 @@ import ( "io" "net/http" "strings" + "time" "github.com/gin-gonic/gin" "github.com/router-for-me/CLIProxyAPI/v6/internal/logging" @@ -103,6 +104,7 @@ func captureRequestInfo(c *gin.Context) (*RequestInfo, error) { Headers: headers, Body: body, RequestID: logging.GetGinRequestID(c), + Timestamp: time.Now(), }, nil } diff --git a/internal/api/middleware/response_writer.go b/internal/api/middleware/response_writer.go index 8029e50a..8272c868 100644 --- a/internal/api/middleware/response_writer.go +++ b/internal/api/middleware/response_writer.go @@ -7,6 +7,7 @@ import ( "bytes" "net/http" "strings" + "time" "github.com/gin-gonic/gin" "github.com/router-for-me/CLIProxyAPI/v6/internal/interfaces" @@ -20,6 +21,7 @@ type RequestInfo struct { Headers map[string][]string // Headers contains the request headers. Body []byte // Body is the raw request body. RequestID string // RequestID is the unique identifier for the request. + Timestamp time.Time // Timestamp is when the request was received. } // ResponseWriterWrapper wraps the standard gin.ResponseWriter to intercept and log response data. @@ -297,7 +299,7 @@ func (w *ResponseWriterWrapper) Finalize(c *gin.Context) error { return nil } - return w.logRequest(finalStatusCode, w.cloneHeaders(), w.body.Bytes(), w.extractAPIRequest(c), w.extractAPIResponse(c), slicesAPIResponseError, forceLog) + return w.logRequest(finalStatusCode, w.cloneHeaders(), w.body.Bytes(), w.extractAPIRequest(c), w.extractAPIResponse(c), w.extractAPIResponseTimestamp(c), slicesAPIResponseError, forceLog) } func (w *ResponseWriterWrapper) cloneHeaders() map[string][]string { @@ -337,7 +339,18 @@ func (w *ResponseWriterWrapper) extractAPIResponse(c *gin.Context) []byte { return data } -func (w *ResponseWriterWrapper) logRequest(statusCode int, headers map[string][]string, body []byte, apiRequestBody, apiResponseBody []byte, apiResponseErrors []*interfaces.ErrorMessage, forceLog bool) error { +func (w *ResponseWriterWrapper) extractAPIResponseTimestamp(c *gin.Context) time.Time { + ts, isExist := c.Get("API_RESPONSE_TIMESTAMP") + if !isExist { + return time.Time{} + } + if t, ok := ts.(time.Time); ok { + return t + } + return time.Time{} +} + +func (w *ResponseWriterWrapper) logRequest(statusCode int, headers map[string][]string, body []byte, apiRequestBody, apiResponseBody []byte, apiResponseTimestamp time.Time, apiResponseErrors []*interfaces.ErrorMessage, forceLog bool) error { if w.requestInfo == nil { return nil } @@ -348,7 +361,7 @@ func (w *ResponseWriterWrapper) logRequest(statusCode int, headers map[string][] } if loggerWithOptions, ok := w.logger.(interface { - LogRequestWithOptions(string, string, map[string][]string, []byte, int, map[string][]string, []byte, []byte, []byte, []*interfaces.ErrorMessage, bool, string) error + LogRequestWithOptions(string, string, map[string][]string, []byte, int, map[string][]string, []byte, []byte, []byte, []*interfaces.ErrorMessage, bool, string, time.Time, time.Time) error }); ok { return loggerWithOptions.LogRequestWithOptions( w.requestInfo.URL, @@ -363,6 +376,8 @@ func (w *ResponseWriterWrapper) logRequest(statusCode int, headers map[string][] apiResponseErrors, forceLog, w.requestInfo.RequestID, + w.requestInfo.Timestamp, + apiResponseTimestamp, ) } diff --git a/internal/logging/request_logger.go b/internal/logging/request_logger.go index 397a4a08..44df43d3 100644 --- a/internal/logging/request_logger.go +++ b/internal/logging/request_logger.go @@ -184,16 +184,16 @@ func (l *FileRequestLogger) SetEnabled(enabled bool) { // Returns: // - error: An error if logging fails, nil otherwise func (l *FileRequestLogger) LogRequest(url, method string, requestHeaders map[string][]string, body []byte, statusCode int, responseHeaders map[string][]string, response, apiRequest, apiResponse []byte, apiResponseErrors []*interfaces.ErrorMessage, requestID string) error { - return l.logRequest(url, method, requestHeaders, body, statusCode, responseHeaders, response, apiRequest, apiResponse, apiResponseErrors, false, requestID) + return l.logRequest(url, method, requestHeaders, body, statusCode, responseHeaders, response, apiRequest, apiResponse, apiResponseErrors, false, requestID, time.Time{}, time.Time{}) } // LogRequestWithOptions logs a request with optional forced logging behavior. // The force flag allows writing error logs even when regular request logging is disabled. -func (l *FileRequestLogger) LogRequestWithOptions(url, method string, requestHeaders map[string][]string, body []byte, statusCode int, responseHeaders map[string][]string, response, apiRequest, apiResponse []byte, apiResponseErrors []*interfaces.ErrorMessage, force bool, requestID string) error { - return l.logRequest(url, method, requestHeaders, body, statusCode, responseHeaders, response, apiRequest, apiResponse, apiResponseErrors, force, requestID) +func (l *FileRequestLogger) LogRequestWithOptions(url, method string, requestHeaders map[string][]string, body []byte, statusCode int, responseHeaders map[string][]string, response, apiRequest, apiResponse []byte, apiResponseErrors []*interfaces.ErrorMessage, force bool, requestID string, requestTimestamp, apiResponseTimestamp time.Time) error { + return l.logRequest(url, method, requestHeaders, body, statusCode, responseHeaders, response, apiRequest, apiResponse, apiResponseErrors, force, requestID, requestTimestamp, apiResponseTimestamp) } -func (l *FileRequestLogger) logRequest(url, method string, requestHeaders map[string][]string, body []byte, statusCode int, responseHeaders map[string][]string, response, apiRequest, apiResponse []byte, apiResponseErrors []*interfaces.ErrorMessage, force bool, requestID string) error { +func (l *FileRequestLogger) logRequest(url, method string, requestHeaders map[string][]string, body []byte, statusCode int, responseHeaders map[string][]string, response, apiRequest, apiResponse []byte, apiResponseErrors []*interfaces.ErrorMessage, force bool, requestID string, requestTimestamp, apiResponseTimestamp time.Time) error { if !l.enabled && !force { return nil } @@ -247,6 +247,8 @@ func (l *FileRequestLogger) logRequest(url, method string, requestHeaders map[st responseHeaders, responseToWrite, decompressErr, + requestTimestamp, + apiResponseTimestamp, ) if errClose := logFile.Close(); errClose != nil { log.WithError(errClose).Warn("failed to close request log file") @@ -499,17 +501,22 @@ func (l *FileRequestLogger) writeNonStreamingLog( responseHeaders map[string][]string, response []byte, decompressErr error, + requestTimestamp time.Time, + apiResponseTimestamp time.Time, ) error { - if errWrite := writeRequestInfoWithBody(w, url, method, requestHeaders, requestBody, requestBodyPath, time.Now()); errWrite != nil { + if requestTimestamp.IsZero() { + requestTimestamp = time.Now() + } + if errWrite := writeRequestInfoWithBody(w, url, method, requestHeaders, requestBody, requestBodyPath, requestTimestamp); errWrite != nil { return errWrite } - if errWrite := writeAPISection(w, "=== API REQUEST ===\n", "=== API REQUEST", apiRequest); errWrite != nil { + if errWrite := writeAPISection(w, "=== API REQUEST ===\n", "=== API REQUEST", apiRequest, time.Time{}); errWrite != nil { return errWrite } if errWrite := writeAPIErrorResponses(w, apiResponseErrors); errWrite != nil { return errWrite } - if errWrite := writeAPISection(w, "=== API RESPONSE ===\n", "=== API RESPONSE", apiResponse); errWrite != nil { + if errWrite := writeAPISection(w, "=== API RESPONSE ===\n", "=== API RESPONSE", apiResponse, apiResponseTimestamp); errWrite != nil { return errWrite } return writeResponseSection(w, statusCode, true, responseHeaders, bytes.NewReader(response), decompressErr, true) @@ -583,7 +590,7 @@ func writeRequestInfoWithBody( return nil } -func writeAPISection(w io.Writer, sectionHeader string, sectionPrefix string, payload []byte) error { +func writeAPISection(w io.Writer, sectionHeader string, sectionPrefix string, payload []byte, timestamp time.Time) error { if len(payload) == 0 { return nil } @@ -601,6 +608,11 @@ func writeAPISection(w io.Writer, sectionHeader string, sectionPrefix string, pa if _, errWrite := io.WriteString(w, sectionHeader); errWrite != nil { return errWrite } + if !timestamp.IsZero() { + if _, errWrite := io.WriteString(w, fmt.Sprintf("Timestamp: %s\n", timestamp.Format(time.RFC3339Nano))); errWrite != nil { + return errWrite + } + } if _, errWrite := w.Write(payload); errWrite != nil { return errWrite } @@ -974,6 +986,9 @@ type FileStreamingLogWriter struct { // apiResponse stores the upstream API response data. apiResponse []byte + + // apiResponseTimestamp captures when the API response was received. + apiResponseTimestamp time.Time } // WriteChunkAsync writes a response chunk asynchronously (non-blocking). @@ -1050,6 +1065,7 @@ func (w *FileStreamingLogWriter) WriteAPIResponse(apiResponse []byte) error { return nil } w.apiResponse = bytes.Clone(apiResponse) + w.apiResponseTimestamp = time.Now() return nil } @@ -1140,10 +1156,10 @@ func (w *FileStreamingLogWriter) writeFinalLog(logFile *os.File) error { if errWrite := writeRequestInfoWithBody(logFile, w.url, w.method, w.requestHeaders, nil, w.requestBodyPath, w.timestamp); errWrite != nil { return errWrite } - if errWrite := writeAPISection(logFile, "=== API REQUEST ===\n", "=== API REQUEST", w.apiRequest); errWrite != nil { + if errWrite := writeAPISection(logFile, "=== API REQUEST ===\n", "=== API REQUEST", w.apiRequest, time.Time{}); errWrite != nil { return errWrite } - if errWrite := writeAPISection(logFile, "=== API RESPONSE ===\n", "=== API RESPONSE", w.apiResponse); errWrite != nil { + if errWrite := writeAPISection(logFile, "=== API RESPONSE ===\n", "=== API RESPONSE", w.apiResponse, w.apiResponseTimestamp); errWrite != nil { return errWrite } diff --git a/sdk/api/handlers/gemini/gemini-cli_handlers.go b/sdk/api/handlers/gemini/gemini-cli_handlers.go index ea78657d..8c85b39c 100644 --- a/sdk/api/handlers/gemini/gemini-cli_handlers.go +++ b/sdk/api/handlers/gemini/gemini-cli_handlers.go @@ -125,6 +125,7 @@ func (h *GeminiCLIAPIHandler) CLIHandler(c *gin.Context) { return } _, _ = c.Writer.Write(output) + c.Set("API_RESPONSE_TIMESTAMP", time.Now()) c.Set("API_RESPONSE", output) } } diff --git a/sdk/api/handlers/handlers.go b/sdk/api/handlers/handlers.go index b1da9664..85657e12 100644 --- a/sdk/api/handlers/handlers.go +++ b/sdk/api/handlers/handlers.go @@ -361,6 +361,11 @@ func appendAPIResponse(c *gin.Context, data []byte) { return } + // Capture timestamp on first API response + if _, exists := c.Get("API_RESPONSE_TIMESTAMP"); !exists { + c.Set("API_RESPONSE_TIMESTAMP", time.Now()) + } + if existing, exists := c.Get("API_RESPONSE"); exists { if existingBytes, ok := existing.([]byte); ok && len(existingBytes) > 0 { combined := make([]byte, 0, len(existingBytes)+len(data)+1)