Profiling mode¶

The profiling mode shows how a program uses Daf: how big its tables get, what is done with them, and which lines of the program do it. Use it to decide where Daffodil needs to be faster, or where a program uses it in a costly way.

Turning it on¶

Set an environment variable. The program needs no change.

DAFFODIL_PROFILE=1 DAFFODIL_PROFILE_STAGE=tabulate python my_program.py

When the program ends, the profile is written to daffodil_profile_<stage>_<host>_<pid>.md in DAFFODIL_PROFILE_DIR, the current directory by default. The report is printed to stderr. DAFFODIL_PROFILE_FILE also writes the report to a file.

Or turn it on in code:

from daffodil.lib import daf_profile

daf_profile.start(stage='tabulate')
run_the_work()
print(daf_profile.report())
daf_profile.stop()

A pipeline of stages¶

A pipeline whose stages run as separate programs gets one profile file per stage. Give each stage its name, and write the files to one directory:

export DAFFODIL_PROFILE=1 DAFFODIL_PROFILE_DIR=profile_run
DAFFODIL_PROFILE_STAGE=load     python stage_load.py
DAFFODIL_PROFILE_STAGE=tabulate python stage_tabulate.py
python -m daffodil.lib.daf_profile combine profile_run -o report.md

The report has a section for all the stages together, and one for each stage. --data combined.md also writes the combined tables.

The profile is Daf tables¶

The totals are kept as Daf tables, and a profile file is those tables in Markdown, written with Daf.dodaf_to_md(). Every table has a stage column.

Table	One row for each	Columns
`info`	process	host, pid, Python and daffodil versions, start time, seconds
`tables`	stage, creation line and way of making a table	tables, keyed, most rows and columns, tables in each size band
`ops`	stage, creation line, way of making, and method	calls on those tables
`methods`	stage and method	calls, seconds, rows at each call in size bands, most rows
`sites`	stage, call site and method	calls, seconds

daf_profile.tables() returns them for the current process, load(path) reads a file, and combine(runs) adds the tables of several runs. Counts and times are added. The most rows and columns take the largest. combine() uses groupby_cols_reduce() to do it.

A call site is the module and line, as in auditengine.tabulate:212, so the same line has the same name in every run. A script run directly is named by its file name.

What it records¶

It keeps running totals, not a log of every call, so memory stays small.

Each table. The line that created it, and how: Daf(), from_csv, select_where and so on. The most rows and columns it had, whether it had a keyfield, and a count of each method called on it. When the table is freed, this summary is added to the totals for its creation line. The median size is reported as the size band that holds it, since bands can be combined across runs and a running sample cannot.
Each method. Calls, total time, and the rows of the table at each call, in size bands.
Each call site. Calls and total time, by method.

Only outer calls are counted. When a Daf method calls another one inside, the inner call is not counted. A table that is built by 10,000 calls to append() is one table, with append 10,000 in its list of operations.

The report¶

The report lists the runs, then has four Markdown tables, for all stages and for each stage.

Tables by the line that created them. Tables made at the same line are grouped, so a loop that makes 3,000 small tables is one line, with the median and the largest size.
Table sizes. How many tables reached each size, by rows and by columns.
Methods. The methods by total time, with the rows at each call in size bands.
Busiest call sites. The lines of the program that spent the most time in Daf.

Costs and limits¶

When it is off, nothing is wrapped, and Daf runs at full speed.
Each counted call costs about 3 µs, and each call that makes a new table about 15 µs more. A call that Daf makes inside another one costs about 0.4 µs. So the times of cheap calls are inflated. Counts and sizes are exact.
Only calls to Daf methods are seen. A loop that reads daf.lol directly is not.
A child process that ends with os._exit(), as multiprocessing workers do, writes nothing at exit. Call daf_profile.dump() at the end of the worker instead.
Lambda and other hosts that freeze or kill the process are not handled yet.

API¶

start ¶

start(
    cls=None,
    stage="",
    data_dir=None,
    report_path=None,
    print_report=False,
)

Start profiling: wrap the public methods of Daf and begin counting.

Calling it again while profiling is on does nothing. The totals are kept until reset().

Parameters:

Name	Type	Description	Default
`cls`	`Type \| None`	The class to profile. Daf if not given.	`None`
`stage`	`str`	A name for this run, such as a stage of a pipeline. It fills the `stage` column of the tables, so the runs of several stages can be combined.	`''`
`data_dir`	`str \| None`	When the program ends, write the tables to `daffodil_profile_<stage>_<host>_<pid>.md` in this directory.	`None`
`report_path`	`str \| None`	When the program ends, write the report to this file. `{pid}` in the name is replaced with the process id.	`None`
`print_report`	`bool`	When the program ends, print the report to stderr.	`False`

stop ¶

stop()

Stop profiling and put the original methods back. The totals are kept.

tables ¶

tables()

Return the totals so far as Daf tables, keyed by 'info', 'tables', 'ops', 'methods' and 'sites'. Tables that are still alive are included, as if they were freed now.

Returns:

Type	Description
`Dict[str, Any]`	A dict of Daf tables. See the module notes for the columns.

dump ¶

dump(path=None)

Write the tables so far to one Markdown file, and return the path.

Parameters:

Name	Type	Description	Default
`path`	`str \| None`	The file. Without it, `daffodil_profile_<stage>_<host>_<pid>.md` in the current directory.	`None`

Returns:

Type	Description
`str`	The path written.

load ¶

load(path)

Read the tables that dump() wrote.

Parameters:

Name	Type	Description	Default
`path`	`str`	The file.	required

Returns:

Type	Description
`Dict[str, Any]`	A dict of Daf tables, with numbers converted back from text.

combine ¶

combine(runs, by_stage=True)

Add up the tables of several runs.

Parameters:

Name	Type	Description	Default
`runs`	`List[Dict[str, Any]]`	The tables of each run, as from `tables()` or `load()`.	required
`by_stage`	`bool`	If True, keep a row for each stage. If False, add the stages together and set `stage` to 'all'.	`True`

Returns:

Type	Description
`Dict[str, Any]`	A dict of Daf tables of the same form.

report ¶

report(dodaf=None, path=None, top=30)

Return a readable report as Markdown, and write it to a file if path is given.

Parameters:

Name	Type	Description	Default
`dodaf`	`Dict[str, Any] \| None`	The tables to report, as from `tables()`, `load()` or `combine()`. Without it, the totals of this process so far.	`None`
`path`	`str \| None`	Write the report to this file too. `{pid}` is replaced with the process id.	`None`
`top`	`int`	The most lines to show in each section.	`30`

Returns:

Type	Description
`str`	The report as Markdown text.

reset ¶

reset()

Clear all totals. Profiling stays on or off as it was.

is_active ¶

is_active()

True while profiling is on.