Skip to content

Commit f793da4

Browse files
aorithaorith
committed
Add vsl tags Brotli, MSE4ObjIter and MSE4ChunkFault
1 parent 134dba1 commit f793da4

File tree

4 files changed

+243
-0
lines changed

4 files changed

+243
-0
lines changed

‎render/vcltree.go‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -58,12 +58,18 @@ func renderTxTree(s *rowBuilder, ts vsl.TransactionSet, tx *vsl.Transaction, vis
5858
s.addRow(r.GetTag(), "", record.String(), "")
5959
case vsl.GzipRecord:
6060
s.addRow(r.GetTag(), "", record.String(), "")
61+
case vsl.BrotliRecord:
62+
s.addRow(r.GetTag(), "", record.String(), "")
6163
case vsl.BackendOpenRecord:
6264
s.addRow(r.GetTag(), "", record.String(), "")
6365
case vsl.LengthRecord:
6466
s.addRow(r.GetTag(), "", record.Size.String(), "")
6567
case vsl.MSE4NewObjectRecord:
6668
s.addRow(r.GetTag(), "", record.String(), "")
69+
case vsl.MSE4ObjIterRecord:
70+
s.addRow(r.GetTag(), "", record.String(), "")
71+
case vsl.MSE4ChunkFaultRecord:
72+
s.addRow(r.GetTag(), "", record.String(), "")
6773
case vsl.VCLLogRecord:
6874
s.addRow(r.GetTag(), "", record.String(), "logMsg")
6975
case vsl.StatusRecord:

‎vsl/parser.go‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -238,6 +238,8 @@ func processRecord(line string) (Record, error) {
238238
return NewBackendCloseRecord(blr)
239239
case tags.BackendReuse:
240240
return NewBackendReuseRecord(blr)
241+
case tags.Brotli:
242+
return NewBrotliRecord(blr)
241243
case tags.ReqAcct, tags.BereqAcct:
242244
return NewAcctRecord(blr)
243245
case tags.PipeAcct:
@@ -256,6 +258,10 @@ func processRecord(line string) (Record, error) {
256258
return NewLengthRecord(blr)
257259
case tags.MSE4NewObject:
258260
return NewMSE4NewObjectRecord(blr)
261+
case tags.MSE4ObjIter:
262+
return NewMSE4ObjIterRecord(blr)
263+
case tags.MSE4ChunkFault:
264+
return NewMSE4ChunkFaultRecord(blr)
259265
case tags.Hit, tags.HitMiss, tags.HitPass:
260266
return NewHitRecord(blr)
261267
case tags.TTL:

‎vsl/records.go‎

Lines changed: 225 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1285,6 +1285,231 @@ func NewMSE4NewObjectRecord(blr BaseRecord) (MSE4NewObjectRecord, error) {
12851285
return record, nil
12861286
}
12871287

1288+
// MSE4ObjIterRecord holds MSE4 object payload iteration timing data
1289+
type MSE4ObjIterRecord struct {
1290+
BaseRecord
1291+
TimeElapsed time.Duration // Time elapsed between start and end of iteration (seconds)
1292+
BytesProcessed SizeValue // Number of bytes processed
1293+
TimeProcessing time.Duration // Total time spent processing (seconds)
1294+
TimeBackendWait time.Duration // Time spent waiting for backend data (seconds)
1295+
DiskIOBytes SizeValue // Disk IO bytes processed [persisted only]
1296+
TimeDiskIOProcessing time.Duration // Time spent on processing disk IO (seconds) [persisted only]
1297+
IsPersisted bool // Whether this object was persisted to disk
1298+
}
1299+
1300+
func (r MSE4ObjIterRecord) String() string {
1301+
s := fmt.Sprintf(
1302+
"%s elapsed | %s processed | %s processing | %s backend wait",
1303+
r.TimeElapsed,
1304+
r.BytesProcessed.String(),
1305+
r.TimeProcessing,
1306+
r.TimeBackendWait,
1307+
)
1308+
1309+
if r.IsPersisted {
1310+
s += fmt.Sprintf(
1311+
" | %s disk IO bytes | %s disk IO processing",
1312+
r.DiskIOBytes.String(),
1313+
r.TimeDiskIOProcessing,
1314+
)
1315+
}
1316+
1317+
return s
1318+
}
1319+
1320+
func NewMSE4ObjIterRecord(blr BaseRecord) (MSE4ObjIterRecord, error) {
1321+
parts := strings.Fields(blr.GetRawValue())
1322+
if len(parts) != 4 && len(parts) != 6 {
1323+
return MSE4ObjIterRecord{}, fmt.Errorf("conversion to MSE4ObjIterRecord failed, expected 4 or 6 fields, got %d on line %q", len(parts), blr.GetRawLog())
1324+
}
1325+
1326+
record := MSE4ObjIterRecord{BaseRecord: blr}
1327+
record.IsPersisted = len(parts) == 6
1328+
1329+
timeElapsed, err := strconv.ParseFloat(parts[0], 64)
1330+
if err != nil {
1331+
return MSE4ObjIterRecord{}, fmt.Errorf("conversion to MSE4ObjIterRecord failed, bad value for timeElapsed on line %q", blr.GetRawLog())
1332+
}
1333+
record.TimeElapsed = time.Duration(timeElapsed * float64(time.Second))
1334+
1335+
bytesProcessed, err := strconv.ParseInt(parts[1], 10, 64)
1336+
if err != nil {
1337+
return MSE4ObjIterRecord{}, fmt.Errorf("conversion to MSE4ObjIterRecord failed, bad value for bytesProcessed on line %q", blr.GetRawLog())
1338+
}
1339+
record.BytesProcessed = SizeValue(bytesProcessed)
1340+
1341+
timeProcessing, err := strconv.ParseFloat(parts[2], 64)
1342+
if err != nil {
1343+
return MSE4ObjIterRecord{}, fmt.Errorf("conversion to MSE4ObjIterRecord failed, bad value for timeProcessing on line %q", blr.GetRawLog())
1344+
}
1345+
record.TimeProcessing = time.Duration(timeProcessing * float64(time.Second))
1346+
1347+
timeBackendWait, err := strconv.ParseFloat(parts[3], 64)
1348+
if err != nil {
1349+
return MSE4ObjIterRecord{}, fmt.Errorf("conversion to MSE4ObjIterRecord failed, bad value for timeBackendWait on line %q", blr.GetRawLog())
1350+
}
1351+
record.TimeBackendWait = time.Duration(timeBackendWait * float64(time.Second))
1352+
1353+
// Parse optional persisted object fields
1354+
if record.IsPersisted {
1355+
diskIOBytes, err := strconv.ParseInt(parts[4], 10, 64)
1356+
if err != nil {
1357+
return MSE4ObjIterRecord{}, fmt.Errorf("conversion to MSE4ObjIterRecord failed, bad value for diskIOBytes on line %q", blr.GetRawLog())
1358+
}
1359+
record.DiskIOBytes = SizeValue(diskIOBytes)
1360+
1361+
timeDiskIOProcessing, err := strconv.ParseFloat(parts[5], 64)
1362+
if err != nil {
1363+
return MSE4ObjIterRecord{}, fmt.Errorf("conversion to MSE4ObjIterRecord failed, bad value for timeDiskIOProcessing on line %q", blr.GetRawLog())
1364+
}
1365+
record.TimeDiskIOProcessing = time.Duration(timeDiskIOProcessing * float64(time.Second))
1366+
}
1367+
1368+
return record, nil
1369+
}
1370+
1371+
// MSE4ChunkFaultRecord holds MSE4 persisted chunk memory fault timing data
1372+
type MSE4ChunkFaultRecord struct {
1373+
BaseRecord
1374+
ChunksProcessed int64 // Number of chunks processed
1375+
BytesProcessed SizeValue // Number of bytes processed
1376+
TimeProcessing time.Duration // Total time spent on processing (seconds)
1377+
TimeMemoryAllocation time.Duration // Time spent allocating memory (seconds)
1378+
TimeDiskIOWait time.Duration // Time spent waiting for disk IO (seconds)
1379+
}
1380+
1381+
func (r MSE4ChunkFaultRecord) String() string {
1382+
return fmt.Sprintf(
1383+
"%d chunks | %s processed | %s processing | %s mem alloc | %s disk IO wait",
1384+
r.ChunksProcessed,
1385+
r.BytesProcessed.String(),
1386+
r.TimeProcessing,
1387+
r.TimeMemoryAllocation,
1388+
r.TimeDiskIOWait,
1389+
)
1390+
}
1391+
1392+
func NewMSE4ChunkFaultRecord(blr BaseRecord) (MSE4ChunkFaultRecord, error) {
1393+
parts := strings.Fields(blr.GetRawValue())
1394+
if len(parts) != 5 {
1395+
return MSE4ChunkFaultRecord{}, fmt.Errorf("conversion to MSE4ChunkFaultRecord failed, expected 5 fields, got %d on line %q", len(parts), blr.GetRawLog())
1396+
}
1397+
1398+
record := MSE4ChunkFaultRecord{BaseRecord: blr}
1399+
1400+
chunksProcessed, err := strconv.ParseInt(parts[0], 10, 64)
1401+
if err != nil {
1402+
return MSE4ChunkFaultRecord{}, fmt.Errorf("conversion to MSE4ChunkFaultRecord failed, bad value for chunksProcessed on line %q", blr.GetRawLog())
1403+
}
1404+
record.ChunksProcessed = chunksProcessed
1405+
1406+
bytesProcessed, err := strconv.ParseInt(parts[1], 10, 64)
1407+
if err != nil {
1408+
return MSE4ChunkFaultRecord{}, fmt.Errorf("conversion to MSE4ChunkFaultRecord failed, bad value for bytesProcessed on line %q", blr.GetRawLog())
1409+
}
1410+
record.BytesProcessed = SizeValue(bytesProcessed)
1411+
1412+
timeProcessing, err := strconv.ParseFloat(parts[2], 64)
1413+
if err != nil {
1414+
return MSE4ChunkFaultRecord{}, fmt.Errorf("conversion to MSE4ChunkFaultRecord failed, bad value for timeProcessing on line %q", blr.GetRawLog())
1415+
}
1416+
record.TimeProcessing = time.Duration(timeProcessing * float64(time.Second))
1417+
1418+
timeMemoryAllocation, err := strconv.ParseFloat(parts[3], 64)
1419+
if err != nil {
1420+
return MSE4ChunkFaultRecord{}, fmt.Errorf("conversion to MSE4ChunkFaultRecord failed, bad value for timeMemoryAllocation on line %q", blr.GetRawLog())
1421+
}
1422+
record.TimeMemoryAllocation = time.Duration(timeMemoryAllocation * float64(time.Second))
1423+
1424+
timeDiskIOWait, err := strconv.ParseFloat(parts[4], 64)
1425+
if err != nil {
1426+
return MSE4ChunkFaultRecord{}, fmt.Errorf("conversion to MSE4ChunkFaultRecord failed, bad value for timeDiskIOWait on line %q", blr.GetRawLog())
1427+
}
1428+
record.TimeDiskIOWait = time.Duration(timeDiskIOWait * float64(time.Second))
1429+
1430+
return record, nil
1431+
}
1432+
1433+
// BrotliRecord holds Brotli compression/decompression operation data
1434+
type BrotliRecord struct {
1435+
BaseRecord
1436+
Operation rune // 'B': Brotli, 'U': Unbrotli, 'u': Unbrotli-test
1437+
Direction rune // 'F': Fetch, 'D': Deliver
1438+
BytesInput SizeValue // Bytes input
1439+
BytesOutput SizeValue // Bytes output
1440+
}
1441+
1442+
func (r BrotliRecord) String() string {
1443+
var operation string
1444+
switch r.Operation {
1445+
case 'B':
1446+
operation = "Brotli"
1447+
case 'U':
1448+
operation = "Unbrotli"
1449+
case 'u':
1450+
operation = "Unbrotli-test"
1451+
default:
1452+
operation = string(r.Operation)
1453+
}
1454+
1455+
var direction string
1456+
switch r.Direction {
1457+
case 'F':
1458+
direction = "Fetch"
1459+
case 'D':
1460+
direction = "Deliver"
1461+
default:
1462+
direction = string(r.Direction)
1463+
}
1464+
1465+
return fmt.Sprintf(
1466+
"%s | %s | %s input | %s output",
1467+
operation,
1468+
direction,
1469+
r.BytesInput.String(),
1470+
r.BytesOutput.String(),
1471+
)
1472+
}
1473+
1474+
func NewBrotliRecord(blr BaseRecord) (BrotliRecord, error) {
1475+
parts := strings.Fields(blr.GetRawValue())
1476+
if len(parts) != 4 {
1477+
return BrotliRecord{}, fmt.Errorf("conversion to BrotliRecord failed, expected 4 fields, got %d on line %q", len(parts), blr.GetRawLog())
1478+
}
1479+
1480+
record := BrotliRecord{BaseRecord: blr}
1481+
1482+
if len(parts[0]) != 1 {
1483+
return BrotliRecord{}, fmt.Errorf("conversion to BrotliRecord failed, bad value for operation on line %q", blr.GetRawLog())
1484+
}
1485+
record.Operation = rune(parts[0][0])
1486+
if record.Operation != 'B' && record.Operation != 'U' && record.Operation != 'u' {
1487+
return BrotliRecord{}, fmt.Errorf("conversion to BrotliRecord failed, invalid operation '%c' on line %q", record.Operation, blr.GetRawLog())
1488+
}
1489+
1490+
if len(parts[1]) != 1 {
1491+
return BrotliRecord{}, fmt.Errorf("conversion to BrotliRecord failed, bad value for direction on line %q", blr.GetRawLog())
1492+
}
1493+
record.Direction = rune(parts[1][0])
1494+
if record.Direction != 'F' && record.Direction != 'D' {
1495+
return BrotliRecord{}, fmt.Errorf("conversion to BrotliRecord failed, invalid direction '%c' on line %q", record.Direction, blr.GetRawLog())
1496+
}
1497+
1498+
bytesInput, err := strconv.ParseInt(parts[2], 10, 64)
1499+
if err != nil {
1500+
return BrotliRecord{}, fmt.Errorf("conversion to BrotliRecord failed, bad value for bytesInput on line %q", blr.GetRawLog())
1501+
}
1502+
record.BytesInput = SizeValue(bytesInput)
1503+
1504+
bytesOutput, err := strconv.ParseInt(parts[3], 10, 64)
1505+
if err != nil {
1506+
return BrotliRecord{}, fmt.Errorf("conversion to BrotliRecord failed, bad value for bytesOutput on line %q", blr.GetRawLog())
1507+
}
1508+
record.BytesOutput = SizeValue(bytesOutput)
1509+
1510+
return record, nil
1511+
}
1512+
12881513
/* BaseRecord aliases */
12891514

12901515
// EndRecord marks the end of a transaction

‎vsl/tags/tags.go‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -60,6 +60,8 @@ const (
6060
BerespStatus = "BerespStatus"
6161
// Bogus HTTP received
6262
BogoHeader = "BogoHeader"
63+
// Brotli - (un)Brotli performed on object
64+
Brotli = "Brotli"
6365
// ESI parser error or warning message
6466
ESIXMLError = "ESI_xmlerror"
6567
// Error messages
@@ -92,6 +94,10 @@ const (
9294
LostHeader = "LostHeader"
9395
// MSE4 new object timing data
9496
MSE4NewObject = "MSE4_NewObject"
97+
// MSE4 object payload iteration timing summary
98+
MSE4ObjIter = "MSE4_ObjIter"
99+
// MSE4 persisted chunk memory fault
100+
MSE4ChunkFault = "MSE4_ChunkFault"
95101
// Informational messages about request handling
96102
Notice = "Notice"
97103
// Object protocol

0 commit comments

Comments
 (0)