measuring job completion times

[Emery Hemingway]

Dear list,

Is there any experience with measuring and recording the time to
complete Tup jobs?

I've looked into the Sqlite database and don't see this sort of
information. I could of course write a wrapper that would
measure execution time and include in the macros for commands
that I want to analyze, and store information with something
like RRDTool.

Cheers,
Emery

[Mike Shal]

The mtime field in the node table stores the time to complete an individual tup job in milliseconds for command nodes. (This is an overloaded field -- for files, it stores the last known mtime of the file on disk, as would be given by stat). Command nodes have type == 1, and the 'name' field is the actual string given to the shell.

For example, you could get a list of job completion times with the following:

$ sqlite3 .tup/db 'select mtime, name from node where type=1'

Note the time includes tup's own processing time to update input/output links, so it will be slightly longer than the actual runtime if you ran it manually in a shell.

Just looking at the node table alone doesn't give you information on the project structure, though. So if you're looking at how well the project is parallelized and such you'd also need to cross-reference it with normal_link.

One thing that I think can be of interest in a project is how long a build takes when a particular file is changed. You can determine the impact of a file change by using 'tup graph'. Eg:

$ tup graph src/tup/updater.c
digraph G {
    node_1839 [label="tup\n1839" shape="oval" color="#000000" fontcolor="#000000" style=solid];
    node_1840 [label="tup-version.o\n1840" shape="oval" color="#000000" fontcolor="#000000" style=solid];
    node_1841 [label="LINK tup tup-version.o\n1841" shape="rectangle" color="#000000" fontcolor="#000000" style=solid];
    node_1840 -> node_1841 [dir=back,style="solid",arrowtail="empty"];
    node_1839 -> node_1841 [dir=back,style="solid",arrowtail="empty"];
    node_1784 [label="updater.o\n1784" shape="oval" color="#000000" fontcolor="#000000" style=solid];
    node_1841 -> node_1784 [dir=back,style="solid",arrowtail="empty"];
    node_1785 [label="CC updater.c\n1785" shape="rectangle" color="#000000" fontcolor="#000000" style=solid];
    node_1784 -> node_1785 [dir=back,style="solid",arrowtail="empty"];
    node_1243 [label="updater.c\n1243" shape="oval" color="#000000" fontcolor="#000000" style=solid];
    node_1785 -> node_1243 [dir=back,style="solid",arrowtail="empty"];
}

This builds out the subgraph in the same way an actual update would happen. It can show you how much of a project needs to be built given a set of inputs. Although the command runtime isn't included here, it should be easy to add in graph.c:dump_node().

Hope that helps,

-Mike