blob: 08ec12a75d521fb652e3c19d2dabec61a92ad716 [file] [log] [blame]
<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN">
<html>
<head>
<link rel="stylesheet" type="text/css" href="help.css">
<title>Understanding GEM Output</title>
</head>
<body>
<a name="top"></a>
<table cellspacing="5">
<tr>
<td>
<img src="images/trident_transparent.png">
</td>
<td>
<h1>Understanding GEM Console Output</h1>
</td>
</tr>
</table>
<hr>
<p><b>
This page is designed to provide detailed explanations (for those who are curious) of the output generated
in the Console View as well as the content of log files GEM generates.
</b></p>
<p>
There is no reason for the casual user to understand in any great detail, the output displayed in
the GEM Console View or the contents of the log files that are generated. GEM exists to provide an
intuitive, visual interface to debug and understand MPI applications and MPI runtime behavior and
to keep the user insulated from the details of trace files. The following views and tools are
provided by GEM to accomplish this:
</p>
<ul>
<li>
<a href="analyzerView.html">GEM Analyzer View</a>
</li>
<li>
<a href="analyzerView.html">GEM Browser View</a>
</li>
<li>
<a href="happensBeforeViewer.html">Happens Before Viewer</a>
</li>
</ul>
<h3>Sample Output From GEM Console View:</h3>
<ul>
<li>MPI Implementation&nbsp;&#8212;&nbsp;OpenMPI</li>
<li>UNIX Sockets enabled</li>
<li>FIB Enabled</li>
<li>Blocking Sends Enabled</li>
<li>3 Processes</li>
</ul>
<pre>
ISP - Insitu Partial Order
-----------------------------------------
Command: /home/alan/mpi/MPI_AnySrc/gem/MPI_AnySrc.gem
Number Procs: 3
Server: Local Socket
Blocking Sends: Enabled
FIB: Enabled
-----------------------------------------
Started Process: 22044
(0) is alive on formal
(2) is alive on formal
INTERLEAVING :1
(1) is alive on formal
-----------------------------------------
Transition list for 0
0 o=1 i=0 rank=0 Barrier /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:31 count=1{[0, 1][0, 2]} {}
1 o=4 i=1 rank=0 Irecv /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:37 src=-1 rtag=0 count=1{[0, 2]} {} Matched [1,1]
2 o=7 i=2 rank=0 Recv /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:39 src=1 rtag=0{} {}
Transition list for 1
0 o=2 i=0 rank=1 Barrier /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:31 count=1{[1, 1]} {}
1 o=5 i=1 rank=1 Send /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:50 dest=0 stag=0{[1, 2]} {} Matched [0,1]
2 o=8 i=2 rank=1 Recv /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:52 src=0 rtag=0{} {}
Transition list for 2
0 o=3 i=0 rank=2 Barrier /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:31 count=1{[2, 1]} {}
1 o=6 i=1 rank=2 Send /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:58 dest=0 stag=0{} {}
No matching MPI call found!
Detected a DEADLOCK in interleaving 1
-----------------------------------------
Started Process: 22048
(1) is alive on formal
(0) is alive on formal
(2) is alive on formal
INTERLEAVING :2
(1) Finished normally
(0) Finished normally
(2) Finished normally
-----------------------------------------
ISP detected deadlock!!!
Total Explored Interleavings: 2
Interleaving Exploration Mode: All Relevant Interleavings
-----------------------------------------
List of Irrelevant Barriers - If want to remove, remove a complete match set:
Match Set: 1
0: /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:31
1: /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:31
2: /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:31
Match Set: 2
0: /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:61
1: /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:61
2: /home/alan/mpi/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c:61
</pre>
<h2>Output is separated into segments by lines of dashes.</h2>
<br>
<ul>
<li>
The first segment is simply a title and will always display <b>ISP - Insitu Partial Order</b>.
ISP is the underlying verification engine used by GEM. The log files GEM interprets are
generated by ISP.
</li>
<li>
The second segment is fairly self explanatory, and provides the string used to specify the
name of the executable, the number of processes used, the server used, whether or not
<b>Blocking Sends</b> should be used, and whether or not <b>Functionally Irrelevant Barrier
(FIB) detection</b> is enabled.
</li>
<li>
The third segment is separated into interleavings. An interleaving (also called a schedule)
is a description of how the ISP Scheduler issued instruction to the MPI runtime. In this
segment, a brief explanation of how each process ran in each interleaving is given. In
the example above all three processes started and finished normally in the first interleaving,
but in the second interleaving a deadlock was found so each process had to abort.
</li>
<li>
The last segment describes how each MPI call was handled. Its
format is very similar to that of the log file except that the calls are grouped
by the process that issued it. To understand what it means
please read the following section on understanding the log file.
</li>
</ul>
<h2>Understanding the Log Files</h2>
<p>
Like <b>GEM Console</b> output, users are not expected to understand log files. The best way understand what
the log file contents represent is to run the <a href="happensBeforeViewer.html">Happens Before (HB) Viewer</a>
to graphically examine the information it displays. The log file consists of a single number (the first line)
that says how many processes were used to create the file, a list of every MPI call that program issued and
information about how that MPI call interacts with other MPI calls, unless a deadlock is found, at which point
progress halts for that particular interleaving. Here the log will have a line giving the interleave number
and the word <b>&#34;DEADLOCK&#34;</b>. It is possible to have more than one deadlock in your program. Each
deadlock will be contained in a particular interleaving (e.g. and interleaving can have at most one deadlock).
</p>
<pre>
3
1 0 0 1 1 Barrier 0_0:1:2: { 1 2 } { [ 1 1 ] [ 2 1 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 31
1 0 1 4 5 Irecv -1 0 0_0:1:2: { 2 } { [ 1 2 ] } Match: 1 1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 37
1 0 2 7 -1 Recv 1 0 0_0:1:2: { } { } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 39
1 1 0 2 2 Barrier 0_0:1:2: { 1 } { [ 0 1 ] [ 0 2 ] [ 2 1 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 31
1 1 1 5 4 Send 0 0 0_0:1:2: { 2 } { [ 0 2 ] } Match: 0 1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 50
1 1 2 8 -1 Recv 0 0 0_0:1:2: { } { } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 52
1 2 0 3 3 Barrier 0_0:1:2: { 1 } { [ 0 1 ] [ 0 2 ] [ 1 1 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 31
1 2 1 6 -1 Send 0 0 0_0:1:2: { } { } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 58
1 DEADLOCK
2 0 0 1 6 Barrier 0_0:1:2: { 1 2 } { [ 1 0 ] [ 2 0 ] [ 1 1 ] [ 0 0 ] [ 2 1 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 31
2 0 1 4 10 Irecv -1 0 0_0:1:2: { 2 5 } { [ 2 1 ] [ 2 2 ] } Match: 2 1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 37
2 0 2 7 12 Recv 1 0 0_0:1:2: { 3 } { [ 1 1 ] [ 1 2 ] [ 0 2 ] } Match: 1 1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 39
2 0 3 17 13 Send 1 0 0_0:1:2: { 4 } { [ 1 2 ] [ 1 3 ] [ 0 3 ] } Match: 1 2 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 41
2 0 4 19 16 Recv -1 0 0_0:1:2: { 5 } { [ 1 3 ] [ 1 4 ] } Match: 1 3 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 44
2 0 5 21 17 Wait { 6 } { } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 46
2 0 6 23 18 Barrier 0_0:1:2: { 7 } { [ 1 4 ] [ 2 2 ] [ 1 5 ] [ 0 6 ] [ 2 3 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 61
2 0 7 24 21 Finalize { } { [ 1 5 ] [ 2 3 ] [ 0 7 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 63
2 1 0 2 7 Barrier 0_0:1:2: { 1 } { [ 0 0 ] [ 2 0 ] [ 0 1 ] [ 0 2 ] [ 1 0 ] [ 2 1 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 31
2 1 1 5 11 Send 0 0 0_0:1:2: { 2 } { [ 0 2 ] [ 0 3 ] [ 1 1 ] } Match: 0 2 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 50
2 1 2 18 14 Recv 0 0 0_0:1:2: { 3 } { [ 0 3 ] [ 0 4 ] [ 1 2 ] } Match: 0 3 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 52
2 1 3 20 15 Send 0 0 0_0:1:2: { 4 } { [ 0 5 ] [ 1 3 ] } Match: 0 4 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 54
2 1 4 22 19 Barrier 0_0:1:2: { 5 } { [ 0 6 ] [ 2 2 ] [ 0 7 ] [ 1 4 ] [ 2 3 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 61
2 1 5 25 22 Finalize { } { [ 0 7 ] [ 2 3 ] [ 1 5 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 63
2 2 0 3 8 Barrier 0_0:1:2: { 1 } { [ 0 0 ] [ 1 0 ] [ 0 1 ] [ 0 2 ] [ 2 0 ] [ 1 1 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 31
2 2 1 6 9 Send 0 0 0_0:1:2: { 2 } { [ 0 2 ] [ 0 5 ] [ 2 1 ] } Match: 0 1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 58
2 2 2 16 20 Barrier 0_0:1:2: { 3 } { [ 0 6 ] [ 1 4 ] [ 0 7 ] [ 2 2 ] [ 1 5 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 61
2 2 3 26 23 Finalize { } { [ 0 7 ] [ 1 5 ] [ 2 3 ] } Match: -1 -1 File: 98 /home/alan/mpi/MPI_AnySrc/src/MPI_AnySrc.c 63
...
</pre>
<hr>
<p>
To understand the format, we will take a single line from the generated log file (line shown below) as an example, and explain each portion in detail:
</p>
<hr/>
<b><tt>
&nbsp;&nbsp;2 0 1 4 10 Irecv -1 0 0_0:1:2: { 2 5 } { [ 2 1 ] [ 2 2 ] } Match: 2 1 File: 98 /home/alan/MPI/MPI_AnySrcCanDeadlock/src/MPI_AnySrc.c 37
</tt>
</b>
<hr/>
<br/>
<table border="1" cellpadding="5">
<tr>
<th>Element</th>
<th>Title</th>
<th>Explanation</th>
</tr>
<tr>
<td><b>2</b></td>
<td style="width: 245px">Interleaving Number (1-based)</td>
<td>This MPI call was issued in the second interleaving.</td>
</tr>
<tr>
<td><b>0</b></td>
<td style="width: 245px">Process Number (0-based)</td>
<td>This call was issued by process zero.</td></tr>
<tr>
<td><b>1</b></td>
<td style="width: 245px">Process Call Index (0-based)</td>
<td>The order the envelope is sent by the process. This was second call issued by this process.</td>
</tr>
<tr>
<td><b>4</b></td>
<td style="width: 245px">Scheduler Receive Index (1-based)</td>
<td>This was the fourth call received by ISP&#39;s scheduler.</td>
</tr>
<tr>
<td><b>10</b></td>
<td style="width: 245px">Scheduler Issue Index (1-based)</td>
<td>The order in which MPI calls are issued to the MPI runtime. This was the tenth call performed by ISP.</td>
</tr>
<tr>
<td><b>Irecv</b></td>
<td style="width: 245px">MPI Call Name</td>
<td>This call was a MPI <b>Irecv</b> issued by process 0.</td>
</tr>
<tr>
<td><b>-1</b></td>
<td style="width: 245px">The Source Index</td>
<td>Source is -1 in this case because the MPI call itself is the source. This call was a MPI Irecv issued by process 0.</td>
</tr>
<tr>
<td><b>0</b></td>
<td style="width: 245px">MPI Message Tag</td>
<td>The MPI message tag here is <b>0</b>.</td>
</tr>
<tr>
<td><b>0_</b></td>
<td style="width: 245px">MPI Communicator</td>
<td>The MPI communicator this MPI call is a member of.</td>
</tr>
<tr>
<td><b>0:1:2</b></td>
<td>Processes in MPI communicator</td>
<td>Processes 0, 1, and 2 are in this particular MPI communicator <i>(MPI_COMM_WORLD in this example).</i></td>
</tr>
<tr>
<td><b>{2 5}</b></td>
<td style="width: 245px">Intra-Process MPI calls blocked</td>
<td>Blocks the MPI calls within this processes with <b>Process Call Index</b> of 2 and 5, Recv and Finalize in this case.</td>
</tr>
<tr>
<td><b>{ [ 2 1 ] [ 2 2 ] }</b></td>
<td style="width: 245px">Inter-Process MPIcalls blocked</td>
<td>
Blocks the indicated calls across processes (MPI calls found in other processes). Each are listed in pairs
(numbers between the [ ] form a pair), the first element of the pair is the process that made the MPI call,
the second number is the <b>Process Call Index</b>. For example, the first pair tells us that the call from
process 2 with a Process Call Index of 1 is blocked.
</td>
</tr>
<tr>
<td><b>Match: 2 1</b></td>
<td style="width: 245px">Match Rank &#38; Index</td>
<td>
For calls like Send and Recv and has -1 -1 for calls without matches (e.g. collectives). Here the <b>match rank</b> is
process <b>2</b> and the <b>match index</b> is <b>1</b>.
</td>
</tr>
<tr>
<td><b>File: 98</b></td>
<td style="width: 245px">Filename &#38; with length</td>
<td>The length of the file name length in this example is <b>98</b>.</td>
</tr>
<tr>
<td><b>/home/.../.../MPI_AnySrc.c</b></td>
<td style="width: 245px">The path and name of the source code file containing the MPI call</td>
<td>The fully qualified path to the source code file named <b>MPI_AnySrc.c</b>.</td>
</tr>
<tr>
<td><b>37</b></td>
<td style="width: 245px">Line number MPI call is found on</td>
<td>This MPI call is found on <b>line 37</b> of the source code file listed above.</td>
</tr>
</table>
<p>&nbsp;</p>
<p><a href="#top">Back to Top</a> | <a href="toc.html">Back to Table of Contents</a></p>
<p>&nbsp;</p>
<hr>
<center>
<p>
School of Computing * 50 S. Central Campus Dr. Rm. 3190 * Salt Lake City, UT
84112 * <A href="mailto:isp-dev@cs.utah.edu">isp-dev@cs.utah.edu</a><br>
<a href="http://www.eclipse.org/org/documents/epl-v10.php">License</a>
</p>
</center>
</body>
</html>