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 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. See Protocol levels: server/client).

• Updated versions of events are represented by having the two-digit server protocol level included after a period (.) in the event type field. For example, 2.53 is associated with the 2021.2 release, and 1.55 is associated with the 2022.2 release.

• 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 2022.1 structured log events format, set the serverlog.version.N configurable to 54.

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+ The cmd field indicates approximately how much memory the command used, and the proc field indicates the approximate peak usage of the process. See P4LOG in Helix Core Command-Line (P4) Reference. [22.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	NetworkPerformance (type 8) events 19.2+ Network performance tracking; Includes send/receive errors and duplex stats 22.2+ 8.55 tracks server-to-server network usage on replicas, with the f_trackType field having the P4PORT data appended to the rpc string after a hyphen (-) in this manner: f_trackType rpc-perforce.com:1666 See the examples and explanations at server-to-server network usage on replicas.
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 librarian 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
cmd	Approximately how many megabytes of memory the command used. See also proc below.	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
proc	Approximately how many megabytes of memory were used by the process or thread associated with the cmd field. See P4LOG in Helix Core Command-Line (P4) Reference.	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