This is the P4 Log Feeder project, in the //p4lf stream depot on the Perforce Public Depot server.
The goal of this project is to frequently grab chunks of a P4LOG from a P4 Server using the 'p4 logtail' command, and generate chunk log files in a designated directory. External automation (outside the scope of this project) is expected to grab files in the directory matching the pattern log.*.gz, send them elsewhere (e.g. for ingestion into Splunk), and then delete the local files. The job of P4LF is to populate the directory, external software does the rest. This frequent feeding of log data into Splunk (or similar) is intended to make data available in near-real-time for the analytics and diagnostics that it can do.
This will work with servers deployed with the P4 Server Deployment Package (SDP).
Any executable scripts, binaries, and config files will be deployed in the SDP structure in the /p4/common/site/log_feeder folder.
A config file will define these settings:
The service must smoothly handle rotation of the P4LOG, whether by SDP script operations that handle P4LOG changes or human admins doing commands like 'mv log log.old'. The p4lf script will not be directly aware of P4LOG rotations, so it must try to detect them with indications based on the change in the offset value reported by 'p4 logtail'. If the offset reported by 'p4 logtail' is same as the offset provided to the 'p4 logtail' command and there was no output, that can be taken as an indication that the log has been rotated. For example, in an interactive session done just after a log rotation, you might see this:
p4 logtail -s 683004600 ... file /p4/1/logs/log ... offset 683004600
That fact that the offset provided and the offset indicated are the same value means nothing new has appeared since that byte offset. On a real production server, the P4LOG is typically updated more than once per second, so this scenario is unlikely to occur unless it's caused by a log rotation. If we see this, we can assume a log rotation occurred.
backup_functions.sh file in the function rotate_log_file() indicates how the log is rotated and gzipped. Because this p4lf calls 'p4 logtail' frequently and the rotate_log_file() is called typically only once daily, it's possible the P4LOG gzip done by the rotate_log_file() function will still be in progress. So, could wait for that to finish, copy it to the LogChunksDir, unzip the copy, and somehow translate the byte offset last used to an line number in log to generate a 'tail' command to capture the "end of the log" snippet that came after the last call to 'p4 logtail'. (This is least defined part of this spec; suggestions on improving the design here are most welcome).# Welcome to the Perforce P4 Log Feeder, P4LF!
## Introduction
This is the P4 Log Feeder project, in the //p4lf stream depot on the Perforce Public Depot server.
The goal of this project is to frequently grab chunks of a P4LOG from a P4 Server using the 'p4 logtail' command, and generate chunk log files in a designated directory. External automation (outside the scope of this project) is expected to grab files in the directory matching the pattern log.\*.gz, send them elsewhere (e.g. for ingestion into Splunk), and then delete the local files. The job of P4LF is to populate the directory, external software does the rest. This frequent feeding of log data into Splunk (or similar) is intended to make data available in near-real-time for the analytics and diagnostics that it can do.
This will work with servers deployed with the P4 Server Deployment Package (SDP).
Any executable scripts, binaries, and config files will be deployed in the SDP structure in the /p4/common/site/log_feeder folder.
## Config File Settings
A config file will define these settings:
* LogTailDelay - Number of seconds between 'p4 logtail' commands. Default: 60s; time formats can be '[0-9]+[hms]{1}$' (e.g. 180s, 3m, 1h).
* LogChunksDir - Directory path to be used for storing log chunks. Default: '$LOGS/logchunks'. Example value: '$LOGS/splunklogs'.
* MaxLogChunks - Max number of log chunk files before we stop capturing. A value of '0' means no max number of files. Service continues to run and check until number of files decreases below the max. Default: 0.
* MinLogSpace - Minimum space in directory/volume where LogChunksDir is, before we stop capturing. A value of 'None' (or '0') means no min space check.Service continues to run and check until space increases above the minimum. Value can be specified as a percentage, e.g 3%, or a size, e.g. 3G, 1T, 500M. Default: None
* MaxLogSize - After this script's own log exceeds a max log size, the service will rotate its own log to $LOGS/p4lf.<timestamp>.log and then gzip the rotated log.
* MaxLogOffsetDelta - Maximum difference in byte offset. Between calls to 'p4 logtail', if the difference in offset is massive, don't try to pull too much at once, which could possibly cause a performance issue.
* MaxLogStartOffset - Maximum byte offset before we are willing to lose log data in a log rotation scenario (more info below on this).
* Debug - Numeric value with '0' indicating off and '1' indicating on. (If warranted, we can support values of 2+ for extra pedantic logging.
## Basic Flow
* A fixed name log file $LOGS/p4lf.log is used by the service.
* On service startup, or on detection of an update to the config file modtime, the config file is loaded.
* The script will run as a systemd service that can be started and stopped.
* The service will call 'p4 logtail' frequently to grab log chunks.
* Each chunk will be stored in a file in the LogsChunksDir named P4LOG_chunk.<offset1>.<offset2>
* Each chunk file will then be gzipped; changing the name to P4LOG_chunk.<offset1>.<offset2>.gz
* The zipped chunk file will be renamed to log.<offset1>.<offset2>.gz
* External automation (outside the scope of this project) is expected to grab files in the LogChunksDir matching the pattern log.\*.gz, send them elsewhere (e.g. to Splunk), and then delete them.
* The 'offset' reported by 'p4 logtail' will be used each time to request data since the last chunk, so that the logs will "just work"
* As needed based on MaxLogSize, this script will rotate its own log.
* On receipt of a standard Linux signal to reload config, the script will reload the config and rotate its log.
## Design Concepts (not hard requirements)
* Be written in bash, so as to minimize dependencies.
* Run as a systemd service named p4lf, operating as User=perforce.
* Avoid undue impact to performance of p4d. For example:
- If the service is offline for a time, it is better to lose chunks of log data than to try to grab too much log data at once.
- Id the difference between the last offset and current offset is massive, allow data to be discarded.
* Even though this is separate from the SDP, honor the SDP Coding Standard for Bash Scripts: https://workshop.perforce.com/view/guest/perforce_software/sdp/dev/doc/SDP_CodingStandard_bash.html
* The service must smoothly handle rotation of the P4LOG, whether by SDP script operations that handle P4LOG changes or human admins doing commands like 'mv log log.old'. The p4lf script will not be directly aware of P4LOG rotations, so it must try to detect them with indications based on the change in the offset value reported by 'p4 logtail'. If the offset reported by 'p4 logtail' is _same_ as the offset provided to the 'p4 logtail' command and there was no output, that can be taken as an indication that the log has been rotated. For example, in an interactive session done just after a log rotation, you might see this:
p4 logtail -s 683004600
... file /p4/1/logs/log
... offset 683004600
That fact that the offset provided and the offset indicated are the same value means nothing new has appeared since that byte offset. On a real production server, the P4LOG is typically updated more than once per second, so this scenario is unlikely to occur unless it's caused by a log rotation. If we see this, we can assume a log rotation occurred.
* When the log is rotated:
- Check the size of the offset and compare to MaxLogStartOffset.
- If the offset is less than or equal to the max, delete the chunk just returned by 'p4 logtail' reset the offset to 0, and call 'p4 logtail -s 0' to pull all the data from the start of recently rotated log, so no log data is lost. Then capture the newly returned offset. ALSO.
- Otherwise, use the log snippet just returned, and note the log rotation event in this scripts log, with a warning that a chunk of text was foregone due to the text size exceeding the MaxLogStartOffset.
- A chunk of the P4LOG may have been missed, i.e. whatever text went into P4LOG after the last call to 'p4 logtail' and before the log rotation event. Ideally, we want to capture that log text, but since it can no longer be acquired with 'p4 logtail', we need to find the rotated P4LOG. Logic in the SDP `backup_functions.sh` file in the function rotate_log_file() indicates how the log is rotated and gzipped. Because this p4lf calls 'p4 logtail' frequently and the rotate_log_file() is called typically only once daily, it's possible the P4LOG gzip done by the rotate_log_file() function will still be in progress. So, could wait for that to finish, copy it to the LogChunksDir, unzip the copy, and somehow translate the byte offset last used to an line number in log to generate a 'tail' command to capture the "end of the log" snippet that came after the last call to 'p4 logtail'. (This is least defined part of this spec; suggestions on improving the design here are most welcome).
* Logging for p4lf will track service start and stop, processing commands and outputs (if any), log rotation event detection, and errors. The output of 'p4 logtail' commands will NOT be captured in the log.
| # | Change | User | Description | Committed | |
|---|---|---|---|---|---|
| #5 | 32814 | C. Thomas Tyler | More refinements. | ||
| #4 | 32811 | C. Thomas Tyler | Further refinements. | ||
| #3 | 32810 | C. Thomas Tyler | Fleshed out with more detail. | ||
| #2 | 32808 | C. Thomas Tyler | Added more details. | ||
| #1 | 32802 | C. Thomas Tyler | Initial pass as README.md |