mirror of
https://github.com/VictoriaMetrics/VictoriaMetrics.git
synced 2025-03-11 15:34:56 +00:00
app/vlinsert: properly parse length-delimited syslog messages sent over TCP according to RFC5425
This commit is contained in:
parent
65f414acee
commit
478468e6cd
17 changed files with 537 additions and 310 deletions
|
@ -97,12 +97,10 @@ func RequestHandler(path string, w http.ResponseWriter, r *http.Request) bool {
|
|||
httpserver.Errorf(w, r, "%s", err)
|
||||
return true
|
||||
}
|
||||
lr := logstorage.GetLogRows(cp.StreamFields, cp.IgnoreFields)
|
||||
processLogMessage := cp.GetProcessLogMessageFunc(lr)
|
||||
lmp := cp.NewLogMessageProcessor()
|
||||
isGzip := r.Header.Get("Content-Encoding") == "gzip"
|
||||
n, err := readBulkRequest(r.Body, isGzip, cp.TimeField, cp.MsgField, processLogMessage)
|
||||
vlstorage.MustAddRows(lr)
|
||||
logstorage.PutLogRows(lr)
|
||||
n, err := readBulkRequest(r.Body, isGzip, cp.TimeField, cp.MsgField, lmp)
|
||||
lmp.MustClose()
|
||||
if err != nil {
|
||||
logger.Warnf("cannot decode log message #%d in /_bulk request: %s, stream fields: %s", n, err, cp.StreamFields)
|
||||
return true
|
||||
|
@ -131,9 +129,7 @@ var (
|
|||
bulkRequestDuration = metrics.NewHistogram(`vl_http_request_duration_seconds{path="/insert/elasticsearch/_bulk"}`)
|
||||
)
|
||||
|
||||
func readBulkRequest(r io.Reader, isGzip bool, timeField, msgField string,
|
||||
processLogMessage func(timestamp int64, fields []logstorage.Field),
|
||||
) (int, error) {
|
||||
func readBulkRequest(r io.Reader, isGzip bool, timeField, msgField string, lmp insertutils.LogMessageProcessor) (int, error) {
|
||||
// See https://www.elastic.co/guide/en/elasticsearch/reference/current/docs-bulk.html
|
||||
|
||||
if isGzip {
|
||||
|
@ -158,7 +154,7 @@ func readBulkRequest(r io.Reader, isGzip bool, timeField, msgField string,
|
|||
n := 0
|
||||
nCheckpoint := 0
|
||||
for {
|
||||
ok, err := readBulkLine(sc, timeField, msgField, processLogMessage)
|
||||
ok, err := readBulkLine(sc, timeField, msgField, lmp)
|
||||
wcr.DecConcurrency()
|
||||
if err != nil || !ok {
|
||||
rowsIngestedTotal.Add(n - nCheckpoint)
|
||||
|
@ -174,9 +170,7 @@ func readBulkRequest(r io.Reader, isGzip bool, timeField, msgField string,
|
|||
|
||||
var lineBufferPool bytesutil.ByteBufferPool
|
||||
|
||||
func readBulkLine(sc *bufio.Scanner, timeField, msgField string,
|
||||
processLogMessage func(timestamp int64, fields []logstorage.Field),
|
||||
) (bool, error) {
|
||||
func readBulkLine(sc *bufio.Scanner, timeField, msgField string, lmp insertutils.LogMessageProcessor) (bool, error) {
|
||||
var line []byte
|
||||
|
||||
// Read the command, must be "create" or "index"
|
||||
|
@ -222,7 +216,7 @@ func readBulkLine(sc *bufio.Scanner, timeField, msgField string,
|
|||
ts = time.Now().UnixNano()
|
||||
}
|
||||
logstorage.RenameField(p.Fields, msgField, "_msg")
|
||||
processLogMessage(ts, p.Fields)
|
||||
lmp.AddRow(ts, p.Fields)
|
||||
logstorage.PutJSONParser(p)
|
||||
|
||||
return true, nil
|
||||
|
|
|
@ -4,22 +4,18 @@ import (
|
|||
"bytes"
|
||||
"compress/gzip"
|
||||
"fmt"
|
||||
"reflect"
|
||||
"testing"
|
||||
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/logstorage"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlinsert/insertutils"
|
||||
)
|
||||
|
||||
func TestReadBulkRequestFailure(t *testing.T) {
|
||||
func TestReadBulkRequest_Failure(t *testing.T) {
|
||||
f := func(data string) {
|
||||
t.Helper()
|
||||
|
||||
processLogMessage := func(timestamp int64, fields []logstorage.Field) {
|
||||
t.Fatalf("unexpected call to processLogMessage with timestamp=%d, fields=%s", timestamp, fields)
|
||||
}
|
||||
|
||||
tlp := &insertutils.TestLogMessageProcessor{}
|
||||
r := bytes.NewBufferString(data)
|
||||
rows, err := readBulkRequest(r, false, "_time", "_msg", processLogMessage)
|
||||
rows, err := readBulkRequest(r, false, "_time", "_msg", tlp)
|
||||
if err == nil {
|
||||
t.Fatalf("expecting non-empty error")
|
||||
}
|
||||
|
@ -36,52 +32,38 @@ func TestReadBulkRequestFailure(t *testing.T) {
|
|||
foobar`)
|
||||
}
|
||||
|
||||
func TestReadBulkRequestSuccess(t *testing.T) {
|
||||
func TestReadBulkRequest_Success(t *testing.T) {
|
||||
f := func(data, timeField, msgField string, rowsExpected int, timestampsExpected []int64, resultExpected string) {
|
||||
t.Helper()
|
||||
|
||||
var timestamps []int64
|
||||
var result string
|
||||
processLogMessage := func(timestamp int64, fields []logstorage.Field) {
|
||||
timestamps = append(timestamps, timestamp)
|
||||
result += string(logstorage.MarshalFieldsToJSON(nil, fields)) + "\n"
|
||||
}
|
||||
tlp := &insertutils.TestLogMessageProcessor{}
|
||||
|
||||
// Read the request without compression
|
||||
r := bytes.NewBufferString(data)
|
||||
rows, err := readBulkRequest(r, false, timeField, msgField, processLogMessage)
|
||||
rows, err := readBulkRequest(r, false, timeField, msgField, tlp)
|
||||
if err != nil {
|
||||
t.Fatalf("unexpected error: %s", err)
|
||||
}
|
||||
if rows != rowsExpected {
|
||||
t.Fatalf("unexpected rows read; got %d; want %d", rows, rowsExpected)
|
||||
}
|
||||
|
||||
if !reflect.DeepEqual(timestamps, timestampsExpected) {
|
||||
t.Fatalf("unexpected timestamps;\ngot\n%d\nwant\n%d", timestamps, timestampsExpected)
|
||||
}
|
||||
if result != resultExpected {
|
||||
t.Fatalf("unexpected result;\ngot\n%s\nwant\n%s", result, resultExpected)
|
||||
if err := tlp.Verify(rowsExpected, timestampsExpected, resultExpected); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
|
||||
// Read the request with compression
|
||||
timestamps = nil
|
||||
result = ""
|
||||
tlp = &insertutils.TestLogMessageProcessor{}
|
||||
compressedData := compressData(data)
|
||||
r = bytes.NewBufferString(compressedData)
|
||||
rows, err = readBulkRequest(r, true, timeField, msgField, processLogMessage)
|
||||
rows, err = readBulkRequest(r, true, timeField, msgField, tlp)
|
||||
if err != nil {
|
||||
t.Fatalf("unexpected error: %s", err)
|
||||
}
|
||||
if rows != rowsExpected {
|
||||
t.Fatalf("unexpected rows read; got %d; want %d", rows, rowsExpected)
|
||||
}
|
||||
|
||||
if !reflect.DeepEqual(timestamps, timestampsExpected) {
|
||||
t.Fatalf("unexpected timestamps;\ngot\n%d\nwant\n%d", timestamps, timestampsExpected)
|
||||
}
|
||||
if result != resultExpected {
|
||||
t.Fatalf("unexpected result;\ngot\n%s\nwant\n%s", result, resultExpected)
|
||||
if err := tlp.Verify(rowsExpected, timestampsExpected, resultExpected); err != nil {
|
||||
t.Fatalf("verification failure after compression: %s", err)
|
||||
}
|
||||
}
|
||||
|
||||
|
@ -104,8 +86,7 @@ func TestReadBulkRequestSuccess(t *testing.T) {
|
|||
timestampsExpected := []int64{1686026891735000000, 1686026892735000000, 1686026893735000000}
|
||||
resultExpected := `{"@timestamp":"","log.offset":"71770","log.file.path":"/var/log/auth.log","_msg":"foobar"}
|
||||
{"@timestamp":"","_msg":"baz"}
|
||||
{"_msg":"xyz","@timestamp":"","x":"y"}
|
||||
`
|
||||
{"_msg":"xyz","@timestamp":"","x":"y"}`
|
||||
f(data, timeField, msgField, rowsExpected, timestampsExpected, resultExpected)
|
||||
}
|
||||
|
||||
|
|
|
@ -5,8 +5,8 @@ import (
|
|||
"fmt"
|
||||
"testing"
|
||||
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlinsert/insertutils"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/bytesutil"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/logstorage"
|
||||
)
|
||||
|
||||
func BenchmarkReadBulkRequest(b *testing.B) {
|
||||
|
@ -33,7 +33,7 @@ func benchmarkReadBulkRequest(b *testing.B, isGzip bool) {
|
|||
|
||||
timeField := "@timestamp"
|
||||
msgField := "message"
|
||||
processLogMessage := func(_ int64, _ []logstorage.Field) {}
|
||||
blp := &insertutils.BenchmarkLogMessageProcessor{}
|
||||
|
||||
b.ReportAllocs()
|
||||
b.SetBytes(int64(len(data)))
|
||||
|
@ -41,7 +41,7 @@ func benchmarkReadBulkRequest(b *testing.B, isGzip bool) {
|
|||
r := &bytes.Reader{}
|
||||
for pb.Next() {
|
||||
r.Reset(dataBytes)
|
||||
_, err := readBulkRequest(r, isGzip, timeField, msgField, processLogMessage)
|
||||
_, err := readBulkRequest(r, isGzip, timeField, msgField, blp)
|
||||
if err != nil {
|
||||
panic(fmt.Errorf("unexpected error: %w", err))
|
||||
}
|
||||
|
|
|
@ -88,28 +88,62 @@ func GetCommonParamsForSyslog(tenantID logstorage.TenantID) *CommonParams {
|
|||
return cp
|
||||
}
|
||||
|
||||
// GetProcessLogMessageFunc returns a function, which adds parsed log messages to lr.
|
||||
func (cp *CommonParams) GetProcessLogMessageFunc(lr *logstorage.LogRows) func(timestamp int64, fields []logstorage.Field) {
|
||||
return func(timestamp int64, fields []logstorage.Field) {
|
||||
if len(fields) > *MaxFieldsPerLine {
|
||||
rf := logstorage.RowFormatter(fields)
|
||||
logger.Warnf("dropping log line with %d fields; it exceeds -insert.maxFieldsPerLine=%d; %s", len(fields), *MaxFieldsPerLine, rf)
|
||||
rowsDroppedTotalTooManyFields.Inc()
|
||||
return
|
||||
}
|
||||
// LogMessageProcessor is an interface for log message processors.
|
||||
type LogMessageProcessor interface {
|
||||
// AddRow must add row to the LogMessageProcessor with the given timestamp and the given fields.
|
||||
//
|
||||
// The LogMessageProcessor implementation cannot hold references to fields, since the caller can re-use them.
|
||||
AddRow(timestamp int64, fields []logstorage.Field)
|
||||
|
||||
lr.MustAdd(cp.TenantID, timestamp, fields)
|
||||
if cp.Debug {
|
||||
s := lr.GetRowString(0)
|
||||
lr.ResetKeepSettings()
|
||||
logger.Infof("remoteAddr=%s; requestURI=%s; ignoring log entry because of `debug` query arg: %s", cp.DebugRemoteAddr, cp.DebugRequestURI, s)
|
||||
rowsDroppedTotalDebug.Inc()
|
||||
return
|
||||
}
|
||||
if lr.NeedFlush() {
|
||||
vlstorage.MustAddRows(lr)
|
||||
lr.ResetKeepSettings()
|
||||
}
|
||||
// MustClose() must flush all the remaining fields and free up resources occupied by LogMessageProcessor.
|
||||
MustClose()
|
||||
}
|
||||
|
||||
type logMessageProcessor struct {
|
||||
cp *CommonParams
|
||||
lr *logstorage.LogRows
|
||||
}
|
||||
|
||||
// AddRow adds new log message to lmp with the given timestamp and fields.
|
||||
func (lmp *logMessageProcessor) AddRow(timestamp int64, fields []logstorage.Field) {
|
||||
if len(fields) > *MaxFieldsPerLine {
|
||||
rf := logstorage.RowFormatter(fields)
|
||||
logger.Warnf("dropping log line with %d fields; it exceeds -insert.maxFieldsPerLine=%d; %s", len(fields), *MaxFieldsPerLine, rf)
|
||||
rowsDroppedTotalTooManyFields.Inc()
|
||||
return
|
||||
}
|
||||
|
||||
lmp.lr.MustAdd(lmp.cp.TenantID, timestamp, fields)
|
||||
if lmp.cp.Debug {
|
||||
s := lmp.lr.GetRowString(0)
|
||||
lmp.lr.ResetKeepSettings()
|
||||
logger.Infof("remoteAddr=%s; requestURI=%s; ignoring log entry because of `debug` query arg: %s", lmp.cp.DebugRemoteAddr, lmp.cp.DebugRequestURI, s)
|
||||
rowsDroppedTotalDebug.Inc()
|
||||
return
|
||||
}
|
||||
if lmp.lr.NeedFlush() {
|
||||
lmp.flush()
|
||||
}
|
||||
}
|
||||
|
||||
func (lmp *logMessageProcessor) flush() {
|
||||
vlstorage.MustAddRows(lmp.lr)
|
||||
lmp.lr.ResetKeepSettings()
|
||||
}
|
||||
|
||||
// MustClose flushes the remaining data to the underlying storage and closes lmp.
|
||||
func (lmp *logMessageProcessor) MustClose() {
|
||||
lmp.flush()
|
||||
logstorage.PutLogRows(lmp.lr)
|
||||
lmp.lr = nil
|
||||
}
|
||||
|
||||
// NewLogMessageProcessor returns new LogMessageProcessor for the given cp.
|
||||
func (cp *CommonParams) NewLogMessageProcessor() LogMessageProcessor {
|
||||
lr := logstorage.GetLogRows(cp.StreamFields, cp.IgnoreFields)
|
||||
return &logMessageProcessor{
|
||||
cp: cp,
|
||||
lr: lr,
|
||||
}
|
||||
}
|
||||
|
||||
|
|
53
app/vlinsert/insertutils/testutils.go
Normal file
53
app/vlinsert/insertutils/testutils.go
Normal file
|
@ -0,0 +1,53 @@
|
|||
package insertutils
|
||||
|
||||
import (
|
||||
"fmt"
|
||||
"reflect"
|
||||
"strings"
|
||||
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/logstorage"
|
||||
)
|
||||
|
||||
// TestLogMessageProcessor implements LogMessageProcessor for testing.
|
||||
type TestLogMessageProcessor struct {
|
||||
timestamps []int64
|
||||
rows []string
|
||||
}
|
||||
|
||||
// AddRow adds row with the given timestamp and fields to tlp
|
||||
func (tlp *TestLogMessageProcessor) AddRow(timestamp int64, fields []logstorage.Field) {
|
||||
tlp.timestamps = append(tlp.timestamps, timestamp)
|
||||
tlp.rows = append(tlp.rows, string(logstorage.MarshalFieldsToJSON(nil, fields)))
|
||||
}
|
||||
|
||||
// MustClose closes tlp.
|
||||
func (tlp *TestLogMessageProcessor) MustClose() {
|
||||
}
|
||||
|
||||
// Verify verifies the number of rows, timestamps and results after AddRow calls.
|
||||
func (tlp *TestLogMessageProcessor) Verify(rowsExpected int, timestampsExpected []int64, resultExpected string) error {
|
||||
result := strings.Join(tlp.rows, "\n")
|
||||
if len(tlp.rows) != rowsExpected {
|
||||
return fmt.Errorf("unexpected rows read; got %d; want %d;\nrows read:\n%s\nrows wanted\n%s", len(tlp.rows), rowsExpected, result, resultExpected)
|
||||
}
|
||||
|
||||
if !reflect.DeepEqual(tlp.timestamps, timestampsExpected) {
|
||||
return fmt.Errorf("unexpected timestamps;\ngot\n%d\nwant\n%d", tlp.timestamps, timestampsExpected)
|
||||
}
|
||||
if result != resultExpected {
|
||||
return fmt.Errorf("unexpected result;\ngot\n%s\nwant\n%s", result, resultExpected)
|
||||
}
|
||||
|
||||
return nil
|
||||
}
|
||||
|
||||
// BenchmarkLogMessageProcessor implements LogMessageProcessor for benchmarks.
|
||||
type BenchmarkLogMessageProcessor struct{}
|
||||
|
||||
// AddRow implements LogMessageProcessor interface.
|
||||
func (blp *BenchmarkLogMessageProcessor) AddRow(_ int64, _ []logstorage.Field) {
|
||||
}
|
||||
|
||||
// MustClose implements LogMessageProcessor interface.
|
||||
func (blp *BenchmarkLogMessageProcessor) MustClose() {
|
||||
}
|
|
@ -4,6 +4,7 @@ import (
|
|||
"bufio"
|
||||
"errors"
|
||||
"fmt"
|
||||
"io"
|
||||
"net/http"
|
||||
"time"
|
||||
|
||||
|
@ -39,8 +40,6 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) {
|
|||
httpserver.Errorf(w, r, "%s", err)
|
||||
return
|
||||
}
|
||||
lr := logstorage.GetLogRows(cp.StreamFields, cp.IgnoreFields)
|
||||
processLogMessage := cp.GetProcessLogMessageFunc(lr)
|
||||
|
||||
reader := r.Body
|
||||
if r.Header.Get("Content-Encoding") == "gzip" {
|
||||
|
@ -53,7 +52,22 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) {
|
|||
reader = zr
|
||||
}
|
||||
|
||||
wcr := writeconcurrencylimiter.GetReader(reader)
|
||||
lmp := cp.NewLogMessageProcessor()
|
||||
err = processStreamInternal(reader, cp.TimeField, cp.MsgField, lmp)
|
||||
lmp.MustClose()
|
||||
|
||||
if err != nil {
|
||||
logger.Errorf("jsonline: %s", err)
|
||||
} else {
|
||||
// update requestDuration only for successfully parsed requests.
|
||||
// There is no need in updating requestDuration for request errors,
|
||||
// since their timings are usually much smaller than the timing for successful request parsing.
|
||||
requestDuration.UpdateDuration(startTime)
|
||||
}
|
||||
}
|
||||
|
||||
func processStreamInternal(r io.Reader, timeField, msgField string, lmp insertutils.LogMessageProcessor) error {
|
||||
wcr := writeconcurrencylimiter.GetReader(r)
|
||||
defer writeconcurrencylimiter.PutReader(wcr)
|
||||
|
||||
lb := lineBufferPool.Get()
|
||||
|
@ -65,30 +79,21 @@ func RequestHandler(w http.ResponseWriter, r *http.Request) {
|
|||
|
||||
n := 0
|
||||
for {
|
||||
ok, err := readLine(sc, cp.TimeField, cp.MsgField, processLogMessage)
|
||||
ok, err := readLine(sc, timeField, msgField, lmp)
|
||||
wcr.DecConcurrency()
|
||||
if err != nil {
|
||||
errorsTotal.Inc()
|
||||
logger.Errorf("cannot read line #%d in /jsonline request: %s", n, err)
|
||||
break
|
||||
return fmt.Errorf("cannot read line #%d in /jsonline request: %s", n, err)
|
||||
}
|
||||
if !ok {
|
||||
break
|
||||
return nil
|
||||
}
|
||||
n++
|
||||
rowsIngestedTotal.Inc()
|
||||
}
|
||||
|
||||
vlstorage.MustAddRows(lr)
|
||||
logstorage.PutLogRows(lr)
|
||||
|
||||
// update requestDuration only for successfully parsed requests.
|
||||
// There is no need in updating requestDuration for request errors,
|
||||
// since their timings are usually much smaller than the timing for successful request parsing.
|
||||
requestDuration.UpdateDuration(startTime)
|
||||
}
|
||||
|
||||
func readLine(sc *bufio.Scanner, timeField, msgField string, processLogMessage func(timestamp int64, fields []logstorage.Field)) (bool, error) {
|
||||
func readLine(sc *bufio.Scanner, timeField, msgField string, lmp insertutils.LogMessageProcessor) (bool, error) {
|
||||
var line []byte
|
||||
for len(line) == 0 {
|
||||
if !sc.Scan() {
|
||||
|
@ -112,7 +117,7 @@ func readLine(sc *bufio.Scanner, timeField, msgField string, processLogMessage f
|
|||
return false, fmt.Errorf("cannot get timestamp: %w", err)
|
||||
}
|
||||
logstorage.RenameField(p.Fields, msgField, "_msg")
|
||||
processLogMessage(ts, p.Fields)
|
||||
lmp.AddRow(ts, p.Fields)
|
||||
logstorage.PutJSONParser(p)
|
||||
|
||||
return true, nil
|
||||
|
|
|
@ -1,47 +1,24 @@
|
|||
package jsonline
|
||||
|
||||
import (
|
||||
"bufio"
|
||||
"bytes"
|
||||
"reflect"
|
||||
"testing"
|
||||
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/logstorage"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlinsert/insertutils"
|
||||
)
|
||||
|
||||
func TestReadLine_Success(t *testing.T) {
|
||||
func TestProcessStreamInternal_Success(t *testing.T) {
|
||||
f := func(data, timeField, msgField string, rowsExpected int, timestampsExpected []int64, resultExpected string) {
|
||||
t.Helper()
|
||||
|
||||
var timestamps []int64
|
||||
var result string
|
||||
processLogMessage := func(timestamp int64, fields []logstorage.Field) {
|
||||
timestamps = append(timestamps, timestamp)
|
||||
result += string(logstorage.MarshalFieldsToJSON(nil, fields)) + "\n"
|
||||
}
|
||||
|
||||
tlp := &insertutils.TestLogMessageProcessor{}
|
||||
r := bytes.NewBufferString(data)
|
||||
sc := bufio.NewScanner(r)
|
||||
rows := 0
|
||||
for {
|
||||
ok, err := readLine(sc, timeField, msgField, processLogMessage)
|
||||
if err != nil {
|
||||
t.Fatalf("unexpected error: %s", err)
|
||||
}
|
||||
if !ok {
|
||||
break
|
||||
}
|
||||
rows++
|
||||
}
|
||||
if rows != rowsExpected {
|
||||
t.Fatalf("unexpected rows read; got %d; want %d", rows, rowsExpected)
|
||||
if err := processStreamInternal(r, timeField, msgField, tlp); err != nil {
|
||||
t.Fatalf("unexpected error: %s", err)
|
||||
}
|
||||
|
||||
if !reflect.DeepEqual(timestamps, timestampsExpected) {
|
||||
t.Fatalf("unexpected timestamps;\ngot\n%d\nwant\n%d", timestamps, timestampsExpected)
|
||||
}
|
||||
if result != resultExpected {
|
||||
t.Fatalf("unexpected result;\ngot\n%s\nwant\n%s", result, resultExpected)
|
||||
if err := tlp.Verify(rowsExpected, timestampsExpected, resultExpected); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
}
|
||||
|
||||
|
@ -55,7 +32,24 @@ func TestReadLine_Success(t *testing.T) {
|
|||
timestampsExpected := []int64{1686026891735000000, 1686026892735000000, 1686026893735000000}
|
||||
resultExpected := `{"@timestamp":"","log.offset":"71770","log.file.path":"/var/log/auth.log","_msg":"foobar"}
|
||||
{"@timestamp":"","_msg":"baz"}
|
||||
{"_msg":"xyz","@timestamp":"","x":"y"}
|
||||
`
|
||||
{"_msg":"xyz","@timestamp":"","x":"y"}`
|
||||
f(data, timeField, msgField, rowsExpected, timestampsExpected, resultExpected)
|
||||
}
|
||||
|
||||
func TestProcessStreamInternal_Failure(t *testing.T) {
|
||||
f := func(data string) {
|
||||
t.Helper()
|
||||
|
||||
tlp := &insertutils.TestLogMessageProcessor{}
|
||||
r := bytes.NewBufferString(data)
|
||||
if err := processStreamInternal(r, "time", "", tlp); err == nil {
|
||||
t.Fatalf("expecting non-nil error")
|
||||
}
|
||||
}
|
||||
|
||||
// invalid json
|
||||
f("foobar")
|
||||
|
||||
// invalid timestamp field
|
||||
f(`{"time":"foobar"}`)
|
||||
}
|
||||
|
|
|
@ -8,6 +8,7 @@ import (
|
|||
"strconv"
|
||||
"time"
|
||||
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlinsert/insertutils"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlstorage"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/bytesutil"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/httpserver"
|
||||
|
@ -51,11 +52,9 @@ func handleJSON(r *http.Request, w http.ResponseWriter) {
|
|||
httpserver.Errorf(w, r, "%s", err)
|
||||
return
|
||||
}
|
||||
lr := logstorage.GetLogRows(cp.StreamFields, cp.IgnoreFields)
|
||||
processLogMessage := cp.GetProcessLogMessageFunc(lr)
|
||||
n, err := parseJSONRequest(data, processLogMessage)
|
||||
vlstorage.MustAddRows(lr)
|
||||
logstorage.PutLogRows(lr)
|
||||
lmp := cp.NewLogMessageProcessor()
|
||||
n, err := parseJSONRequest(data, lmp)
|
||||
lmp.MustClose()
|
||||
if err != nil {
|
||||
httpserver.Errorf(w, r, "cannot parse Loki json request: %s", err)
|
||||
return
|
||||
|
@ -75,7 +74,7 @@ var (
|
|||
requestJSONDuration = metrics.NewHistogram(`vl_http_request_duration_seconds{path="/insert/loki/api/v1/push",format="json"}`)
|
||||
)
|
||||
|
||||
func parseJSONRequest(data []byte, processLogMessage func(timestamp int64, fields []logstorage.Field)) (int, error) {
|
||||
func parseJSONRequest(data []byte, lmp insertutils.LogMessageProcessor) (int, error) {
|
||||
p := parserPool.Get()
|
||||
defer parserPool.Put(p)
|
||||
v, err := p.ParseBytes(data)
|
||||
|
@ -168,7 +167,7 @@ func parseJSONRequest(data []byte, processLogMessage func(timestamp int64, field
|
|||
Name: "_msg",
|
||||
Value: bytesutil.ToUnsafeString(msg),
|
||||
})
|
||||
processLogMessage(ts, fields)
|
||||
lmp.AddRow(ts, fields)
|
||||
}
|
||||
rowsIngested += len(lines)
|
||||
}
|
||||
|
|
|
@ -1,19 +1,17 @@
|
|||
package loki
|
||||
|
||||
import (
|
||||
"fmt"
|
||||
"strings"
|
||||
"testing"
|
||||
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/logstorage"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlinsert/insertutils"
|
||||
)
|
||||
|
||||
func TestParseJSONRequestFailure(t *testing.T) {
|
||||
func TestParseJSONRequest_Failure(t *testing.T) {
|
||||
f := func(s string) {
|
||||
t.Helper()
|
||||
n, err := parseJSONRequest([]byte(s), func(_ int64, _ []logstorage.Field) {
|
||||
t.Fatalf("unexpected call to parseJSONRequest callback!")
|
||||
})
|
||||
|
||||
tlp := &insertutils.TestLogMessageProcessor{}
|
||||
n, err := parseJSONRequest([]byte(s), tlp)
|
||||
if err == nil {
|
||||
t.Fatalf("expecting non-nil error")
|
||||
}
|
||||
|
@ -56,39 +54,30 @@ func TestParseJSONRequestFailure(t *testing.T) {
|
|||
f(`{"streams":[{"values":[["123",1234]]}]}`)
|
||||
}
|
||||
|
||||
func TestParseJSONRequestSuccess(t *testing.T) {
|
||||
f := func(s string, resultExpected string) {
|
||||
func TestParseJSONRequest_Success(t *testing.T) {
|
||||
f := func(s string, timestampsExpected []int64, resultExpected string) {
|
||||
t.Helper()
|
||||
var lines []string
|
||||
n, err := parseJSONRequest([]byte(s), func(timestamp int64, fields []logstorage.Field) {
|
||||
var a []string
|
||||
for _, f := range fields {
|
||||
a = append(a, f.String())
|
||||
}
|
||||
line := fmt.Sprintf("_time:%d %s", timestamp, strings.Join(a, " "))
|
||||
lines = append(lines, line)
|
||||
})
|
||||
|
||||
tlp := &insertutils.TestLogMessageProcessor{}
|
||||
|
||||
n, err := parseJSONRequest([]byte(s), tlp)
|
||||
if err != nil {
|
||||
t.Fatalf("unexpected error: %s", err)
|
||||
}
|
||||
if n != len(lines) {
|
||||
t.Fatalf("unexpected number of lines parsed; got %d; want %d", n, len(lines))
|
||||
}
|
||||
result := strings.Join(lines, "\n")
|
||||
if result != resultExpected {
|
||||
t.Fatalf("unexpected result;\ngot\n%s\nwant\n%s", result, resultExpected)
|
||||
if err := tlp.Verify(n, timestampsExpected, resultExpected); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
}
|
||||
|
||||
// Empty streams
|
||||
f(`{"streams":[]}`, ``)
|
||||
f(`{"streams":[{"values":[]}]}`, ``)
|
||||
f(`{"streams":[{"stream":{},"values":[]}]}`, ``)
|
||||
f(`{"streams":[{"stream":{"foo":"bar"},"values":[]}]}`, ``)
|
||||
f(`{"streams":[]}`, nil, ``)
|
||||
f(`{"streams":[{"values":[]}]}`, nil, ``)
|
||||
f(`{"streams":[{"stream":{},"values":[]}]}`, nil, ``)
|
||||
f(`{"streams":[{"stream":{"foo":"bar"},"values":[]}]}`, nil, ``)
|
||||
|
||||
// Empty stream labels
|
||||
f(`{"streams":[{"values":[["1577836800000000001", "foo bar"]]}]}`, `_time:1577836800000000001 "_msg":"foo bar"`)
|
||||
f(`{"streams":[{"stream":{},"values":[["1577836800000000001", "foo bar"]]}]}`, `_time:1577836800000000001 "_msg":"foo bar"`)
|
||||
f(`{"streams":[{"values":[["1577836800000000001", "foo bar"]]}]}`, []int64{1577836800000000001}, `{"_msg":"foo bar"}`)
|
||||
f(`{"streams":[{"stream":{},"values":[["1577836800000000001", "foo bar"]]}]}`, []int64{1577836800000000001}, `{"_msg":"foo bar"}`)
|
||||
|
||||
// Non-empty stream labels
|
||||
f(`{"streams":[{"stream":{
|
||||
|
@ -98,9 +87,9 @@ func TestParseJSONRequestSuccess(t *testing.T) {
|
|||
["1577836800000000001", "foo bar"],
|
||||
["1477836900005000002", "abc"],
|
||||
["147.78369e9", "foobar"]
|
||||
]}]}`, `_time:1577836800000000001 "label1":"value1" "label2":"value2" "_msg":"foo bar"
|
||||
_time:1477836900005000002 "label1":"value1" "label2":"value2" "_msg":"abc"
|
||||
_time:147783690000 "label1":"value1" "label2":"value2" "_msg":"foobar"`)
|
||||
]}]}`, []int64{1577836800000000001, 1477836900005000002, 147783690000}, `{"label1":"value1","label2":"value2","_msg":"foo bar"}
|
||||
{"label1":"value1","label2":"value2","_msg":"abc"}
|
||||
{"label1":"value1","label2":"value2","_msg":"foobar"}`)
|
||||
|
||||
// Multiple streams
|
||||
f(`{
|
||||
|
@ -124,7 +113,7 @@ _time:147783690000 "label1":"value1" "label2":"value2" "_msg":"foobar"`)
|
|||
]
|
||||
}
|
||||
]
|
||||
}`, `_time:1577836800000000001 "foo":"bar" "a":"b" "_msg":"foo bar"
|
||||
_time:1577836900005000002 "foo":"bar" "a":"b" "_msg":"abc"
|
||||
_time:1877836900005000002 "x":"y" "_msg":"yx"`)
|
||||
}`, []int64{1577836800000000001, 1577836900005000002, 1877836900005000002}, `{"foo":"bar","a":"b","_msg":"foo bar"}
|
||||
{"foo":"bar","a":"b","_msg":"abc"}
|
||||
{"x":"y","_msg":"yx"}`)
|
||||
}
|
||||
|
|
|
@ -6,7 +6,7 @@ import (
|
|||
"testing"
|
||||
"time"
|
||||
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/logstorage"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlinsert/insertutils"
|
||||
)
|
||||
|
||||
func BenchmarkParseJSONRequest(b *testing.B) {
|
||||
|
@ -22,12 +22,13 @@ func BenchmarkParseJSONRequest(b *testing.B) {
|
|||
}
|
||||
|
||||
func benchmarkParseJSONRequest(b *testing.B, streams, rows, labels int) {
|
||||
blp := &insertutils.BenchmarkLogMessageProcessor{}
|
||||
b.ReportAllocs()
|
||||
b.SetBytes(int64(streams * rows))
|
||||
b.RunParallel(func(pb *testing.PB) {
|
||||
data := getJSONBody(streams, rows, labels)
|
||||
for pb.Next() {
|
||||
_, err := parseJSONRequest(data, func(_ int64, _ []logstorage.Field) {})
|
||||
_, err := parseJSONRequest(data, blp)
|
||||
if err != nil {
|
||||
panic(fmt.Errorf("unexpected error: %w", err))
|
||||
}
|
||||
|
|
|
@ -9,6 +9,7 @@ import (
|
|||
"sync"
|
||||
"time"
|
||||
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlinsert/insertutils"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlstorage"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/bytesutil"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/httpserver"
|
||||
|
@ -43,11 +44,9 @@ func handleProtobuf(r *http.Request, w http.ResponseWriter) {
|
|||
httpserver.Errorf(w, r, "%s", err)
|
||||
return
|
||||
}
|
||||
lr := logstorage.GetLogRows(cp.StreamFields, cp.IgnoreFields)
|
||||
processLogMessage := cp.GetProcessLogMessageFunc(lr)
|
||||
n, err := parseProtobufRequest(data, processLogMessage)
|
||||
vlstorage.MustAddRows(lr)
|
||||
logstorage.PutLogRows(lr)
|
||||
lmp := cp.NewLogMessageProcessor()
|
||||
n, err := parseProtobufRequest(data, lmp)
|
||||
lmp.MustClose()
|
||||
if err != nil {
|
||||
httpserver.Errorf(w, r, "cannot parse Loki protobuf request: %s", err)
|
||||
return
|
||||
|
@ -67,7 +66,7 @@ var (
|
|||
requestProtobufDuration = metrics.NewHistogram(`vl_http_request_duration_seconds{path="/insert/loki/api/v1/push",format="protobuf"}`)
|
||||
)
|
||||
|
||||
func parseProtobufRequest(data []byte, processLogMessage func(timestamp int64, fields []logstorage.Field)) (int, error) {
|
||||
func parseProtobufRequest(data []byte, lmp insertutils.LogMessageProcessor) (int, error) {
|
||||
bb := bytesBufPool.Get()
|
||||
defer bytesBufPool.Put(bb)
|
||||
|
||||
|
@ -110,7 +109,7 @@ func parseProtobufRequest(data []byte, processLogMessage func(timestamp int64, f
|
|||
if ts == 0 {
|
||||
ts = currentTimestamp
|
||||
}
|
||||
processLogMessage(ts, fields)
|
||||
lmp.AddRow(ts, fields)
|
||||
}
|
||||
rowsIngested += len(stream.Entries)
|
||||
}
|
||||
|
|
|
@ -6,83 +6,83 @@ import (
|
|||
"testing"
|
||||
"time"
|
||||
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlinsert/insertutils"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/logstorage"
|
||||
"github.com/golang/snappy"
|
||||
)
|
||||
|
||||
func TestParseProtobufRequestSuccess(t *testing.T) {
|
||||
f := func(s string, resultExpected string) {
|
||||
type testLogMessageProcessor struct {
|
||||
pr PushRequest
|
||||
}
|
||||
|
||||
func (tlp *testLogMessageProcessor) AddRow(timestamp int64, fields []logstorage.Field) {
|
||||
msg := ""
|
||||
for _, f := range fields {
|
||||
if f.Name == "_msg" {
|
||||
msg = f.Value
|
||||
}
|
||||
}
|
||||
var a []string
|
||||
for _, f := range fields {
|
||||
if f.Name == "_msg" {
|
||||
continue
|
||||
}
|
||||
item := fmt.Sprintf("%s=%q", f.Name, f.Value)
|
||||
a = append(a, item)
|
||||
}
|
||||
labels := "{" + strings.Join(a, ", ") + "}"
|
||||
tlp.pr.Streams = append(tlp.pr.Streams, Stream{
|
||||
Labels: labels,
|
||||
Entries: []Entry{
|
||||
{
|
||||
Timestamp: time.Unix(0, timestamp),
|
||||
Line: msg,
|
||||
},
|
||||
},
|
||||
})
|
||||
}
|
||||
|
||||
func (tlp *testLogMessageProcessor) MustClose() {
|
||||
}
|
||||
|
||||
func TestParseProtobufRequest_Success(t *testing.T) {
|
||||
f := func(s string, timestampsExpected []int64, resultExpected string) {
|
||||
t.Helper()
|
||||
var pr PushRequest
|
||||
n, err := parseJSONRequest([]byte(s), func(timestamp int64, fields []logstorage.Field) {
|
||||
msg := ""
|
||||
for _, f := range fields {
|
||||
if f.Name == "_msg" {
|
||||
msg = f.Value
|
||||
}
|
||||
}
|
||||
var a []string
|
||||
for _, f := range fields {
|
||||
if f.Name == "_msg" {
|
||||
continue
|
||||
}
|
||||
item := fmt.Sprintf("%s=%q", f.Name, f.Value)
|
||||
a = append(a, item)
|
||||
}
|
||||
labels := "{" + strings.Join(a, ", ") + "}"
|
||||
pr.Streams = append(pr.Streams, Stream{
|
||||
Labels: labels,
|
||||
Entries: []Entry{
|
||||
{
|
||||
Timestamp: time.Unix(0, timestamp),
|
||||
Line: msg,
|
||||
},
|
||||
},
|
||||
})
|
||||
})
|
||||
|
||||
tlp := &testLogMessageProcessor{}
|
||||
n, err := parseJSONRequest([]byte(s), tlp)
|
||||
if err != nil {
|
||||
t.Fatalf("unexpected error: %s", err)
|
||||
}
|
||||
if n != len(pr.Streams) {
|
||||
t.Fatalf("unexpected number of streams; got %d; want %d", len(pr.Streams), n)
|
||||
if n != len(tlp.pr.Streams) {
|
||||
t.Fatalf("unexpected number of streams; got %d; want %d", len(tlp.pr.Streams), n)
|
||||
}
|
||||
|
||||
data, err := pr.Marshal()
|
||||
data, err := tlp.pr.Marshal()
|
||||
if err != nil {
|
||||
t.Fatalf("unexpected error when marshaling PushRequest: %s", err)
|
||||
}
|
||||
encodedData := snappy.Encode(nil, data)
|
||||
|
||||
var lines []string
|
||||
n, err = parseProtobufRequest(encodedData, func(timestamp int64, fields []logstorage.Field) {
|
||||
var a []string
|
||||
for _, f := range fields {
|
||||
a = append(a, f.String())
|
||||
}
|
||||
line := fmt.Sprintf("_time:%d %s", timestamp, strings.Join(a, " "))
|
||||
lines = append(lines, line)
|
||||
})
|
||||
tlp2 := &insertutils.TestLogMessageProcessor{}
|
||||
n, err = parseProtobufRequest(encodedData, tlp2)
|
||||
if err != nil {
|
||||
t.Fatalf("unexpected error: %s", err)
|
||||
}
|
||||
if n != len(lines) {
|
||||
t.Fatalf("unexpected number of lines parsed; got %d; want %d", n, len(lines))
|
||||
}
|
||||
result := strings.Join(lines, "\n")
|
||||
if result != resultExpected {
|
||||
t.Fatalf("unexpected result;\ngot\n%s\nwant\n%s", result, resultExpected)
|
||||
if err := tlp2.Verify(n, timestampsExpected, resultExpected); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
}
|
||||
|
||||
// Empty streams
|
||||
f(`{"streams":[]}`, ``)
|
||||
f(`{"streams":[{"values":[]}]}`, ``)
|
||||
f(`{"streams":[{"stream":{},"values":[]}]}`, ``)
|
||||
f(`{"streams":[{"stream":{"foo":"bar"},"values":[]}]}`, ``)
|
||||
f(`{"streams":[]}`, nil, ``)
|
||||
f(`{"streams":[{"values":[]}]}`, nil, ``)
|
||||
f(`{"streams":[{"stream":{},"values":[]}]}`, nil, ``)
|
||||
f(`{"streams":[{"stream":{"foo":"bar"},"values":[]}]}`, nil, ``)
|
||||
|
||||
// Empty stream labels
|
||||
f(`{"streams":[{"values":[["1577836800000000001", "foo bar"]]}]}`, `_time:1577836800000000001 "_msg":"foo bar"`)
|
||||
f(`{"streams":[{"stream":{},"values":[["1577836800000000001", "foo bar"]]}]}`, `_time:1577836800000000001 "_msg":"foo bar"`)
|
||||
f(`{"streams":[{"values":[["1577836800000000001", "foo bar"]]}]}`, []int64{1577836800000000001}, `{"_msg":"foo bar"}`)
|
||||
f(`{"streams":[{"stream":{},"values":[["1577836800000000001", "foo bar"]]}]}`, []int64{1577836800000000001}, `{"_msg":"foo bar"}`)
|
||||
|
||||
// Non-empty stream labels
|
||||
f(`{"streams":[{"stream":{
|
||||
|
@ -92,9 +92,9 @@ func TestParseProtobufRequestSuccess(t *testing.T) {
|
|||
["1577836800000000001", "foo bar"],
|
||||
["1477836900005000002", "abc"],
|
||||
["147.78369e9", "foobar"]
|
||||
]}]}`, `_time:1577836800000000001 "label1":"value1" "label2":"value2" "_msg":"foo bar"
|
||||
_time:1477836900005000002 "label1":"value1" "label2":"value2" "_msg":"abc"
|
||||
_time:147783690000 "label1":"value1" "label2":"value2" "_msg":"foobar"`)
|
||||
]}]}`, []int64{1577836800000000001, 1477836900005000002, 147783690000}, `{"label1":"value1","label2":"value2","_msg":"foo bar"}
|
||||
{"label1":"value1","label2":"value2","_msg":"abc"}
|
||||
{"label1":"value1","label2":"value2","_msg":"foobar"}`)
|
||||
|
||||
// Multiple streams
|
||||
f(`{
|
||||
|
@ -118,12 +118,12 @@ _time:147783690000 "label1":"value1" "label2":"value2" "_msg":"foobar"`)
|
|||
]
|
||||
}
|
||||
]
|
||||
}`, `_time:1577836800000000001 "foo":"bar" "a":"b" "_msg":"foo bar"
|
||||
_time:1577836900005000002 "foo":"bar" "a":"b" "_msg":"abc"
|
||||
_time:1877836900005000002 "x":"y" "_msg":"yx"`)
|
||||
}`, []int64{1577836800000000001, 1577836900005000002, 1877836900005000002}, `{"foo":"bar","a":"b","_msg":"foo bar"}
|
||||
{"foo":"bar","a":"b","_msg":"abc"}
|
||||
{"x":"y","_msg":"yx"}`)
|
||||
}
|
||||
|
||||
func TestParsePromLabelsSuccess(t *testing.T) {
|
||||
func TestParsePromLabels_Success(t *testing.T) {
|
||||
f := func(s string) {
|
||||
t.Helper()
|
||||
fields, err := parsePromLabels(nil, s)
|
||||
|
@ -147,7 +147,7 @@ func TestParsePromLabelsSuccess(t *testing.T) {
|
|||
f(`{foo="ba\"r\\z\n", a="", b="\"\\"}`)
|
||||
}
|
||||
|
||||
func TestParsePromLabelsFailure(t *testing.T) {
|
||||
func TestParsePromLabels_Failure(t *testing.T) {
|
||||
f := func(s string) {
|
||||
t.Helper()
|
||||
fields, err := parsePromLabels(nil, s)
|
||||
|
|
|
@ -8,7 +8,7 @@ import (
|
|||
|
||||
"github.com/golang/snappy"
|
||||
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/logstorage"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlinsert/insertutils"
|
||||
)
|
||||
|
||||
func BenchmarkParseProtobufRequest(b *testing.B) {
|
||||
|
@ -24,12 +24,13 @@ func BenchmarkParseProtobufRequest(b *testing.B) {
|
|||
}
|
||||
|
||||
func benchmarkParseProtobufRequest(b *testing.B, streams, rows, labels int) {
|
||||
blp := &insertutils.BenchmarkLogMessageProcessor{}
|
||||
b.ReportAllocs()
|
||||
b.SetBytes(int64(streams * rows))
|
||||
b.RunParallel(func(pb *testing.PB) {
|
||||
body := getProtobufBody(streams, rows, labels)
|
||||
for pb.Next() {
|
||||
_, err := parseProtobufRequest(body, func(_ int64, _ []logstorage.Field) {})
|
||||
_, err := parseProtobufRequest(body, blp)
|
||||
if err != nil {
|
||||
panic(fmt.Errorf("unexpected error: %w", err))
|
||||
}
|
||||
|
|
|
@ -8,6 +8,7 @@ import (
|
|||
"fmt"
|
||||
"io"
|
||||
"net"
|
||||
"strconv"
|
||||
"strings"
|
||||
"sync"
|
||||
"sync/atomic"
|
||||
|
@ -25,6 +26,7 @@ import (
|
|||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/logstorage"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/netutil"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/protoparser/common"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/slicesutil"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/writeconcurrencylimiter"
|
||||
"github.com/VictoriaMetrics/metrics"
|
||||
)
|
||||
|
@ -277,6 +279,18 @@ func serveTCP(ln net.Listener) {
|
|||
|
||||
// processStream parses a stream of syslog messages from r and ingests them into vlstorage.
|
||||
func processStream(r io.Reader, cp *insertutils.CommonParams) error {
|
||||
if err := vlstorage.CanWriteData(); err != nil {
|
||||
return err
|
||||
}
|
||||
|
||||
lmp := cp.NewLogMessageProcessor()
|
||||
err := processStreamInternal(r, lmp)
|
||||
lmp.MustClose()
|
||||
|
||||
return err
|
||||
}
|
||||
|
||||
func processStreamInternal(r io.Reader, lmp insertutils.LogMessageProcessor) error {
|
||||
switch *compressMethod {
|
||||
case "", "none":
|
||||
case "gzip":
|
||||
|
@ -295,7 +309,7 @@ func processStream(r io.Reader, cp *insertutils.CommonParams) error {
|
|||
logger.Panicf("BUG: compressLevel=%q; supported values: none, gzip, deflate", *compressMethod)
|
||||
}
|
||||
|
||||
err := processUncompressedStream(r, cp)
|
||||
err := processUncompressedStream(r, lmp)
|
||||
|
||||
switch *compressMethod {
|
||||
case "gzip":
|
||||
|
@ -309,76 +323,154 @@ func processStream(r io.Reader, cp *insertutils.CommonParams) error {
|
|||
return err
|
||||
}
|
||||
|
||||
func processUncompressedStream(r io.Reader, cp *insertutils.CommonParams) error {
|
||||
if err := vlstorage.CanWriteData(); err != nil {
|
||||
return err
|
||||
}
|
||||
lr := logstorage.GetLogRows(cp.StreamFields, nil)
|
||||
processLogMessage := cp.GetProcessLogMessageFunc(lr)
|
||||
|
||||
func processUncompressedStream(r io.Reader, lmp insertutils.LogMessageProcessor) error {
|
||||
wcr := writeconcurrencylimiter.GetReader(r)
|
||||
defer writeconcurrencylimiter.PutReader(wcr)
|
||||
|
||||
lb := lineBufferPool.Get()
|
||||
defer lineBufferPool.Put(lb)
|
||||
|
||||
lb.B = bytesutil.ResizeNoCopyNoOverallocate(lb.B, insertutils.MaxLineSizeBytes.IntN())
|
||||
sc := bufio.NewScanner(wcr)
|
||||
sc.Buffer(lb.B, len(lb.B))
|
||||
slr := getSyslogLineReader(wcr)
|
||||
defer putSyslogLineReader(slr)
|
||||
|
||||
n := 0
|
||||
for {
|
||||
currentYear := int(globalCurrentYear.Load())
|
||||
ok, err := readLine(sc, currentYear, globalTimezone, processLogMessage)
|
||||
ok := slr.nextLine()
|
||||
wcr.DecConcurrency()
|
||||
if !ok {
|
||||
break
|
||||
}
|
||||
|
||||
currentYear := int(globalCurrentYear.Load())
|
||||
err := processLine(slr.line, currentYear, globalTimezone, lmp)
|
||||
if err != nil {
|
||||
errorsTotal.Inc()
|
||||
return fmt.Errorf("cannot read line #%d: %s", n, err)
|
||||
}
|
||||
if !ok {
|
||||
break
|
||||
}
|
||||
n++
|
||||
rowsIngestedTotal.Inc()
|
||||
}
|
||||
|
||||
vlstorage.MustAddRows(lr)
|
||||
logstorage.PutLogRows(lr)
|
||||
|
||||
return nil
|
||||
return slr.Error()
|
||||
}
|
||||
|
||||
func readLine(sc *bufio.Scanner, currentYear int, timezone *time.Location, processLogMessage func(timestamp int64, fields []logstorage.Field)) (bool, error) {
|
||||
var line []byte
|
||||
for len(line) == 0 {
|
||||
if !sc.Scan() {
|
||||
if err := sc.Err(); err != nil {
|
||||
if errors.Is(err, bufio.ErrTooLong) {
|
||||
return false, fmt.Errorf(`line size exceeds -insert.maxLineSizeBytes=%d`, insertutils.MaxLineSizeBytes.IntN())
|
||||
}
|
||||
return false, err
|
||||
}
|
||||
return false, nil
|
||||
}
|
||||
line = sc.Bytes()
|
||||
type syslogLineReader struct {
|
||||
line []byte
|
||||
|
||||
br *bufio.Reader
|
||||
err error
|
||||
}
|
||||
|
||||
func (slr *syslogLineReader) reset(r io.Reader) {
|
||||
slr.line = slr.line[:0]
|
||||
slr.br.Reset(r)
|
||||
slr.err = nil
|
||||
}
|
||||
|
||||
// Error returns the last error occurred in slr.
|
||||
func (slr *syslogLineReader) Error() error {
|
||||
if slr.err == nil || slr.err == io.EOF {
|
||||
return nil
|
||||
}
|
||||
return slr.err
|
||||
}
|
||||
|
||||
// nextLine reads the next syslog line from slr and stores it at slr.line.
|
||||
//
|
||||
// false is returned if the next line cannot be read. Error() must be called in this case
|
||||
// in order to verify whether there is an error or just slr stream has been finished.
|
||||
func (slr *syslogLineReader) nextLine() bool {
|
||||
if slr.err != nil {
|
||||
return false
|
||||
}
|
||||
|
||||
prefix, err := slr.br.ReadSlice(' ')
|
||||
if err != nil {
|
||||
if err != io.EOF {
|
||||
slr.err = fmt.Errorf("cannot read message frame prefix: %w", err)
|
||||
return false
|
||||
}
|
||||
if len(prefix) == 0 {
|
||||
slr.err = err
|
||||
return false
|
||||
}
|
||||
}
|
||||
// skip empty lines
|
||||
for len(prefix) > 0 && prefix[0] == '\n' {
|
||||
prefix = prefix[1:]
|
||||
}
|
||||
|
||||
if prefix[0] >= '0' && prefix[0] <= '9' {
|
||||
// This is octet-counting method. See https://www.ietf.org/archive/id/draft-gerhards-syslog-plain-tcp-07.html#msgxfer
|
||||
msgLenStr := bytesutil.ToUnsafeString(prefix[:len(prefix)-1])
|
||||
msgLen, err := strconv.ParseUint(msgLenStr, 10, 64)
|
||||
if err != nil {
|
||||
slr.err = fmt.Errorf("cannot parse message length from %q: %w", msgLenStr, err)
|
||||
return false
|
||||
}
|
||||
if maxMsgLen := insertutils.MaxLineSizeBytes.IntN(); msgLen > uint64(maxMsgLen) {
|
||||
slr.err = fmt.Errorf("cannot read message longer than %d bytes; msgLen=%d", maxMsgLen, msgLen)
|
||||
return false
|
||||
}
|
||||
slr.line = slicesutil.SetLength(slr.line, int(msgLen))
|
||||
if _, err := io.ReadFull(slr.br, slr.line); err != nil {
|
||||
slr.err = fmt.Errorf("cannot read message with size %d bytes: %w", msgLen, err)
|
||||
return false
|
||||
}
|
||||
return true
|
||||
}
|
||||
|
||||
// This is octet-stuffing method. See https://www.ietf.org/archive/id/draft-gerhards-syslog-plain-tcp-07.html#octet-stuffing-legacy
|
||||
slr.line = append(slr.line[:0], prefix...)
|
||||
for {
|
||||
line, err := slr.br.ReadSlice('\n')
|
||||
if err == nil {
|
||||
slr.line = append(slr.line, line[:len(line)-1]...)
|
||||
return true
|
||||
}
|
||||
if err == io.EOF {
|
||||
slr.line = append(slr.line, line...)
|
||||
return true
|
||||
}
|
||||
if err == bufio.ErrBufferFull {
|
||||
slr.line = append(slr.line, line...)
|
||||
continue
|
||||
}
|
||||
slr.err = fmt.Errorf("cannot read message in octet-stuffing method: %w", err)
|
||||
return false
|
||||
}
|
||||
}
|
||||
|
||||
func getSyslogLineReader(r io.Reader) *syslogLineReader {
|
||||
v := syslogLineReaderPool.Get()
|
||||
if v == nil {
|
||||
br := bufio.NewReaderSize(r, 64*1024)
|
||||
return &syslogLineReader{
|
||||
br: br,
|
||||
}
|
||||
}
|
||||
slr := v.(*syslogLineReader)
|
||||
slr.reset(r)
|
||||
return slr
|
||||
}
|
||||
|
||||
func putSyslogLineReader(slr *syslogLineReader) {
|
||||
syslogLineReaderPool.Put(slr)
|
||||
}
|
||||
|
||||
var syslogLineReaderPool sync.Pool
|
||||
|
||||
func processLine(line []byte, currentYear int, timezone *time.Location, lmp insertutils.LogMessageProcessor) error {
|
||||
p := logstorage.GetSyslogParser(currentYear, timezone)
|
||||
lineStr := bytesutil.ToUnsafeString(line)
|
||||
p.Parse(lineStr)
|
||||
ts, err := insertutils.ExtractTimestampISO8601FromFields("timestamp", p.Fields)
|
||||
if err != nil {
|
||||
return false, fmt.Errorf("cannot get timestamp from syslog line %q: %w", line, err)
|
||||
return fmt.Errorf("cannot get timestamp from syslog line %q: %w", line, err)
|
||||
}
|
||||
logstorage.RenameField(p.Fields, "message", "_msg")
|
||||
processLogMessage(ts, p.Fields)
|
||||
lmp.AddRow(ts, p.Fields)
|
||||
logstorage.PutSyslogParser(p)
|
||||
|
||||
return true, nil
|
||||
return nil
|
||||
}
|
||||
|
||||
var lineBufferPool bytesutil.ByteBufferPool
|
||||
|
||||
var (
|
||||
rowsIngestedTotal = metrics.NewCounter(`vl_rows_ingested_total{type="syslog"}`)
|
||||
|
||||
|
|
|
@ -1,65 +1,121 @@
|
|||
package syslog
|
||||
|
||||
import (
|
||||
"bufio"
|
||||
"bytes"
|
||||
"reflect"
|
||||
"testing"
|
||||
"time"
|
||||
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/lib/logstorage"
|
||||
"github.com/VictoriaMetrics/VictoriaMetrics/app/vlinsert/insertutils"
|
||||
)
|
||||
|
||||
func TestReadLine_Success(t *testing.T) {
|
||||
func TestSyslogLineReader_Success(t *testing.T) {
|
||||
f := func(data string, linesExpected []string) {
|
||||
t.Helper()
|
||||
|
||||
r := bytes.NewBufferString(data)
|
||||
slr := getSyslogLineReader(r)
|
||||
defer putSyslogLineReader(slr)
|
||||
|
||||
var lines []string
|
||||
for slr.nextLine() {
|
||||
lines = append(lines, string(slr.line))
|
||||
}
|
||||
if err := slr.Error(); err != nil {
|
||||
t.Fatalf("unexpected error: %s", err)
|
||||
}
|
||||
if !reflect.DeepEqual(lines, linesExpected) {
|
||||
t.Fatalf("unexpected lines read;\ngot\n%q\nwant\n%q", lines, linesExpected)
|
||||
}
|
||||
}
|
||||
|
||||
f("", nil)
|
||||
f("foobar", []string{"foobar"})
|
||||
|
||||
f(`Jun 3 12:08:33 abcd systemd: Starting Update the local ESM caches...
|
||||
48 <165>Jun 4 12:08:33 abcd systemd[345]: abc defg<123>1 2023-06-03T17:42:12.345Z mymachine.example.com appname 12345 ID47 [exampleSDID@32473 iut="3" eventSource="Application 123 = ] 56" eventID="11211"] This is a test message with structured data.
|
||||
`, []string{
|
||||
"Jun 3 12:08:33 abcd systemd: Starting Update the local ESM caches...",
|
||||
"<165>Jun 4 12:08:33 abcd systemd[345]: abc defg",
|
||||
`<123>1 2023-06-03T17:42:12.345Z mymachine.example.com appname 12345 ID47 [exampleSDID@32473 iut="3" eventSource="Application 123 = ] 56" eventID="11211"] This is a test message with structured data.`,
|
||||
})
|
||||
}
|
||||
|
||||
func TestSyslogLineReader_Failure(t *testing.T) {
|
||||
f := func(data string) {
|
||||
t.Helper()
|
||||
|
||||
r := bytes.NewBufferString(data)
|
||||
slr := getSyslogLineReader(r)
|
||||
defer putSyslogLineReader(slr)
|
||||
|
||||
if slr.nextLine() {
|
||||
t.Fatalf("expecting failure to read the first line")
|
||||
}
|
||||
if err := slr.Error(); err == nil {
|
||||
t.Fatalf("expecting non-nil error")
|
||||
}
|
||||
}
|
||||
|
||||
// invalid format for message size
|
||||
f("12foo bar")
|
||||
|
||||
// too big message size
|
||||
f("123 aa")
|
||||
f("1233423432 abc")
|
||||
}
|
||||
|
||||
func TestProcessStreamInternal_Success(t *testing.T) {
|
||||
f := func(data string, currentYear, rowsExpected int, timestampsExpected []int64, resultExpected string) {
|
||||
t.Helper()
|
||||
|
||||
MustInit()
|
||||
defer MustStop()
|
||||
|
||||
var timestamps []int64
|
||||
var result string
|
||||
processLogMessage := func(timestamp int64, fields []logstorage.Field) {
|
||||
timestamps = append(timestamps, timestamp)
|
||||
result += string(logstorage.MarshalFieldsToJSON(nil, fields)) + "\n"
|
||||
}
|
||||
globalTimezone = time.UTC
|
||||
globalCurrentYear.Store(int64(currentYear))
|
||||
|
||||
tlp := &insertutils.TestLogMessageProcessor{}
|
||||
r := bytes.NewBufferString(data)
|
||||
sc := bufio.NewScanner(r)
|
||||
rows := 0
|
||||
timezone := time.UTC
|
||||
for {
|
||||
ok, err := readLine(sc, currentYear, timezone, processLogMessage)
|
||||
if err != nil {
|
||||
t.Fatalf("unexpected error: %s", err)
|
||||
}
|
||||
if !ok {
|
||||
break
|
||||
}
|
||||
rows++
|
||||
if err := processStreamInternal(r, tlp); err != nil {
|
||||
t.Fatalf("unexpected error: %s", err)
|
||||
}
|
||||
if rows != rowsExpected {
|
||||
t.Fatalf("unexpected rows read; got %d; want %d", rows, rowsExpected)
|
||||
}
|
||||
|
||||
if !reflect.DeepEqual(timestamps, timestampsExpected) {
|
||||
t.Fatalf("unexpected timestamps;\ngot\n%d\nwant\n%d", timestamps, timestampsExpected)
|
||||
}
|
||||
if result != resultExpected {
|
||||
t.Fatalf("unexpected result;\ngot\n%s\nwant\n%s", result, resultExpected)
|
||||
if err := tlp.Verify(rowsExpected, timestampsExpected, resultExpected); err != nil {
|
||||
t.Fatal(err)
|
||||
}
|
||||
}
|
||||
|
||||
data := `Jun 3 12:08:33 abcd systemd: Starting Update the local ESM caches...
|
||||
<165>Jun 4 12:08:33 abcd systemd[345]: abc defg
|
||||
<123>1 2023-06-03T17:42:12.345Z mymachine.example.com appname 12345 ID47 [exampleSDID@32473 iut="3" eventSource="Application 123 = ] 56" eventID="11211"] This is a test message with structured data.
|
||||
|
||||
48 <165>Jun 4 12:08:33 abcd systemd[345]: abc defg<123>1 2023-06-03T17:42:12.345Z mymachine.example.com appname 12345 ID47 [exampleSDID@32473 iut="3" eventSource="Application 123 = ] 56" eventID="11211"] This is a test message with structured data.
|
||||
`
|
||||
currentYear := 2023
|
||||
rowsExpected := 3
|
||||
timestampsExpected := []int64{1685794113000000000, 1685880513000000000, 1685814132345000000}
|
||||
resultExpected := `{"format":"rfc3164","timestamp":"","hostname":"abcd","app_name":"systemd","_msg":"Starting Update the local ESM caches..."}
|
||||
{"priority":"165","facility":"20","severity":"5","format":"rfc3164","timestamp":"","hostname":"abcd","app_name":"systemd","proc_id":"345","_msg":"abc defg"}
|
||||
{"priority":"123","facility":"15","severity":"3","format":"rfc5424","timestamp":"","hostname":"mymachine.example.com","app_name":"appname","proc_id":"12345","msg_id":"ID47","exampleSDID@32473":"iut=\"3\" eventSource=\"Application 123 = ] 56\" eventID=\"11211\"","_msg":"This is a test message with structured data."}
|
||||
`
|
||||
{"priority":"123","facility":"15","severity":"3","format":"rfc5424","timestamp":"","hostname":"mymachine.example.com","app_name":"appname","proc_id":"12345","msg_id":"ID47","exampleSDID@32473":"iut=\"3\" eventSource=\"Application 123 = ] 56\" eventID=\"11211\"","_msg":"This is a test message with structured data."}`
|
||||
f(data, currentYear, rowsExpected, timestampsExpected, resultExpected)
|
||||
}
|
||||
|
||||
func TestProcessStreamInternal_Failure(t *testing.T) {
|
||||
f := func(data string) {
|
||||
t.Helper()
|
||||
|
||||
MustInit()
|
||||
defer MustStop()
|
||||
|
||||
tlp := &insertutils.TestLogMessageProcessor{}
|
||||
r := bytes.NewBufferString(data)
|
||||
if err := processStreamInternal(r, tlp); err == nil {
|
||||
t.Fatalf("expecting non-nil error")
|
||||
}
|
||||
}
|
||||
|
||||
// invalid format for message size
|
||||
f("12foo bar")
|
||||
|
||||
// too big message size
|
||||
f("123 foo")
|
||||
f("123456789 bar")
|
||||
}
|
||||
|
|
|
@ -19,6 +19,8 @@ according to [these docs](https://docs.victoriametrics.com/victorialogs/quicksta
|
|||
|
||||
## tip
|
||||
|
||||
* BUGFIX: properly read syslog messages over TCP and TLS connections according to [RFC5425](https://datatracker.ietf.org/doc/html/rfc5425) when [data ingestion for syslog protocol](https://docs.victoriametrics.com/victorialogs/data-ingestion/syslog/) is enabled.
|
||||
|
||||
## [v0.20.0](https://github.com/VictoriaMetrics/VictoriaMetrics/releases/tag/v0.20.0-victorialogs)
|
||||
|
||||
Released at 2024-06-17
|
||||
|
|
|
@ -31,6 +31,11 @@ The following command starts VictoriaLogs, which accepts logs in Syslog format a
|
|||
./victoria-logs -syslog.listenAddr.tcp=:514 -syslog.listenAddr.udp=:514
|
||||
```
|
||||
|
||||
VictoriaLogs can accept logs from the following syslog collectors:
|
||||
|
||||
- [Rsyslog](https://www.rsyslog.com/). See [these docs](#rsyslog).
|
||||
- [Syslog-ng](https://www.syslog-ng.com/). See [these docs](#syslog-ng).
|
||||
|
||||
Multiple logs in Syslog format can be ingested via a single TCP connection or via a single UDP packet - just put every log on a separate line
|
||||
and delimit them with `\n` char.
|
||||
|
||||
|
@ -97,3 +102,25 @@ For example, the following command starts VictoriaLogs, which writes syslog mess
|
|||
```sh
|
||||
./victoria-logs -syslog.listenAddr.tcp=:514 -syslog.tenantID=12:34
|
||||
```
|
||||
|
||||
## Rsyslog
|
||||
|
||||
1. Run VictoriaLogs with `-syslog.listenAddr.tcp=:29514` command-line flag.
|
||||
1. Put the following line to [rsyslog](https://www.rsyslog.com/) config (this config is usually located at `/etc/rsyslog.conf`):
|
||||
```
|
||||
*.* @@victoria-logs-server:29514
|
||||
```
|
||||
Where `victoria-logs-server` is the hostname where VictoriaLogs runs. See [these docs](https://www.rsyslog.com/sending-messages-to-a-remote-syslog-server/)
|
||||
for more details.
|
||||
|
||||
## Syslog-ng
|
||||
|
||||
1. Run VictoriaLogs with `-syslog.listenAddr.tcp=:29514` command-line flag.
|
||||
1. Put the following line to [syslog-ng](https://www.syslog-ng.com/) config:
|
||||
```
|
||||
destination d_remote {
|
||||
tcp("victoria-logs-server" port(29514));
|
||||
};
|
||||
```
|
||||
Where `victoria-logs-server` is the hostname where VictoriaLogs runs.
|
||||
See [these docs](https://www.syslog-ng.com/technical-documents/doc/syslog-ng-open-source-edition/3.19/administration-guide/29#TOPIC-1094570) for details.
|
||||
|
|
Loading…
Reference in a new issue