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:

  • 19.2+ indicates that 2019.2 or later is required, and

  • 21.2+ indicates that 2021.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) 19.2+
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 19.2+
9 track-db Database performance tracking; Includes lock times, including peek 19.2+
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 19.2+
22 ServerLockPerformance Logs the use of serverlocks 19.2+
23 DatabaseBlockingLocksTaken Logs the failed lock attempts prior to a blocking lock being taken 19.2+
24 LibrarianUsage Tracking metrics for the librarianClosed The librarian subsystem of the server stores, manages, and provides the archive files to other subsystems of the Helix Core server.21.2+

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:

  • 19.2+ indicates that 2019.2 or later is required, and

  • 21.2+ indicates that 2021.2 or later is required

Field Description Event Types
action Action ldapsync purge
action Audit action audit
address Location of remote database RemoteDatabasePerformance 19.2+
args Command arguments

command-compute
command-end
command-start
LibrarianUsage 21.2+
RemoteDatabasePerformance 19.2+
attempts Number of lock attempts prior to blocking DatabaseBlockingLocksTaken 19.2+
checkins New revisions of archive files made permanent LibrarianUsage 21.2+
client Client workspace All
closes Archive files closed LibrarianUsage 21.2+
cmdident Command identity 19.2+ All
cmdno Command number All
context Context for trigger trigger
copies Archive files copied LibrarianUsage 21.2+
date Date All
dbName Database table name track-db
deletes Database deletes track-db
deletes Archive files deleted LibrarianUsage 21.2+
digests Digests computed for archive files LibrarianUsage 21.2+
eventCode Event code event
eventInfo Event info event
eventtype Event type All
exists Existence checks for archive files LibrarianUsage 21.2+
file File purge
file File name audit
filesize File revision size audit-size
filesizes Sizes computed for archive files LibrarianUsage 21.2+
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 19.2+
lbrType Type of librarian file for which metrics are attributable LibrarianUsage 21.2+
lockName Lock name ServerLockPerformance 19.2+
lockTarget Lock locations ServerLockPerformance 19.2+
lockType

Lock type:

  • Read
  • Write
 ServerLockPerformance 19.2+
maxrss Max physical memory track-usage
modtimes Modification time determinations for archive files LibrarianUsage 21.2+
net_in IPC in track-usage
net_out IPC out track-usage
opens Archive files opened LibrarianUsage 21.2+
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 19.2+
pipeRows Number of DB rows sent to remote location RemoteDatabasePerformance 19.2+
pipeTime Time taken to transmit data to remote location RemoteDatabasePerformance 19.2+
positions Database positions track-db
prog Program All
readbytes Bytes read from archive files LibrarianUsage 21.2+
readLocks Read locks track-db
reads Read operations from archive files LibrarianUsage 21.2+
reason

Reason for event termination:

  • standard error
  • terminated by monitor command
  • authentication failed
  • maxLimit reached

auth 19.2+
command-end 19.2+
ldapsync19.2+
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_fwd Highmark forward, the limit of anticipated round trip data when content is being sent towards the client track-rpc
rpc_hi_mark_rev Highmark reverse, the imit of anticipated round trip data when content is being received from the client 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 19.2+
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
errors-failed
errors-fatal
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 19.2+
totalLockWaitRead Total wait time on read lock ServerLockPerformance 19.2+
totalLockWaitWrite Total wait time on write lock ServerLockPerformance 19.2+
trackType Server tracking type RemoteDatabasePerformance 19.2+
ServerLockPerformance 19.2+
trackType Tracking type

LibrarianUsage 21.2+
track-db
track-rpc
track-usage
triggerAction Trigger action trigger
triggerData Trigger data trigger
triggerLapse Trigger lapse time trigger 19.2+
triggerType Trigger type trigger 19.2+
user User All
user User Name ldapsync
utime User time track-usage
version Program version All
writebytes Bytes written to archive files LibrarianUsage 21.2+
writeLocks Write locks track-db
writes Write operations to archive files LibrarianUsage 21.2+

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