Using structured logging
Structured server logs record information about server and user activity. Logs are written in comma separated value (CSV) format which can be processed by external tools or natively using the p4 logparse command. Structured logs can be configured to easily manage automatic log file rotation and log retention policies.
Structured server logs are intended to supplement standard Helix Server logs, not replace them.
Structured server logs:
- Record information about server and user activity
- Are written in comma separated value (CSV) format to facilitate parsing with the p4 logparse command
- Can be verbose and grow rapidly, so we recommend that you establish a process for automatic log file rotation and a policy for log retention
Versioned Log Schema
With Helix Server 2019.2 and later, structured logs have a versioned schema that allows new versions of existing events to be added. Updated versions of events are represented by having the server protocol level included after a period in the event type field. For example, 2.49 is associated with the 2019.2 release. See Protocol levels of server and client by server release number).
The serverlog.version.N configurable can be used to pin a structured log file to a specific server version's format. For example, to retain the 2019.2 structured log events format, set the serverlog.version.N configurable to 49.
Event types with new versions in Helix Server 2020.1
All event types have a new version N.50 in the 2020.1 release which adds a unique command identifier and the current serverId after the command number field (5th column). For commands that result in log events being written on multiple servers, the unique command identifier will have been propagated to allow those events to be matched up. Examples include submits from edge servers, replica forwarded commands, remote depot access, and P4AUTH.
The 11.50 trigger event type has two additional fields, f_triggerType which is one of trigger, extension, or bgtask, and f_triggerLapse, which records the trigger execution lapse time. Trigger arguments are now separated by colon (:) characters to match the command arguments format.
Event types with new versions in Helix Server 2019.2
2.49 - CommandEnd
6.49 - Audit
8.49 - NetworkPerformance
9.49 - DatabasePerformance
To retain the 2019.1 structured log events format, set the serverlog.version.N configurable to 48.
Structured Server Log Records
All structured server log records contain an event type written as the first field in the log record.
Prior to Helix Server 2019.2, the event type was an integer value.
With 2019.2 and later, the event type includes the server protocol level after a period in the event type field, such as 2.49 for a command-end log event written by a 2019.2 Helix Server.
Events are applicable to server versions that support structured logging (2012.1 and later), except where ** indicates that 2019.2 or later is required.
Structured Log Events
Type | Name | Description |
---|---|---|
0 | command-start | Command start |
1 | command-compute | Compute end |
2 | command-end | Command end;
Lapse time and termination reason (error, auth, max*, monitor, etc) * * |
3 | errors-all | All errors |
4 | errors-failed | Failed errors - User errors ('user' has not been enabled, Invalid option:, Submit failed) |
5 | errors-fatal | Fatal errors - System errors (Database open errors, Operation 'open' failed) |
6 | audit | Audit events (p4 sync, p4 archive, ...) |
7 | track-usage | Performance usage tracking |
8 | track-rpc | Network performance tracking; Includes send/receive errors and duplex stats * * |
9 | Network performance tracking; Includes send/receive errors and duplex stats * * | Database performance tracking; Includes lock times, including peek * * |
10 | user | User events from p4 logappend |
11 | trigger | Trigger events |
12 | event | Server startup, shutdown, restart, checkpoint, journal rotate |
13 | purge | purge revision (p4 obliterate) |
14 | network-estimates | Network estimates |
15 | integrity | Replica integrity checking events |
16 | auth | Login events |
17 | route | Network route of client connections |
18 | audit-size | Audit events including file revision's size |
19 | ldapsync | p4 ldapsync events |
20 | action | Primarily stores insert, update and delete actions such as: depot, change, submit |
21 | RemoteDatabasePerformance | logs tracking data for remote database access * * |
22 | ServerLockPerformance | logs the failed lock attempts prior to a blocking lock being taken * * |
23 | DatabaseBlockingLocksTaken | logs the failed lock attempts prior to a blocking lock being * * |
Structured Log Record Fields are based on event type
Events are applicable to server versions that support structured logging (2012.1 and later), except where ** indicated that 2019.2 or later is required.
Field | Description | Event Types |
---|---|---|
action | Action | ldapsync purge |
action | Audit action | audit |
address | Location of remote database | RemoteDatabasePerformance ** |
args | Command arguments | command-compute
command-end command-start RemoteDatabasePerformance * * |
attempts | Number of lock attempts prior to blocking | DatabaseBlockingLocksTaken * * |
client | Client workspace | All |
cmdident | Command identity * * | All |
cmdno | Command number | All |
context | Context for trigger | trigger |
date | Date | All |
dbName | Database table name | track-db |
deletes | Database deletes | track-db |
eventCode | Event code | event |
eventInfo | Event info | event |
eventtype | Event type | All |
file | File | purge |
file | File name | audit |
filesize | File revision size | audit-size |
func | Command | All |
gets | Database gets | track-db |
group | Group name | ldapsync |
host | Client host | All |
io_in | I/O reads | track-usage |
io_out | I/O writes | track-usage |
lapse | Lapse Time | command-end * * |
lockName | Lock name | ServerLockPerformance * * |
lockTarget | Lock locations | ServerLockPerformance * * |
lockType |
Lock type:
|
ServerLockPerformance * * |
maxrss | Max physical memory | track-usage |
net_in | IPC in | track-usage |
net_out | IPC out | track-usage |
page_faults | Page faults | track-usage |
pagesCached | Pages cached | track-db |
pagesIn | Pages in | track-db |
pagesOut | Pages out | track-db |
pid | Process ID | All |
pipeProbe | Number of pipe probes sent remote location | RemoteDatabasePerformance * * |
pipeRows | Number of DB rows sent to remote location | RemoteDatabasePerformance * * |
pipeTime | Time taken to transmit data to remote location | RemoteDatabasePerformance * * |
positions | Database positions | track-db |
prog | Program | All |
readLocks | Read locks | track-db |
reason |
Reason for event termination:
|
auth * * |
recvBytes | Receive bytes | track-rpc |
recvCount | Receive count | track-rpc |
recvTime | Receive time | track-rpc |
reorderIntl | Reorder internal | track-db |
reorderLeaf | Reorder leaf | track-db |
result | Result | ldapsync |
rev | File revision | audit |
rev | Revision | purge |
rpc_hi_mark_fws | Highmark forward | track-rpc |
rpc_hi_mark_rev | Highmark reverse | track-rpc |
scans | Database scans | track-db |
sendBytes | Send bytes | track-rpc |
sendCount | Send count | track-rpc |
sendTime | Send time | track-rpc |
serverid | Server ID | All ** |
severity | Severity level |
errors-all errors-failed errors-fatal |
stime | System time | track-usage |
subcode | Subsystem code |
errors-all errors-failed errors-fatal |
subsys | Subsystem |
errors-all errors-failed errors-fatal |
targetID | Target ID | trigger |
targetType | Target type | trigger |
text | Error text |
errors-all
|
timer | Timer | track-usage |
timestamp | Unix timestamp | All |
timestamp2 | High-precision timestamp | All |
totalLockHeldRead | Total hold time on read lock | All |
totalLockHeldWrite | Total hold time on write lock | ServerLockPerformance ** |
totalLockWaitRead | Total wait time on read lock | ServerLockPerformance ** |
totalLockWaitWrite | Total wait time on write lock | ServerLockPerformance ** |
trackType | Server tracking type | RemoteDatabasePerformance ** ServerLockPerformance ** |
trackType | Tracking type |
track-db
|
triggerAction | Trigger action | trigger |
triggerData | Trigger data | trigger |
triggerLapse | Trigger lapse time | trigger ** |
triggerType | Trigger type | trigger ** |
user | User | All |
user | User Name | ldapsync |
utime | User time | track-usage |
version | Program version | All |
writeLocks | Write locks | track-db |
Log record details
For a specific log record, use the event type and p4 logschema to get details on the specific fields in the record. For example, an event record (type 12) from the log:
12,1474054242,775358804,2016/09/16 12:30:42 75358804,21204,4,shutdown p4 -F '%f_name%' logschema 12 f_eventtype f_timestamp f_timestamp2 f_date f_pid f_eventCode f_eventInfo
Integrity events
The integrity event type is recorded in the f_integrityEvent field.
0 | Unknown |
1 | VerifyResults |
2 | Unload |
3 | UnloadResults |
4 | ScanStart |
5 | ScanEnd |
6 | ScanResults |
7 | ChangeVerify |
8 | ChangeResults |
9 | TableResults |