eMake Debug Log Levels

5 minute read

This section discusses eMake debug log levels. Content was adapted from the “Electric Make debug log levels” blog post on https://blog.melski.net/ and was the most recent information available when the article was posted.

Disclaimer: eMake debug logs are intended for use by CloudBees engineering and support staff. Debug logging contents and availability are subject to change in any release, for any or no reason.

Often when analyzing builds executed with eMake, all of the information you need is in the annotation file—an easily digested XML file containing data such as the relationships between the jobs, the commands run, and the timing of each job. But sometimes you need more detail, and that is where the eMake debug log is useful.

Enabling eMake Debug Logging

To enable eMake debug logging, specify this pair of command-line arguments:

--emake-debug=<value> specifies the types of debug logging to enable. Provide a set of single-letter values, such as “ jng ”.

--emake-logfile=<path> specifies the location of the debug log.

eMake Debug Log Level Descriptions

Available log levels:

a: agent allocation

l: ledger

c: cache

m: memory

e: environment

n: node

f: file system

o: parse output

g: profiling

p: parse

h: history

P: parse avoidance

j: job

r: parse relocation

L: nmake lexer

s: subbuild

Y: security

a: agent allocation

Agent allocation logging provides detailed information about eMake’s attempts to procure agents from the Cluster Manager during the build. If you think eMake might be stalled trying to acquire agents, allocation logging will help to understand what is happening.

c: cache

Cache logging records details about the file system cache used by eMake to accelerate parse jobs in cluster builds. For example, it logs when a directory’s contents are added to the cache, and the result of lookups in the cache. Because it is only used during remote parse jobs, you must use it with the ` --emake-rdebug=value ` option. Use cache logging if you suspect a problem with the cached local file system .

e: environment

Environment logging augments node logging with a dump of the entire environment block for every job as it is sent to an agent. Normally this is omitted because it is quite verbose (could be as much as 32 KB per job). Generally, it is better to use env-level annotation, which is more compact and easier to parse.

f: file system

File system logging records numerous details about eMake’s interaction with its versioned file system data structure. In particular, it logs every time that eMake looks up a file (when doing up-to-date checks, for example), and it logs every update to the versioned file system caused by file usage during the build’s execution. This level of logging is very verbose, so it is not usually enabled. It is most often used when diagnosing issues related to the versioned file system and conflicts.

g: profiling

Profiling debug logging is one of the easiest-to-interpret and most useful types of debug logging. When enabled, eMake emits hundreds of performance metrics at the end of the build. This is a very lightweight logging level and is safe (and advisable) to enable for all builds.

h: history

History logging prints messages related to the data tracked in the eMake history file—both file system dependencies and autodep information. When history logging is enabled, eMake will print a message every time a dependency is added to the history file, and it will print information about the files checked during up-to-date checks based on autodep data. Enable history logging if you suspect a problem with autodep behavior.

j: job

Job logging prints minimal messages related to the creation and execution of jobs. For each job you will see a message when it starts running, when it finishes running, and when eMake checks the job for conflicts. If there is a conflict in the job, you will see a message about that, too. If you just want a general overview of how the build is progressing, j-level logging is a good choice.

L: nmake lexer

eMake uses a generated parser to process portions of NMAKE makefiles. Lexer debug logging enables the debug logging in that generated code. This is generally not useful to end users because it is too low-level.

l: ledger

Ledger debug logging prints information about build decisions based on data in the ledger file, as well as updates made to the ledger file. Enable it if you believe the ledger is not functioning correctly.

m: memory

When memory logging is enabled, eMake prints memory usage metrics to the debug log once per second. This includes the total process memory usage as well as current and peak memory usage grouped into several “buckets” that correspond to various types of data in eMake. For example, the “Operation” bucket indicates the amount of memory used to store file operations; the “Variable” bucket is the amount of memory used for makefile variables. This is most useful when you are experiencing an out-of-memory failure in eMake because it can provide guidance about how memory is being utilized during the build, and how quickly it is growing.

n:node

Node logging prints detailed information about all messages between eMake and the agents, including file system data and commands executed. Together with job logging, this can give a very comprehensive picture of the behavior of a build. However, node logging is extremely verbose, so enable it only when you are chasing a specific problem.

o: parse output

Parse output logging instructs eMake to preserve the raw result of parsing a makefile. The result is a binary file containing information about all targets, rules, dependencies, and variables extracted from makefiles read during a parse job. This can be useful when investigating parser incompatibility issues and scheduling issues (for example, if a rule is not being scheduled for execution when you expect). Note that this debug level only makes sense when parsing, which means you must specify it in the ` --emake-rdebug ` option. The parse results will be saved in the ` --emake-rlogdir ` directory, named as ` parse_jobid.out`. Note that the directory might be on the local disk of the remote nodes, depending on the value you specify.

p: parse

Parse debug logging prints extremely detailed information about the reading and interpretation of makefiles during a parse job. This is most useful when investigating parser compatibility issues. This output is very verbose, so enable it only when you are pursuing a specific problem. Like parse output logging, this debug level only makes sense during parsing, which means you must specify it in the ` --emake-rdebug ` option. The parse log files will be saved in the --emake-rlogdir ` directory, named as ` parse_jobid.dlog. Note that the directory might be on the local disk of the remote nodes, depending on the value you specify.

P: parse avoidance

Parse avoidance logging indicates when a new parse is required, and if so, why it was required.

r: parse relocation

Parse relocation logging prints low-level information about the process of transmitting parse result data to eMake at the end of a parse job. It is used only internally when we the parse result format is being extended, so is unlikely to be of interest to end-users.

s: subbuild

Subbuild logging prints details about decisions made while using the eMake subbuild feature. Enable it if you believe that the subbuild feature is not working correctly.

Y: authentication

Authentication logging is a subset of node logging that prints only those messages related to authenticating eMake to agents and vice-versa. Enable this debug level, if you are having problems using the authentication feature.