Discussion:
[PATCH 0/2 RFC] Add time stamp collection to operf and opreport
(too old to reply)
Carl E. Love
2015-10-02 16:39:38 UTC
Permalink
Raw Message
Will, Ramya, OProfile community:

As mentioned earlier this week, I have been working on a patch to add
the ability to collect the time stamp for each sample collected by
operf. I started work on this with Maynard Johnson. The first patch in
the series adds the command line option -T to operf and opreport to
handle the collection and processing of time stamps. The list of time
stamps for each sample is put into the XML file by opreport if the -T
option is specified and the time stamps were collected by operf.

Given the number of samples it is very hard to read the data and make
sense of it. So, the second patch is provided to process and graph the
time stamps. The patch consists of a shell and perl script. The perl
script reads up the data from the XML file, process it and generates a
command and data file for gnu plot. The shell script takes the name of
the XML input file, passes it to the perl script to generate the gnu
plot files. The shell script then calls gnuplot to generate the graph
as a post script file. Finally, the shell script will call xdg-open to
display the graph. These scripts are installed as executables along
with the operf and opreport binaries to make it easy for the user to
process the data. A couple of different formats for displaying the data
is provided as a place to start. If there are other formats that would
be of use, they can be added in the future.

I am posting the patches for community review and comment. Please let me
know what feed back you have on the patches. Hopefully, we can add this
functionality to OProfile. Thank you for your time.

Carl Love


------------------------------------------------------------------------------
Ramya Shivalingamurthy -X (rshivali - INFOSYS LIMITED at Cisco)
2015-10-03 12:19:10 UTC
Permalink
Raw Message
Hi Carl,

Sorry for the delay in reply. It's a long weekend over here in India.
Thank you very much for sharing the information. I will surely try out the patches and get back to you on the same.

Thanks and Regards,
Ramya

-----Original Message-----
From: Carl E. Love [mailto:***@us.ibm.com]
Sent: Friday, October 02, 2015 10:10 PM
To: oprofile-***@lists.sf.net; Ramya Shivalingamurthy -X (rshivali - INFOSYS LIMITED at Cisco); William Cohen
Cc: ***@us.ibm.com
Subject: [PATCH 0/2 RFC] Add time stamp collection to operf and opreport

Will, Ramya, OProfile community:

As mentioned earlier this week, I have been working on a patch to add the ability to collect the time stamp for each sample collected by operf. I started work on this with Maynard Johnson. The first patch in the series adds the command line option -T to operf and opreport to handle the collection and processing of time stamps. The list of time stamps for each sample is put into the XML file by opreport if the -T option is specified and the time stamps were collected by operf.

Given the number of samples it is very hard to read the data and make sense of it. So, the second patch is provided to process and graph the time stamps. The patch consists of a shell and perl script. The perl script reads up the data from the XML file, process it and generates a command and data file for gnu plot. The shell script takes the name of the XML input file, passes it to the perl script to generate the gnu plot files. The shell script then calls gnuplot to generate the graph as a post script file. Finally, the shell script will call xdg-open to display the graph. These scripts are installed as executables along with the operf and opreport binaries to make it easy for the user to process the data. A couple of different formats for displaying the data is provided as a place to start. If there are other formats that would be of use, they can be added in the future.

I am posting the patches for community review and comment. Please let me know what feed back you have on the patches. Hopefully, we can add this functionality to OProfile. Thank you for your time.

Carl Love

------------------------------------------------------------------------------
William Cohen
2015-10-07 14:47:18 UTC
Permalink
Raw Message
Post by Carl E. Love
As mentioned earlier this week, I have been working on a patch to add
the ability to collect the time stamp for each sample collected by
operf. I started work on this with Maynard Johnson. The first patch in
the series adds the command line option -T to operf and opreport to
handle the collection and processing of time stamps. The list of time
stamps for each sample is put into the XML file by opreport if the -T
option is specified and the time stamps were collected by operf.
Given the number of samples it is very hard to read the data and make
sense of it. So, the second patch is provided to process and graph the
time stamps. The patch consists of a shell and perl script. The perl
script reads up the data from the XML file, process it and generates a
command and data file for gnu plot. The shell script takes the name of
the XML input file, passes it to the perl script to generate the gnu
plot files. The shell script then calls gnuplot to generate the graph
as a post script file. Finally, the shell script will call xdg-open to
display the graph. These scripts are installed as executables along
with the operf and opreport binaries to make it easy for the user to
process the data. A couple of different formats for displaying the data
is provided as a place to start. If there are other formats that would
be of use, they can be added in the future.
I am posting the patches for community review and comment. Please let me
know what feed back you have on the patches. Hopefully, we can add this
functionality to OProfile. Thank you for your time.
Carl Love
Hi Carl,

Thanks for the patches. I starting to look at the patches. I will
try to have a more complete list of comments before the week is out.

In addition to the man pages there should be an example use in the
manual's doc/oprofile.xml.

It would be really nice if the plotting allowed multiple to be plotted
at the same time, for example cycles, instructions retired, and cache
misses. This would make it easier to spot possible cause of a problem.
Another thing to consider plotting is ratios of counts. There would
be a lot of utility in visualizing fluctuations in cycles per
instructions or cache misses per instruction.

The process_time_stamps.sh script left some files around in the
directory after running. It should clean up after itself. Also it
would be nicer if could feed the output of "opreport -T -X" directly
into the scripts rather than having to write them to a file.

Should the doc/opreport.xsd andlibpp/xml_utils.cpp schema_version be bumped
due to the additional timestamp element?

The following additional include is unneeded:

diff --git a/libdb/db_insert.c b/libdb/db_insert.c
index 6bbd71f..6a55d11 100644
--- a/libdb/db_insert.c
+++ b/libdb/db_insert.c
@@ -16,9 +16,16 @@
#include <errno.h>

#include "odb.h"
+#include "op_libiberty.h"

libop/op_config.h doesn't look like the right places for:

+#define EMPTY_TM_ARRAY ~0x0ULL
+#define VALID_TM_ARRAY_END 0xA5A5A5A55A5A5A5AULL


One of the things I did was do a coverity check with and without the
patches. There were some minor issues flagged by coverity:


Error: COMPILER_WARNING:
oprofile-1.1.0/libdb/db_manage.c: scope_hint: In function 'odb_write_timestamps'
oprofile-1.1.0/libdb/db_manage.c:432:2: warning: ignoring return value of 'write', declared with attribute warn_unused_result [-Wunused-result]
# write(data->fd, &tm_index, sizeof(tm_index));
# ^
# 430| * followed by the valid time stamp array marker.
# 431| */
# 432|-> write(data->fd, &tm_index, sizeof(tm_index));
# 433| tm_index = VALID_TM_ARRAY_END;
# 434| write(data->fd, &tm_index, sizeof(tm_index));

Error: COMPILER_WARNING:
oprofile-1.1.0/libdb/db_manage.c:434:2: warning: ignoring return value of 'write', declared with attribute warn_unused_result [-Wunused-result]
# write(data->fd, &tm_index, sizeof(tm_index));
# ^
# 432| write(data->fd, &tm_index, sizeof(tm_index));
# 433| tm_index = VALID_TM_ARRAY_END;
# 434|-> write(data->fd, &tm_index, sizeof(tm_index));
# 435|
# 436| return;

Error: STREAM_FORMAT_STATE:
oprofile-1.1.0/libpp/format_output.cpp:963: format_changed: "hex" changes the format state of "out" for category basefield.
# 961| found_timestamps = true;
# 962| i++;
# 963|-> out << "0x" << hex << *it_tm << " ";
# 964| }
# 965| break;

Error: INVALIDATE_ITERATOR (CWE-119):
oprofile-1.1.0/libpp/format_output.cpp:953: past_the_end: Function "end" creates an iterator.
oprofile-1.1.0/libpp/format_output.cpp:953: tested_end: "it" testing equal to "count_timestamp.end()".
oprofile-1.1.0/libpp/format_output.cpp:969: deref_iterator: Dereferencing iterator "it" though it is already past the end of its container.
# 967| }
# 968|
# 969|-> if (it->first != pclass) {
# 970| cerr << "ERROR: xml_formatter::output_time stamp_data() Failed "
# 971| << "to find the Time stamp vector for pclass = "

Error: INVALIDATE_ITERATOR (CWE-119):
oprofile-1.1.0/libpp/xml_utils.cpp:404: past_the_end: Function "end" creates an iterator.
oprofile-1.1.0/libpp/xml_utils.cpp:404: tested_end: "it" testing equal to "summary_tm->end()".
oprofile-1.1.0/libpp/xml_utils.cpp:411: deref_iterator: Dereferencing iterator "it" though it is already past the end of its container.
# 409| }
# 410|
# 411|-> if (it->first != pclass) {
# 412| cerr << "ERROR: xml_utils::output_tm_data failed to find the Time stamp vector for pclass = " << pclass << endl;
# 413| }

Error: STREAM_FORMAT_STATE:
oprofile-1.1.0/libpp/xml_utils.cpp:419: format_changed: "hex" changes the format state of "out" for category basefield.
# 417| for(; it_tm != tm_vector.end(); it_tm++) {
# 418| i++;
# 419|-> out << "0x" << hex << *it_tm << " ";
# 420| rtn = true;
# 421| }


-Will
Carl E. Love
2015-10-22 23:22:53 UTC
Permalink
Raw Message
Post by William Cohen
Thanks for the patches. I starting to look at the patches. I will
try to have a more complete list of comments before the week is out.
In addition to the man pages there should be an example use in the
manual's doc/oprofile.xml.
It would be really nice if the plotting allowed multiple to be plotted
at the same time, for example cycles, instructions retired, and cache
misses. This would make it easier to spot possible cause of a problem.
Another thing to consider plotting is ratios of counts. There would
be a lot of utility in visualizing fluctuations in cycles per
instructions or cache misses per instruction.
The process_time_stamps.sh script left some files around in the
directory after running. It should clean up after itself. Also it
would be nicer if could feed the output of "opreport -T -X" directly
into the scripts rather than having to write them to a file.
Should the doc/opreport.xsd andlibpp/xml_utils.cpp schema_version be bumped
due to the additional timestamp element?
Will:

I have reworked the two patches to add the desired functionality and
documentation you mentioned above. I bumped the versions in
doc/opreport.xsd and libpp/xml_utils.cpp from 1.0 to 1.1. I also took
care of the coverity issues you listed.

I am sending the updated patches for review. Thanks for the time and
help reviewing the patches.

Carl Love


------------------------------------------------------------------------------
Carl E. Love
2015-10-22 23:22:56 UTC
Permalink
Raw Message
Updated version 2, Add time stamp collection to operf, report time stamps in XML output

This patch adds a command line option to operf to collect timestamp data
for each sample. The time stamps are printed to the various oprofile data
files.

The opreport command also has a command line option added. This option
will print the time stamp data in the XML output file for each sample. If
the -d option is used the time stamps will also be printed for each
instruct in the detailed XML output file.

The initial version of the patch had some issues supporting the printing
of the time stamps on multiple events. Thes have been fixed in this
version.

Fixed an issue where there were duplicate entries for the-T option. The
second one was removed. The variable that it set was not used.

Add support to opreport to call graphing scripts

Signed-off-by: Carl Love <***@us.ibm.com>
---
doc/operf.1.in | 8 +-
doc/opreport.1.in | 57 +++++++-
doc/opreport.xsd | 16 ++-
doc/oprofile.xml | 7 +
libabi/opimport.cpp | 2 +-
libabi/tests/abi_test.cpp | 2 +-
libdb/db_insert.c | 28 +++-
libdb/db_manage.c | 306 +++++++++++++++++++++++++++++++++++++-
libdb/odb.h | 29 +++-
libop/op_config.h | 2 +
libop/op_xml_out.c | 1 +
libop/op_xml_out.h | 1 +
libop/tm_array.h | 17 ++
libperf_events/operf_counter.cpp | 18 ++-
libperf_events/operf_counter.h | 7 +-
libperf_events/operf_sfile.cpp | 8 +-
libperf_events/operf_sfile.h | 1 +
libperf_events/operf_utils.cpp | 9 +
libpp/callgraph_container.cpp | 3 +-
libpp/format_output.cpp | 84 ++++++++++-
libpp/format_output.h | 5 +
libpp/op_header.h | 2 +
libpp/profile.cpp | 57 ++++++--
libpp/profile.h | 32 +++-
libpp/profile_container.cpp | 37 ++++-
libpp/profile_container.h | 8 +-
libpp/symbol.cpp | 9 +
libpp/symbol.h | 8 +
libpp/symbol_container.cpp | 8 +
libpp/xml_utils.cpp | 66 ++++++++-
libpp/xml_utils.h | 3 +
pe_profiling/operf.cpp | 10 +-
pp/opgprof.cpp | 8 +-
pp/opreport.cpp | 28 +++-
pp/opreport_options.cpp | 144 ++++++++++++++++++
pp/opreport_options.h | 4 +
36 files changed, 963 insertions(+), 72 deletions(-)
create mode 100644 libop/tm_array.h

diff --git a/doc/operf.1.in b/doc/operf.1.in
index efaceb9..a9129de 100644
--- a/doc/operf.1.in
+++ b/doc/operf.1.in
@@ -10,7 +10,7 @@ operf \- Performance profiler tool for Linux
[
.I options
]
-[ --system-wide | --pid <pid> | [ command [ args ] ] ]
+[ --system-wide | --pid <pid> | -T | [ command [ args ] ] ]

.SH DESCRIPTION
Operf is the profiler tool provided with OProfile. Operf
@@ -248,6 +248,10 @@ A comma-separated list of debugging control values, used to increase the verbosi
Valid values are: debug, record, convert, misc, sfile, arcs, or the special value, 'all'.
.br
.TP
+.BI "-T "
+Collect the time stamp for each sample.
+.br
+.TP
.BI "--version / -v"
Show operf version.
.br
@@ -267,4 +271,4 @@ $ operf make
This man page is current for @PACKAGE@-@***@.

.SH SEE ALSO
-opreport(1), opannotate(1).
+opreport(1), opannotate(1), plot_time_stamps(1).
diff --git a/doc/opreport.1.in b/doc/opreport.1.in
index 0627aa9..afd4a45 100644
--- a/doc/opreport.1.in
+++ b/doc/opreport.1.in
@@ -134,16 +134,63 @@ of total samples. For profiles using multiple events, if the threshold is reache
for any event, then all sample data for the symbol is shown.
.br
.TP
+.BI "--xml / -X"
+Generate XML output.
+.TP
+.BI "--enable_timestamp / -T "
+Print time stamp for each sample. The --xml or -X option must also be
+specified as the data is only available in the XML output format.
+.br
+.TP
+.BI "--plot_ps / -P "
+Generates a postscript plot of the time stamps. The --xml or -X option must
+also be specified as the data is only available in the XML output format.
+.br
+.TP
+.BI "--ts_plot_name / -F [file]"
+The postscript plot of the time stamps is written to the specified file. The
+--xml or -X and -P or --plot_ps options must be specified to use this option.
+.br
+.TP
+.BI "--line_graph / -L "
+Generate a line graph of the time stamps, this is the default. The
+--xml or -X and -P or --plot_ps options must be specified to use this option.
+.br
+.TP
+.BI "--bar_graph / -B "
+Generate a bar graph of the time stamps. The -xml or -X and -P or
+--plot_ps options must be specified to use this option.
+.br
+.TP
+.BI "--ts_max_sym / -M [N]"
+Plot the symbols whose time stamp counts are in the top N of the symbols. The
+-xml or -X and -P or --plot_ps options must be specified to use this option.
+.br
+.TP
+.BI "--ts_max_bins / -b [N]"
+The time between the start and end times is divided into N bins. The count
+of time stamps that fall in each bin is plotted. The -xml or -X and -P or
+--plot_ps options must be specified to use this option.
+.br
+.TP
+.BI "--ts_start_time / -S [N]"
+Set the number of ns from the beginning of the data set to start the plot at.
+This can be used with the -E option to zoom in on a time range of interest.
+The -xml or -X and -P or --plot_ps options must be specified to use this option.
+.br
+.TP
+.BI "--ts_end_time / -E [N]"
+Set the number of ns from the beginning of the data set to stop the plot at.
+This can be used with the -S option to zoom in on a time range of interest.
+The -xml or -X and -P or --plot_ps options must be specified to use this option
+.br
+.TP
.BI "--verbose / -V [options]"
Give verbose debugging output.
.br
.TP
.BI "--version / -v"
Show version.
-.br
-.TP
-.BI "--xml / -X"
-Generate XML output.

.SH ENVIRONMENT
No special environment variables are recognized by opreport.
@@ -159,4 +206,4 @@ This man page is current for @PACKAGE@-@***@.

.SH SEE ALSO
.BR @OP_DOCDIR@,
-.BR oprofile(1)
+.BR oprofile(1), plot_time_stamps(1).
diff --git a/doc/opreport.xsd b/doc/opreport.xsd
index 28e3128..8f16f5d 100644
--- a/doc/opreport.xsd
+++ b/doc/opreport.xsd
@@ -1,4 +1,4 @@
-<?xml version="1.0" encoding="UTF-8"?>
+<?xml version="1.1" encoding="UTF-8"?>
<xs:schema
xmlns:xs="http://www.w3.org/2001/XMLSchema">
<xs:element name="profile">
@@ -107,6 +107,18 @@
</xs:complexType>
</xs:element>

+ <xs:element name="timestamp">
+ <xs:complexType>
+ <xs:simpleContent>
+ <xs:extension base="xs:nonNegativeInteger">
+ <!-- if no separation by cpu and only a single non masked event
+ the class attribute is unnecessary -->
+ <xs:attribute name="class" type="xs:string" use="optional"/>
+ </xs:extension>
+ </xs:simpleContent>
+ </xs:complexType>
+ </xs:element>
+
<xs:element name="process">
<xs:complexType>
<xs:sequence>
@@ -207,6 +219,7 @@
<xs:element minOccurs="0" maxOccurs="1" ref="callers"/>
<xs:element minOccurs="0" maxOccurs="1" ref="callees"/>
<xs:element minOccurs="0" maxOccurs="unbounded" ref="count"/>
+ <xs:element minOccurs="0" maxOccurs="unbounded" ref="timestamp" use="optional"/>
</xs:sequence>
<!-- idref is an index into symboltable table-->
<xs:attribute name="idref" type="xs:nonNegativeInteger" use="required"/>
@@ -246,6 +259,7 @@
<xs:complexType>
<xs:sequence>
<xs:element minOccurs="1" maxOccurs="unbounded" ref="count"/>
+ <xs:element minOccurs="0" maxOccurs="unbounded" ref="timestamp" use="optional"/>
</xs:sequence>
<!-- line only occurs when debug-info option used -->
<xs:attribute name="line" type="xs:nonNegativeInteger" use="optional"/>
diff --git a/doc/oprofile.xml b/doc/oprofile.xml
index 325ef6f..98866c4 100644
--- a/doc/oprofile.xml
+++ b/doc/oprofile.xml
@@ -1027,6 +1027,13 @@ Differential profile of an archived binary with the current session :
# opreport -l /bin/bash { archive:./orig } { }
</screen>

+<para>
+Generate plot of the timestamps collected by operf.
+</para>
+<screen>
+# opreport -X -T -P
+</screen>
+
</sect2> <!-- profile spec examples -->

<sect2 id="profile-spec-details">
diff --git a/libabi/opimport.cpp b/libabi/opimport.cpp
index c2234fe..3d658a7 100644
--- a/libabi/opimport.cpp
+++ b/libabi/opimport.cpp
@@ -233,7 +233,7 @@ int main(int argc, char const ** argv)
cerr << "caught abi exception: " << e.desc << endl;
}

- odb_close(&dest);
+ odb_close(&dest, /* write_timestamps*/ false);

assert(munmap(in, statb.st_size) == 0);
}
diff --git a/libabi/tests/abi_test.cpp b/libabi/tests/abi_test.cpp
index b129a28..506b345 100644
--- a/libabi/tests/abi_test.cpp
+++ b/libabi/tests/abi_test.cpp
@@ -91,6 +91,6 @@ int main(int argc, char const ** argv)
exit(EXIT_FAILURE);
}
}
- odb_close(&dest);
+ odb_close(&dest, /* write_timestamps*/ false);
}
}
diff --git a/libdb/db_insert.c b/libdb/db_insert.c
index 6bbd71f..7b33b40 100644
--- a/libdb/db_insert.c
+++ b/libdb/db_insert.c
@@ -17,8 +17,13 @@

#include "odb.h"

+static void insert_timestamp(odb_node_t *node, uint64_t timestamp) {
+ /* add the time stamp to the head of the list */
+ add_data(&node->tm_list, &timestamp, sizeof(uint64_t));
+}

-static inline int add_node(odb_data_t * data, odb_key_t key, odb_value_t value)
+static inline int add_node(odb_data_t * data, odb_key_t key, odb_value_t value,
+ uint64_t timestamp)
{
odb_index_t new_node;
odb_node_t * node;
@@ -38,6 +43,11 @@ static inline int add_node(odb_data_t * data, odb_key_t key, odb_value_t value)
node = &data->node_base[new_node];
node->value = value;
node->key = key;
+ init_buffer(&node->tm_list);
+
+ if (timestamp) {
+ insert_timestamp(node, timestamp);
+ }

index = odb_do_hash(data, key);
node->next = data->hash_base[index];
@@ -49,14 +59,15 @@ static inline int add_node(odb_data_t * data, odb_key_t key, odb_value_t value)
return 0;
}

-int odb_update_node(odb_t * odb, odb_key_t key)
+int odb_update_node(odb_t * odb, odb_key_t key, uint64_t timestamp)
{
- return odb_update_node_with_offset(odb, key, 1);
+ return odb_update_node_with_offset(odb, key, 1, timestamp);
}

int odb_update_node_with_offset(odb_t * odb,
odb_key_t key,
- unsigned long int offset)
+ unsigned long int offset,
+ uint64_t timestamp)
{
odb_index_t index;
odb_node_t * node;
@@ -69,6 +80,9 @@ int odb_update_node_with_offset(odb_t * odb,
if (node->key == key) {
if (node->value + offset != 0) {
node->value += offset;
+ if (timestamp) {
+ insert_timestamp(node, timestamp);
+ }
} else {
/* post profile tools must handle overflow */
/* FIXME: the tricky way will be just to add
@@ -98,12 +112,12 @@ int odb_update_node_with_offset(odb_t * odb,

index = node->next;
}
-
- return add_node(data, key, offset);
+ /* no existing node, add one */
+ return add_node(data, key, offset, timestamp);
}


int odb_add_node(odb_t * odb, odb_key_t key, odb_value_t value)
{
- return add_node(odb->data, key, value);
+ return add_node(odb->data, key, value, /* time stamp */ 0);
}
diff --git a/libdb/db_manage.c b/libdb/db_manage.c
index 668e994..31769c2 100644
--- a/libdb/db_manage.c
+++ b/libdb/db_manage.c
@@ -23,6 +23,8 @@
#include "odb.h"
#include "op_string.h"
#include "op_libiberty.h"
+#include "op_config.h"
+#include "tm_array.h"


static __inline odb_descr_t * odb_to_descr(odb_data_t * data)
@@ -59,6 +61,43 @@ static unsigned int tables_size(odb_data_t const * data, odb_node_nr_t node_nr)
return size;
}

+/**
+ * Add space for time stamps after the end of the hash table.
+ * Call this once after all the samples have been collected and the hash table
+ * is complete. Note that we are not modifying the hash table itself, and
+ * we will not rebuild the table after this call is made.
+ */
+int odb_grow_hashtable_for_timestamps(odb_data_t * data,
+ unsigned int additional_bytes)
+{
+ unsigned int old_file_size;
+ unsigned int new_file_size;
+ void * new_map;
+
+ old_file_size = tables_size(data, data->descr->size);
+ new_file_size = old_file_size + additional_bytes;
+
+ if (ftruncate(data->fd, new_file_size)) {
+ fprintf(stderr, "ERROR odb_grow_hashtable_for_time stamps, ftruncate failed.\n");
+ return 1;
+ }
+
+ new_map = mremap(data->base_memory,
+ old_file_size, new_file_size, MREMAP_MAYMOVE);
+
+ if (new_map == MAP_FAILED) {
+ fprintf(stderr, "ERROR odb_grow_hashtable_for_time stamps, mremap failed\n");
+ return 1;
+ }
+ data->base_memory = new_map;
+ data->descr = odb_to_descr(data);
+ data->node_base = odb_to_node_base(data);
+ data->hash_base = odb_to_hash_base(data);
+
+ /* Note: do not rebuild the hash table. We are not modifying it */
+
+ return 0;
+}

int odb_grow_hashtable(odb_data_t * data)
{
@@ -113,6 +152,15 @@ int odb_grow_hashtable(odb_data_t * data)
data->hash_base[index] = pos;
}

+ /* Initialize the values. Entries are updated later if time stamps
+ * are enabled.
+ */
+ for (pos = data->descr->current_size; pos < data->descr->size; ++pos) {
+ data->node_base[pos].tm_list.max_size = 0;
+ data->node_base[pos].tm_list.size = 0;
+ data->node_base[pos].tm_list.p = NULL;
+ }
+
return 0;
}

@@ -158,6 +206,245 @@ find_samples_data(size_t hash, char const * filename)
return NULL;
}

+/* Read the time stamp data from data->filename. Return the number of
+ * time stamps for the data file. If no time stamps were collected,
+ * return zero.
+*/
+static int read_timestamp(odb_data_t * data) {
+ int fd = data->fd;
+ char *file_name = data->filename;
+ uint64_t *timestamp_array;
+ int error = -1;
+
+ uint64_t time_stamp, num_time_stamps, i;
+
+ int n;
+ int offset, file_size;
+ int timestamp_size = sizeof(time_stamp);
+
+ file_size = lseek(fd, (off_t) 0L, SEEK_END);
+ if (file_size <= 0) {
+ fprintf(stderr, "ERROR, setting fd to end of file %s.\n",
+ file_name);
+ error = file_size;
+ goto err;
+ }
+
+ /* Back up to right before the number of time stamps and the
+ * valid time stamp array marker.
+ */
+ offset = file_size - 2 * timestamp_size;
+ n = lseek(fd, ((off_t) offset), SEEK_SET);
+
+ if (n < 0) {
+ fprintf(stderr, "ERROR, setting fd to read the number of time stamps "
+ "in file %s.\n", file_name);
+ error = n;
+ goto err;
+ }
+
+ if ((n = read(fd, &num_time_stamps, sizeof(num_time_stamps)))
+ != sizeof(num_time_stamps)) {
+ fprintf(stderr, "ERROR, failed to read enough bytes for the "
+ "number of time stamps\n");
+ error = -1;
+ goto err;
+ }
+
+ /* read the end of the time stamp marker */
+ if ((n = read(fd, &time_stamp, sizeof(time_stamp)))
+ != sizeof(time_stamp)) {
+ fprintf(stderr, "ERROR, failed to read enough bytes for the "
+ "number of time stamps\n");
+ error = -1;
+ goto err;
+ }
+
+ if (time_stamp != VALID_TM_ARRAY_END) {
+ /* We have to abort since the file information is incomplete.*/
+
+ fprintf(stderr, "\nERROR, operf did not complete writing data correctly to file %s.\n",
+ file_name);
+ fprintf(stderr,
+ "One of the operf processes died unexpectedly.\n\n");
+ error = -2;
+ goto err;
+ }
+
+ if (num_time_stamps == 0)
+ timestamp_array = xmalloc(1*sizeof(uint64_t));
+ else
+ timestamp_array = xmalloc(num_time_stamps*sizeof(uint64_t));
+
+ if (timestamp_array == NULL) {
+ fprintf(stderr, "ERROR, failed to allocate space for the time stamps "
+ "stored in file %s\n", file_name);
+ error = ENOMEM;
+ goto err;
+ }
+
+ /* Set the first element to max value. Will be overwritten
+ * if the file had time stamps.
+ */
+ timestamp_array[0] = EMPTY_TM_ARRAY;
+
+ /* Backup to the beginning of the time stamp array. The layout of the
+ * data in the file is:
+ * [hashtable]
+ * [time stamp data]
+ * [number of time stamps]
+ * [time stamp array marker]
+ */
+ offset = file_size - timestamp_size*(num_time_stamps + 2);
+
+ n = lseek(fd, ((off_t) offset), SEEK_SET);
+ if (n < 0) {
+ fprintf(stderr, "ERROR, setting fd to read the time stamps in "
+ "file %s.\n", file_name);
+ error = n;
+ goto err;
+ }
+
+ for (i = 0; i < num_time_stamps; i++) {
+ if ((n = read(fd, &time_stamp, sizeof(time_stamp)))
+ != sizeof(num_time_stamps)) {
+ fprintf(stderr, "ERROR, failed to read enough bytes for "
+ "time stamp number %ld in file %s\n", i, file_name);
+ error = n;
+ goto err;
+ }
+ timestamp_array[i] = time_stamp;
+ }
+
+ /* Calculate the number of bytes used to store the time stamp data and
+ * number of time stamps and valid marker stored at the end of the file.
+ */
+ data->timestamp_array = timestamp_array;
+ return ((num_time_stamps+2)*timestamp_size);
+ err:
+ return error;
+}
+
+void odb_write_timestamps(odb_t * odb, int data_collector_call) {
+ /* The output file contains the list of nodes (odb_node_t) that
+ * contain the key (instruction pointer value), the samples count,
+ * and a pointer to the list of time stamps. The time stamps for
+ * each key will all be stored at the end of the data file in the
+ * array tm_array. Each node will have the index tm_index set
+ * to the first time stamp for this node in the tm_array.
+ */
+
+ odb_data_t * data;
+ uint64_t index, tm_index = 0, num_timestamps;
+ odb_node_nr_t pos;
+ uint64_t value;
+ void *ptr;
+ int rc = 0;
+ int file_size;
+
+ data = odb->data;
+
+ /* This function is called by the operf data collector, the post
+ * processing tools, and some test functions. Only if we are called
+ * by the operf data collector will we have time stamps to print.
+ * We must print the number of time stamps as the last thing in
+ * the file. This value will be read by the post processor so
+ * the expected size of the file with the time stamps can be
+ * calculated.
+ */
+
+ if (data_collector_call == 0)
+ return;
+
+ /* Determine the total number of time stamps to be written to
+ * the end of the file. Need space for total number of time
+ * stamps and marker.
+ */
+ num_timestamps = 2;
+
+ for (pos = 1; pos < data->descr->size * BUCKET_FACTOR; pos++) {
+ num_timestamps +=
+ data->node_base[pos].tm_list.size/sizeof(uint64_t);
+ }
+
+ /* Grow the hashtable so we can add the time stamps to
+ * the end of the table.
+ */
+ if (odb_grow_hashtable_for_timestamps(data,
+ (num_timestamps
+ * sizeof(uint64_t)))){
+ fprintf(stderr,
+ "ERROR, failed to resize file to write time stamps.\n");
+ return;
+ }
+
+ file_size = lseek(data->fd, 0, SEEK_END);
+
+ /* Make sure the file pointer is pointing at the end
+ * of the file.
+ */
+ rc = lseek(data->fd, file_size
+ - num_timestamps*sizeof(uint64_t), SEEK_SET);
+
+ if (rc == (off_t)(-1)) {
+ fprintf(stderr, "ERROR, failed to reposition file descriptor to write time stamps.\n");
+ return;
+ }
+
+ for (pos = 1; pos < data->descr->size * BUCKET_FACTOR; pos++) {
+ data->node_base[pos].tm_index = tm_index;
+ ptr = data->node_base[pos].tm_list.p;
+
+ num_timestamps = data->node_base[pos].tm_list.size/sizeof(uint64_t);
+
+ for (index = 0; index < num_timestamps; index++) {
+ if( memcpy(&value, ptr, sizeof(uint64_t)) == NULL) {
+ fprintf(stderr, "ERROR, copy time stamps failed.\n");
+ return;
+ }
+ rc = write(data->fd, &value, sizeof(value));
+
+ if (rc < 0) {
+ fprintf(stderr, "ERROR, write time stamps failed.\n");
+ return;
+ }
+ ptr += sizeof(uint64_t);
+ tm_index++;
+ }
+
+ if ((num_timestamps > 0) &&
+ (data->node_base[pos].value !=
+ (data->node_base[pos].tm_list.size/sizeof(uint64_t)))) {
+
+ fprintf(stderr, "WARNING: missing time stamps "
+ "for Key = 0x%lx, time stamp count "
+ " %lu, sample %lu, file %s\n",
+ (unsigned long int) data->node_base[pos].key,
+ data->node_base[pos].tm_list.size/sizeof(uint64_t),
+ (unsigned long int) data->node_base[pos].value,
+ data->filename);
+ }
+ free(data->node_base[pos].tm_list.p); // Done with buffer
+ }
+
+ /* Write the number of time stamps at the end of the file
+ * followed by the valid time stamp array marker.
+ */
+ rc = write(data->fd, &tm_index, sizeof(tm_index));
+ if (rc < 0) {
+ fprintf(stderr, "ERROR, writing the number of time stamps.\n");
+ return;
+ }
+
+ tm_index = VALID_TM_ARRAY_END;
+ rc = write(data->fd, &tm_index, sizeof(tm_index));
+ if (rc < 0) {
+ fprintf(stderr, "ERROR, writing the VALID_TM_ARRAY_END marker.\n");
+ return;
+ }
+
+ return;
+}

int odb_open(odb_t * odb, char const * filename, enum odb_rw rw,
size_t sizeof_header)
@@ -167,6 +454,7 @@ int odb_open(odb_t * odb, char const * filename, enum odb_rw rw,
odb_data_t * data;
size_t hash;
int err = 0;
+ int timestamp_size;

int flags = (rw == ODB_RDWR) ? (O_CREAT | O_RDWR) : O_RDONLY;
int mmflags = (rw == ODB_RDWR) ? (PROT_READ | PROT_WRITE) : PROT_READ;
@@ -213,9 +501,18 @@ int odb_open(odb_t * odb, char const * filename, enum odb_rw rw,
err = errno;
goto fail;
}
+ timestamp_size = 0;
} else {
+ /* Time stamp data file exixts */
+ data->timestamp_array = NULL;
+ timestamp_size = read_timestamp(data);
+ if (timestamp_size < 0) {
+ err = EIO; /* The data file is bad. */
+ goto fail;
+ }
/* Calculate nr node allowing a sanity check later */
- nr_node = (stat_buf.st_size - data->offset_node) /
+ nr_node = (stat_buf.st_size - timestamp_size
+ - data->offset_node) /
((sizeof(odb_index_t) * BUCKET_FACTOR) + sizeof(odb_node_t));
}

@@ -260,14 +557,17 @@ fail:
}


-void odb_close(odb_t * odb)
+void odb_close(odb_t * odb, int data_collector_call)
{
odb_data_t * data = odb->data;
+ size_t size;

if (data) {
data->ref_count--;
if (data->ref_count == 0) {
- size_t size = tables_size(data, data->descr->size);
+ odb_write_timestamps(odb, data_collector_call);
+
+ size = tables_size(data, data->descr->size);
list_del(&data->list);
munmap(data->base_memory, size);
if (data->fd >= 0)
diff --git a/libdb/odb.h b/libdb/odb.h
index 9ad1da2..52b258a 100644
--- a/libdb/odb.h
+++ b/libdb/odb.h
@@ -17,6 +17,7 @@
#include <stdint.h>

#include "op_list.h"
+#include "../libutil/op_growable_buffer.h"

/** the type of key. 64-bit because CG needs 32-bit pair {from,to} */
typedef uint64_t odb_key_t;
@@ -43,6 +44,8 @@ typedef struct {
odb_key_t key; /**< eip */
odb_value_t value; /**< samples count */
odb_index_t next; /**< next entry for this bucket */
+ struct growable_buffer tm_list; /* list of time stamps */
+ unsigned long int tm_index; /* Index into tm list */
} odb_node_t;

/** the minimal information which must be stored in the file to reload
@@ -84,6 +87,7 @@ typedef struct odb_data {
char * filename; /**< full path name of sample file */
int ref_count; /**< reference count */
struct list_head list; /**< hash bucket list */
+ uint64_t *timestamp_array; /* All time stamps for the file */
} odb_data_t;

typedef struct {
@@ -124,7 +128,7 @@ int odb_open(odb_t * odb, char const * filename,
enum odb_rw rw, size_t sizeof_header);

/** Close the given ODB file */
-void odb_close(odb_t * odb);
+void odb_close(odb_t * odb, int write_timestamp);

/** return the number of times this sample file is open */
int odb_open_count(odb_t const * odb);
@@ -150,8 +154,15 @@ void odb_sync(odb_t const * odb);
* after cleanup some program resource.
*/
int odb_grow_hashtable(odb_data_t * data);
+
+/* This call adds space to the end of the table to add the time stamp data.
+ * This can only be called once, as odb_grow_hashtable() does not know how to
+ * handle moving the time stamps at the end of the file.
+ */
+int odb_grow_hashtable_for_timestamp(odb_data_t * data, unsigned int size);
+
/**
- * commit a previously successfull node reservation. This can't fail.
+ * commit a previously successful node reservation. This can't fail.
*/
static __inline void odb_commit_reservation(odb_data_t * data)
{
@@ -178,13 +189,14 @@ void odb_hash_free_stat(odb_hash_stat_t * stats);
*
* returns EXIT_SUCCESS on success, EXIT_FAILURE on failure
*/
-int odb_update_node(odb_t * odb, odb_key_t key);
+int odb_update_node(odb_t * odb, odb_key_t key, uint64_t timestamp);

/**
* odb_update_node_with_offset
* @param odb the data base object to setup
* @param key the hash key
* @param offset the offset to be added
+ * @param timestamp, (user optional) time stamp of sample
*
* update info at key by adding the specified offset to its associated value,
* if the key does not exist a new node is created and the value associated
@@ -193,8 +205,9 @@ int odb_update_node(odb_t * odb, odb_key_t key);
* returns EXIT_SUCCESS on success, EXIT_FAILURE on failure
*/
int odb_update_node_with_offset(odb_t * odb,
- odb_key_t key,
- unsigned long int offset);
+ odb_key_t key,
+ unsigned long int offset,
+ uint64_t timestamp);

/** Add a new node w/o regarding if a node with the same key already exists
*
@@ -232,6 +245,12 @@ odb_do_hash(odb_data_t const * data, odb_key_t value)
return ((temp << 0) ^ (temp >> 8)) & data->hash_mask;
}

+#ifdef DEBUG_TM
+extern void print_tmstmp_range(odb_node_t tm_list_node, uint64_t key,
+ uint64_t *timestmp_array);
+extern void print_tmstmp(uint64_t *timestmp_array, uint64_t max);
+#endif
+
#ifdef __cplusplus
}
#endif
diff --git a/libop/op_config.h b/libop/op_config.h
index 8fe70c8..f3bed35 100644
--- a/libop/op_config.h
+++ b/libop/op_config.h
@@ -72,4 +72,6 @@ extern char op_samples_current_dir[];
}
#endif

+#define EMPTY_TM_ARRAY ~0x0ULL
+#define VALID_TM_ARRAY_END 0xA5A5A5A55A5A5A5AULL
#endif /* OP_CONFIG_H */
diff --git a/libop/op_xml_out.c b/libop/op_xml_out.c
index 63ee41c..4fc3233 100644
--- a/libop/op_xml_out.c
+++ b/libop/op_xml_out.c
@@ -61,6 +61,7 @@ char const * xml_tag_map[] = {
"summarydata",
"sampledata",
"count",
+ "timestamp",
"detailtable",
"symboldetails",
"detaildata",
diff --git a/libop/op_xml_out.h b/libop/op_xml_out.h
index a829f66..cd8c0dc 100644
--- a/libop/op_xml_out.h
+++ b/libop/op_xml_out.h
@@ -39,6 +39,7 @@ typedef enum {
SOURCE_FILE, SOURCE_LINE, CODE_LENGTH,
SUMMARY, SAMPLE,
COUNT,
+ TIMESTAMP,
DETAIL_TABLE, SYMBOL_DETAILS, DETAIL_DATA, VMA,
BYTES_TABLE, BYTES,
HELP_EVENTS,
diff --git a/libop/tm_array.h b/libop/tm_array.h
new file mode 100644
index 0000000..c259856
--- /dev/null
+++ b/libop/tm_array.h
@@ -0,0 +1,17 @@
+/**
+ * @file tm_array.h
+ *
+ * @remark Copyright 2015 OProfile authors
+ * @remark Read the file COPYING
+ *
+ * @author Carl Love <***@us.ibm.com>
+ * @Modifications
+ */
+
+#ifndef TM_ARRAY_H
+#define TM_ARRAY_H
+
+#define EMPTY_TM_ARRAY ~0x0ULL
+#define VALID_TM_ARRAY_END 0xA5A5A5A55A5A5A5AULL
+
+#endif /* TM_ARRAY_H */
diff --git a/libperf_events/operf_counter.cpp b/libperf_events/operf_counter.cpp
index 023f210..acd361a 100644
--- a/libperf_events/operf_counter.cpp
+++ b/libperf_events/operf_counter.cpp
@@ -206,7 +206,8 @@ out:
} // end anonymous namespace

operf_counter::operf_counter(operf_event_t & evt, bool enable_on_exec, bool do_cg,
- bool separate_cpu, bool inherit, int event_number)
+ bool do_timestamps, bool separate_cpu,
+ bool inherit, int event_number)
{
memset(&attr, 0, sizeof(attr));
attr.size = sizeof(attr);
@@ -215,6 +216,8 @@ operf_counter::operf_counter(operf_event_t & evt, bool enable_on_exec, bool do_
attr.sample_type |= PERF_SAMPLE_CALLCHAIN;
if (separate_cpu)
attr.sample_type |= PERF_SAMPLE_CPU;
+ if (do_timestamps)
+ attr.sample_type |= PERF_SAMPLE_TIME;

#ifdef __s390__
attr.type = PERF_TYPE_HARDWARE;
@@ -316,8 +319,9 @@ operf_record::~operf_record()

operf_record::operf_record(int out_fd, bool sys_wide, pid_t the_pid, bool pid_running,
vector<operf_event_t> & events, vmlinux_info_t vi, bool do_cg,
- bool separate_by_cpu, bool out_fd_is_file,
- int _convert_read_pipe, int _convert_write_pipe)
+ bool do_timestamps, bool separate_by_cpu,
+ bool out_fd_is_file, int _convert_read_pipe,
+ int _convert_write_pipe)
{
struct sigaction sa;
sigset_t ss;
@@ -328,6 +332,7 @@ operf_record::operf_record(int out_fd, bool sys_wide, pid_t the_pid, bool pid_ru
pid_started = pid_running;
system_wide = sys_wide;
callgraph = do_cg;
+ collect_timestamps = do_timestamps;
separate_cpu = separate_by_cpu;
total_bytes_recorded = 0;
poll_count = 0;
@@ -693,7 +698,9 @@ void operf_record::setup()
pid_for_open = pid_to_profile;
operf_counter op_ctr(operf_counter(evts[event],
(!pid_started && !system_wide),
- callgraph, separate_cpu,
+ callgraph,
+ collect_timestamps,
+ separate_cpu,
inherit, event));
if ((rc = op_ctr.perf_event_open(pid_for_open,
real_cpu, this, true)) < 0) {
@@ -783,7 +790,8 @@ int operf_record::_start_recoding_new_thread(pid_t id)
for (unsigned event = 0; event < evts.size(); event++) {
operf_counter op_ctr(operf_counter(evts[event],
(!pid_started && !system_wide),
- callgraph, separate_cpu,
+ callgraph, collect_timestamps,
+ separate_cpu,
false, event));
if (op_ctr.perf_event_open(id, -1, this, false) < 0) {
sample_id = OP_PERF_NO_SAMPLE_ID;
diff --git a/libperf_events/operf_counter.h b/libperf_events/operf_counter.h
index 6e19da9..7f41863 100644
--- a/libperf_events/operf_counter.h
+++ b/libperf_events/operf_counter.h
@@ -57,7 +57,8 @@ op_perf_event_open(struct perf_event_attr * attr,
class operf_counter {
public:
operf_counter(operf_event_t & evt, bool enable_on_exec, bool callgraph,
- bool separate_by_cpu, bool inherit, int event_number);
+ bool collect_timestamps, bool separate_by_cpu,
+ bool inherit, int event_number);
~operf_counter();
int perf_event_open(pid_t pid, int cpu, operf_record * pr, bool print_error);
const struct perf_event_attr * the_attr(void) const { return &attr; }
@@ -83,7 +84,8 @@ public:
*/
operf_record(int output_fd, bool sys_wide, pid_t the_pid, bool pid_running,
std::vector<operf_event_t> & evts, OP_perf_utils::vmlinux_info_t vi,
- bool callgraph, bool separate_by_cpu, bool output_fd_is_file,
+ bool callgraph, bool collect_timestamps,
+ bool separate_by_cpu, bool output_fd_is_file,
int _convert_read_pipe, int _convert_write_pipe);
~operf_record();
void recordPerfData(void);
@@ -123,6 +125,7 @@ private:
bool pid_started;
bool system_wide;
bool callgraph;
+ bool collect_timestamps;
bool separate_cpu;
std::vector<operf_counter> perfCounters;
unsigned int total_bytes_recorded;
diff --git a/libperf_events/operf_sfile.cpp b/libperf_events/operf_sfile.cpp
index 3ffa325..69bb574 100644
--- a/libperf_events/operf_sfile.cpp
+++ b/libperf_events/operf_sfile.cpp
@@ -363,7 +363,7 @@ void operf_sfile_log_arc(struct operf_transient const * trans)
key = to & (0xffffffff);
key |= ((uint64_t)from) << 32;

- err = odb_update_node(file, key);
+ err = odb_update_node(file, key, 0); /* do not add time stamps */
if (err) {
fprintf(stderr, "%s: %s\n", __FUNCTION__, strerror(err));
abort();
@@ -400,7 +400,9 @@ void operf_sfile_log_sample_count(struct operf_transient const * trans,
}
err = odb_update_node_with_offset(file,
(odb_key_t)pc,
- count);
+ count,
+ trans->timestamp);
+
if (err) {
fprintf(stderr, "%s: %s\n", __FUNCTION__, strerror(err));
abort();
@@ -419,7 +421,7 @@ static int close_sfile(struct operf_sfile * sf, void * data __attribute__((unuse

/* it's OK to close a non-open odb file */
for (i = 0; i < op_nr_events; ++i)
- odb_close(&sf->files[i]);
+ odb_close(&sf->files[i], true); /* write the time stamps */

// TODO: handle extended
//opd_ext_operf_sfile_close(sf);
diff --git a/libperf_events/operf_sfile.h b/libperf_events/operf_sfile.h
index bc00355..ee1f8bc 100644
--- a/libperf_events/operf_sfile.h
+++ b/libperf_events/operf_sfile.h
@@ -104,6 +104,7 @@ struct operf_transient {
bool cg;
// TODO: handle extended
//void * ext;
+ u64 timestamp;
};


diff --git a/libperf_events/operf_utils.cpp b/libperf_events/operf_utils.cpp
index ff972d4..8b88e43 100644
--- a/libperf_events/operf_utils.cpp
+++ b/libperf_events/operf_utils.cpp
@@ -75,6 +75,7 @@ static inline void clear_trans(struct operf_transient * trans)
{
trans->tgid = ~0U;
trans->cur_procinfo = NULL;
+ trans->timestamp = 0;
}

static void __handle_fork_event(event_t * event)
@@ -613,6 +614,14 @@ static int __handle_sample_event(event_t * event, u64 sample_type)
goto done;
}

+ data.time = 0; /* if time stamp is 0, it will not be recorded */
+ /* Only have time stamps if the user requested them */
+ if (sample_type & PERF_SAMPLE_TIME) {
+ data.time = *array;
+ trans.timestamp = data.time;
+ array++;
+ }
+
data.id = ~0ULL;
if (sample_type & PERF_SAMPLE_ID) {
data.id = *array;
diff --git a/libpp/callgraph_container.cpp b/libpp/callgraph_container.cpp
index 2affa8f..92adde8 100644
--- a/libpp/callgraph_container.cpp
+++ b/libpp/callgraph_container.cpp
@@ -30,6 +30,7 @@
#include "op_sample_file.h"
#include "locate_images.h"
#include "utility.h"
+#include "profile.h"
#include <string.h>

using namespace std;
@@ -150,7 +151,7 @@ public:

for (; p_it.first != p_it.second; ++p_it.first) {
samples.push_back(make_pair(p_it.first.vma(),
- p_it.first.count()));
+ p_it.first.cnt_struct().count));
}

sort(samples.begin(), samples.end(),
diff --git a/libpp/format_output.cpp b/libpp/format_output.cpp
index 11cd396..97d3fca 100644
--- a/libpp/format_output.cpp
+++ b/libpp/format_output.cpp
@@ -32,8 +32,15 @@
#include "xml_utils.h"
#include "cverb.h"

+/* only print warning on missing times stampls once */
+bool warned_no_timestamps = false;
+
using namespace std;

+namespace options {
+ extern bool enable_timestamps;
+}
+
namespace {


@@ -771,6 +778,8 @@ string xml_formatter::
output_symbol_details(symbol_entry const * symb,
size_t & detail_index, size_t const lo, size_t const hi)
{
+ bool found_timestamps = false;
+
if (!has_sample_counts(symb->sample.counts, lo, hi))
return "";

@@ -817,9 +826,24 @@ output_symbol_details(symbol_entry const * symb,
// output buffered sample data
output_sample_data(str, it->second, p);

+ if (options::enable_timestamps)
+ // output time stamp for each sample collected
+ found_timestamps |=
+ output_timestamp_data(str, it->second, p);
+
str << close_element(DETAIL_DATA);
}
}
+
+ if (!found_timestamps && (options::enable_timestamps)
+ && (warned_no_timestamps == false)) {
+ warned_no_timestamps = true;
+ cerr << "WARNING, Time stamp option -T was specified "
+ << "for opreport but no time stamp information\nwas "
+ << "available. \nUse -T option on operf to collect the "
+ << "time stamp data.\n\n";
+ }
+
return str.str();
}

@@ -833,10 +857,27 @@ output_symbol(ostream & out,

// output symbol's summary data for each profile class
bool got_samples = false;
+ bool found_timestamps = false;

for (size_t p = lo; p <= hi; ++p) {
got_samples |= xml_support->output_summary_data(str,
symb->sample.counts, p);
+
+ if ((options::enable_timestamps) && !need_details)
+ /* Check if time stamp information has been stored. */
+ found_timestamps |= xml_support->output_tm_data(str,
+ symb->sample.counts,
+ symb->sample.count_timestamp,
+ p);
+ }
+
+ if ((options::enable_timestamps) && (found_timestamps == false)
+ && !need_details && (warned_no_timestamps == false)) {
+ warned_no_timestamps = true;
+ cerr << "WARNING, Time stamp option -T was specified for "
+ << "opreport but no time stamp information\nwas "
+ << "available. \nUse -T option on operf to collect the "
+ << "time stamp data.\n\n";
}

if (!got_samples)
@@ -891,10 +932,51 @@ output_sample_data(ostream & out, sample_entry const & sample, size_t pclass)
out << open_element(COUNT, true);
out << init_attr(CLASS, classes.v[pclass].name);
out << close_element(NONE, true);
- out << sample.counts[pclass];
+ out << dec << sample.counts[pclass];
out << close_element(COUNT);
}

+bool xml_formatter::
+output_timestamp_data(ostream & out, sample_entry const & sample,
+ size_t pclass)
+{
+ bool found_timestamps = false;
+
+ out << open_element(TIMESTAMP, true);
+
+ if (classes.v[pclass].name != "") {
+ out << init_attr(CLASS, classes.v[pclass].name);
+ }
+ out << close_element(NONE, true);
+
+ /* print the time stamps */
+ count_tm_map_t count_timestamp = sample.count_timestamp;
+ count_tm_map_t::iterator it = count_timestamp.begin();
+
+ for(; it != count_timestamp.end(); ++it) {
+ if (it->first == pclass) {
+ /* found entry */
+ std::vector<uint64_t> it_tm_vector = it->second;
+ std::vector<uint64_t>::iterator it_tm = it_tm_vector.begin();
+
+ ios::fmtflags f(out.flags());
+ for(; it_tm != it_tm_vector.end(); ++it_tm) {
+ found_timestamps = true;
+ out << "0x" << hex << *it_tm << " ";
+ }
+ out.flags(f);
+ break;
+ }
+ }
+
+ if (found_timestamps == false) {
+ cerr << "ERROR: xml_formatter::output_time stamp_data() Failed "
+ << "to find the Time stamp vector for pclass = "
+ << pclass << endl;
+ }
+ out << close_element(TIMESTAMP);
+ return found_timestamps;
+}

void xml_formatter::
output_attribute(ostream & out, field_datum const & datum,
diff --git a/libpp/format_output.h b/libpp/format_output.h
index 6531bdc..636e5dd 100644
--- a/libpp/format_output.h
+++ b/libpp/format_output.h
@@ -72,6 +72,8 @@ protected:
struct counts_t {
/// total sample count
count_array_t total;
+ /// time stamps so far
+ count_tm_map_t total_tm;
/// samples so far
count_array_t cumulated_samples;
/// percentage so far
@@ -282,6 +284,9 @@ private:
void output_sample_data(std::ostream & out,
sample_entry const & sample, size_t count);

+ bool output_timestamp_data(std::ostream & out,
+ sample_entry const & sample, size_t count);
+
/// output attribute in XML
void output_attribute(std::ostream & out, field_datum const & datum,
format_flags fl, tag_t tag);
diff --git a/libpp/op_header.h b/libpp/op_header.h
index b0fc48f..3b1d9a2 100644
--- a/libpp/op_header.h
+++ b/libpp/op_header.h
@@ -14,8 +14,10 @@

#include <iosfwd>
#include <string>
+#include <vector>

#include "op_sample_file.h"
+#include <stdint.h>

/**
* @param h1 sample file header
diff --git a/libpp/profile.cpp b/libpp/profile.cpp
index be3ff93..58bfd72 100644
--- a/libpp/profile.cpp
+++ b/libpp/profile.cpp
@@ -23,10 +23,12 @@
#include "op_exception.h"
#include "op_header.h"
#include "op_config.h"
+#include "tm_array.h"
#include "op_sample_file.h"
#include "profile.h"
#include "op_bfd.h"
#include "cverb.h"
+#include <vector>

using namespace std;

@@ -37,22 +39,22 @@ profile_t::profile_t()


// static member
-count_type profile_t::sample_count(string const & filename)
+count_t profile_t::sample_count(string const & filename)
{
odb_t samples_db;
+ count_t count_tm;
+ count_type count = 0;

open_sample_file(filename, samples_db);

- count_type count = 0;
-
odb_node_nr_t node_nr, pos;
odb_node_t * node = odb_get_iterator(&samples_db, &node_nr);
for (pos = 0; pos < node_nr; ++pos)
count += node[pos].value;

- odb_close(&samples_db);
-
- return count;
+ odb_close(&samples_db, /* write time stamps */ false);
+ count_tm.count = count;
+ return count_tm;
}

//static member
@@ -92,22 +94,35 @@ void profile_t::add_sample_file(string const & filename)
else
file_header.reset(new opd_header(head));

+ count_type i;
odb_node_nr_t node_nr, pos;
odb_node_t * node = odb_get_iterator(&samples_db, &node_nr);

- for (pos = 0; pos < node_nr; ++pos) {
+ for (pos = 1; pos < node_nr; ++pos) { /* node node zero not used */
ordered_samples_t::iterator it =
ordered_samples.find(node[pos].key);
if (it != ordered_samples.end()) {
- it->second += node[pos].value;
+ it->second.count += node[pos].value;
} else {
+ count_t entry;
+ entry.count = node[pos].value;
+
+ if (samples_db.data->timestamp_array[0]
+ != EMPTY_TM_ARRAY)
+ for (i = node[pos].tm_index;
+ i < node[pos].tm_index + entry.count;
+ i++) {
+
+ entry.time_stamps.push_back(samples_db.data->timestamp_array[i]);
+ }
+
ordered_samples_t::value_type
- val(node[pos].key, node[pos].value);
+ val(node[pos].key, entry);
ordered_samples.insert(val);
}
}

- odb_close(&samples_db);
+ odb_close(&samples_db, /* write time stamps */ false);
}


@@ -162,6 +177,28 @@ profile_t::samples_range(odb_key_t start, odb_key_t end) const
const_iterator(last, start_offset));
}

+const count_t profile_t::accumulate(const_iterator const & first,
+ const_iterator const & last,
+ uint64_t val) {
+ /* accumulate the count value and the corresponding time stamps
+ * if there are any time stamps.
+ */
+ profile_t::const_iterator it;
+ count_t count_struct;
+ std::vector <uint64_t> tm_stamps;
+
+ for (it = first; it != last; ++it) {
+ count_struct = it.cnt_struct();
+ val += count_struct.count;
+ tm_stamps.insert(tm_stamps.end(),
+ count_struct.time_stamps.begin(),
+ count_struct.time_stamps.end());
+ }
+ count_struct.count = val;
+ count_struct.time_stamps = tm_stamps;
+ return count_struct;
+}
+

profile_t::iterator_pair profile_t::samples_range() const
{
diff --git a/libpp/profile.h b/libpp/profile.h
index 78cda72..0d094fb 100644
--- a/libpp/profile.h
+++ b/libpp/profile.h
@@ -16,14 +16,25 @@
#include <string>
#include <map>
#include <iterator>
+#include <vector>

#include "odb.h"
#include "op_types.h"
#include "utility.h"
+#include <stdint.h>

class opd_header;
class op_bfd;

+/* structure to store the time stamp for each count
+ * and the total count
+ */
+typedef struct {
+ count_type count;
+ std::vector <uint64_t> time_stamps;
+} count_t;
+
+
/**
* Class containing a single sample file contents.
* i.e. set of count values for VMA offsets for
@@ -52,7 +63,7 @@ public:
* them. It's placed here so all access to samples files go through
* profile_t static or non static member.
*/
- static count_type sample_count(std::string const & filename);
+ static count_t sample_count(std::string const & filename);

/**
* cumulate sample file to our container of samples
@@ -82,6 +93,9 @@ public:

/// return a pair of iterator for all samples
iterator_pair samples_range() const;
+ const count_t accumulate(const_iterator const & first,
+ const_iterator const & last,
+ uint64_t val);

private:
/// helper for sample_count() and add_sample_file(). All error launch
@@ -92,8 +106,9 @@ private:
/// copy of the samples file header
scoped_ptr<opd_header> file_header;

- /// storage type for samples sorted by eip
- typedef std::map<odb_key_t, count_type> ordered_samples_t;
+ /// storage type for samples sorted by eip, {count, time_stamps}
+ typedef std::map<odb_key_t, count_t> ordered_samples_t;
+ // typedef std::map<odb_key_t, count_type> ordered_samples_t;

/**
* Samples are stored in hash table, iterating over hash table don't
@@ -140,14 +155,13 @@ namespace std {
template <>
struct iterator_traits<profile_t::const_iterator> {
typedef ptrdiff_t difference_type;
- typedef count_type value_type;
- typedef count_type * pointer;
- typedef count_type & reference;
+ typedef count_t value_type;
+ typedef count_t * pointer;
+ typedef count_t & reference;
typedef input_iterator_tag iterator_category;
};
}

-
class profile_t::const_iterator
{
typedef ordered_samples_t::const_iterator iterator_t;
@@ -156,11 +170,11 @@ public:
const_iterator(iterator_t it_, u64 start_offset_)
: it(it_), start_offset(start_offset_) {}

- count_type operator*() const { return it->second; }
+ count_t operator*() const { return it->second; }
const_iterator & operator++() { ++it; return *this; }

odb_key_t vma() const { return it->first + start_offset; }
- count_type count() const { return **this; }
+ count_t cnt_struct() const { return **this; }

bool operator!=(const_iterator const & rhs) const {
return it != rhs.it;
diff --git a/libpp/profile_container.cpp b/libpp/profile_container.cpp
index dca6fdd..3fd0856 100644
--- a/libpp/profile_container.cpp
+++ b/libpp/profile_container.cpp
@@ -28,6 +28,10 @@

using namespace std;

+namespace options {
+ extern bool timestamps;
+}
+
namespace {

struct filename_by_samples {
@@ -70,7 +74,7 @@ profile_container::~profile_container()
// the symbols/samples are sorted by increasing vma.
// the range of sample_entry inside each symbol entry are valid
// the samples_by_file_loc member var is correctly setup.
-void profile_container::add(profile_t const & profile,
+void profile_container::add(profile_t & profile,
op_bfd const & abfd, string const & app_name,
size_t pclass)
{
@@ -81,12 +85,15 @@ void profile_container::add(profile_t const & profile,

unsigned long long start = 0, end = 0;
symbol_entry symb_entry;
+ count_t count_tm;

abfd.get_symbol_range(i, start, end);

profile_t::iterator_pair p_it =
profile.samples_range(start, end);
- count_type count = accumulate(p_it.first, p_it.second, 0ull);
+ count_tm = profile.accumulate(p_it.first, p_it.second, 0ull);
+ count_type count = count_tm.count;
+ std::vector <uint64_t> time_stamps = count_tm.time_stamps;

// skip entries with no samples
if (count == 0)
@@ -94,8 +101,21 @@ void profile_container::add(profile_t const & profile,

sym_count_total += count;
symb_entry.sample.counts[pclass] = count;
+ /* Track the time stamps for the sym_entry counts in a map.
+ * Note, if not collecting time stamps, the
+ * count_tm.time_stamps will be empty.
+ */
+ symb_entry.symbol_add_tm(pclass, count_tm.time_stamps);
+
total_count[pclass] += count;

+ total_tm[pclass].insert(total_tm[pclass].end(),
+ time_stamps.begin(),
+ time_stamps.end());
+
+ /* track the time stamps for the entry in total_count[] for
+ * use in the XML output.
+ */
symb_entry.size = end - start;

symb_entry.name = symbol_names.create(abfd.syms[i].name());
@@ -125,7 +145,10 @@ void profile_container::add(profile_t const & profile,
if (cverb << vdebug) {
profile_t::iterator_pair summary_it =
profile.samples_range(profile.get_offset(), ~0ULL);
- count_type module_summary_count = accumulate(summary_it.first, summary_it.second, 0ull);
+ count_t count_tm = profile.accumulate(summary_it.first,
+ summary_it.second, 0ull);
+ count_type module_summary_count = count_tm.count;
+
if (sym_count_total < module_summary_count)
cout << "INFO: Sample counts differ: Module summary count: " << dec
<< module_summary_count << "; total symbols count: " << sym_count_total
@@ -149,7 +172,8 @@ profile_container::add_samples(op_bfd const & abfd, symbol_index_t sym_index,
for (it = p_it.first; it != p_it.second ; ++it) {
sample_entry sample;

- sample.counts[pclass] = it.count();
+ sample.counts[pclass] = it.cnt_struct().count;
+ sample.count_timestamp[pclass] = it.cnt_struct().time_stamps;

sample.file_loc.linenr = 0;
if (debug_info) {
@@ -263,6 +287,11 @@ count_array_t profile_container::samples_count() const
return total_count;
}

+count_tm_map_t profile_container::samples_count_tm() const
+{
+ return total_tm;
+}
+

// Rest here are delegated to our private implementation.

diff --git a/libpp/profile_container.h b/libpp/profile_container.h
index c22f5d3..5396c72 100644
--- a/libpp/profile_container.h
+++ b/libpp/profile_container.h
@@ -63,7 +63,7 @@ public:
* Obviously you can add only samples files which are coherent (same
* sampling rate, same events etc.)
*/
- void add(profile_t const & profile, op_bfd const & abfd,
+ void add(profile_t & profile, op_bfd const & abfd,
std::string const & app_name, size_t pclass);

/// Find a symbol from its image_name, vma, return zero if no symbol
@@ -117,6 +117,9 @@ public:
/// return the total number of samples
count_array_t samples_count() const;

+ /// return the time stamp vector for the total number of samples
+ count_tm_map_t samples_count_tm() const;
+
/// Get the samples count which belongs to filename. Return 0 if
/// no samples found.
count_array_t samples_count(debug_name_id filename_id) const;
@@ -171,6 +174,9 @@ private:
/// build() must count samples count for each profile class so cache it
/// here since user of profile_container often need it later.
count_array_t total_count;
+ /// XML output will use the time stamps.
+ count_tm_map_t total_tm;
+

/**
* Optimization hints for what information we are going to need,
diff --git a/libpp/symbol.cpp b/libpp/symbol.cpp
index cb39571..2aa6373 100644
--- a/libpp/symbol.cpp
+++ b/libpp/symbol.cpp
@@ -47,3 +47,12 @@ string const & get_image_name(image_name_id id,
{
return image_names.get_name(id, type, extra);
}
+
+void symbol_entry::symbol_add_tm(size_t pclass,
+ std::vector <uint64_t> & time_stamps)
+{
+ /* add time stamp vector to map with key pclass */
+ sample.count_timestamp[pclass].insert(sample.count_timestamp[pclass].end(),
+ time_stamps.begin(),
+ time_stamps.end());
+}
diff --git a/libpp/symbol.h b/libpp/symbol.h
index 017e04c..580fea2 100644
--- a/libpp/symbol.h
+++ b/libpp/symbol.h
@@ -30,6 +30,8 @@ class extra_images;
/// for storing sample counts
typedef sparse_array<u32, count_type> count_array_t;

+/// map for storing the time stamp vector for the counts
+typedef std::map<u32, std::vector<uint64_t> > count_tm_map_t;

/// A simple container for a fileno:linenr location.
struct file_location {
@@ -56,6 +58,8 @@ struct sample_entry {
bfd_vma vma;
/// the samples count
count_array_t counts;
+ /// the time stamps for the samples count
+ count_tm_map_t count_timestamp;
};


@@ -64,6 +68,8 @@ class symbol_entry {
public:
symbol_entry() : sym_index(0), size(0), vma_adj(0) {}
virtual ~symbol_entry() {}
+ class const_iterator;
+ typedef std::pair<const_iterator, const_iterator> iterator_pair;

/// which image this symbol belongs to
image_name_id image_name;
@@ -99,6 +105,8 @@ public:
* this to every symbol_entry, but there isn't a better option.
*/
bfd_vma vma_adj;
+ void symbol_add_tm(size_t pclass,
+ std::vector <uint64_t> & time_stamps);
};


diff --git a/libpp/symbol_container.cpp b/libpp/symbol_container.cpp
index 55aa76f..6088b60 100644
--- a/libpp/symbol_container.cpp
+++ b/libpp/symbol_container.cpp
@@ -9,6 +9,7 @@
* @author John Levon
*/

+#include <iostream> // for debugging only remove later
#include <string>
#include <algorithm>
#include <set>
@@ -31,6 +32,13 @@ symbol_entry const * symbol_container::insert(symbol_entry const & symb)
// safe: count is not used by sorting criteria
symbol_entry * symbol = const_cast<symbol_entry*>(&*p.first);
symbol->sample.counts += symb.sample.counts;
+
+ count_tm_map_t const symbol_tm = symbol->sample.count_timestamp;
+ count_tm_map_t const & symb_tm = symb.sample.count_timestamp;
+ count_tm_map_t symb_tm_map = symb_tm;
+ count_tm_map_t::iterator it_symb = symb_tm_map.begin();
+
+ symbol->sample.count_timestamp[it_symb->first] = it_symb->second;
}

return &*p.first;
diff --git a/libpp/xml_utils.cpp b/libpp/xml_utils.cpp
index 3de41e5..9668104 100644
--- a/libpp/xml_utils.cpp
+++ b/libpp/xml_utils.cpp
@@ -246,7 +246,7 @@ void xml_utils::output_xml_header(string const & command_options,
string const schema_version = "3.1";

// This is the XML version, not schema version.
- string const xml_header = "<?xml version=\"1.0\" ?>";
+ string const xml_header = "<?xml version=\"1.1\" ?>";

cout << xml_header << endl;
cout << open_element(PROFILE, true);
@@ -386,7 +386,45 @@ xml_utils::output_symbol_bytes(ostream & out, symbol_entry const * symb,


bool
-xml_utils::output_summary_data(ostream & out, count_array_t const & summary, size_t pclass)
+xml_utils::output_tm_data(std::ostream & out, count_array_t const & summary,
+ count_tm_map_t const & summary_tm, size_t pclass)
+{
+ /* Return true if there were time stamps found to print */
+ count_tm_map_t tm_map = summary_tm;
+ count_tm_map_t::iterator it = tm_map.begin();
+ bool rtn = false;
+
+ if (summary[pclass] == 0) return false;
+
+ out << open_element(TIMESTAMP, has_subclasses);
+ if (has_subclasses) {
+ out << init_attr(CLASS, classes.v[pclass].name);
+ out << close_element(NONE, true);
+ }
+
+ std::vector<uint64_t> tm_vector;
+
+ for(; it != summary_tm.end(); it++) {
+ if (it->first == pclass) {
+ tm_vector = it->second;
+
+ std::vector<uint64_t>::iterator it_tm = tm_vector.begin();
+ ios::fmtflags f(out.flags());
+ rtn = true; /* found time stamp data */
+ for(; it_tm != tm_vector.end(); it_tm++) {
+ out << " 0x" << hex << *it_tm << " ";
+ }
+ out.flags(f);
+ break;
+ }
+ }
+ out << close_element(TIMESTAMP);
+ return rtn;
+}
+
+bool
+xml_utils::output_summary_data
+(ostream & out, count_array_t const & summary, size_t pclass)
{
size_t const count = summary[pclass];

@@ -417,6 +455,7 @@ public:
void set_begin(sym_iterator b);
void set_end(sym_iterator e);
void add_to_summary(count_array_t const & counts);
+ void add_tm_to_summary(count_tm_map_t const & tm_vector);
void output(ostream & out);
bool is_closed(string const & n);
protected:
@@ -429,6 +468,8 @@ protected:

// summary sample data
count_array_t summary;
+ // summary sample data timestamps
+ count_tm_map_t summary_tm;

// range of profile classes approprate for this module
size_t lo;
@@ -537,6 +578,22 @@ void module_info::add_to_summary(count_array_t const & counts)
summary[pclass] += counts[pclass];
}

+void module_info::add_tm_to_summary(count_tm_map_t const & tm_map)
+{
+
+ count_tm_map_t map = tm_map;
+ count_tm_map_t::iterator it = map.begin();
+
+ for (size_t pclass = lo ; pclass <= hi; ++pclass) {
+ for(; it != map.end(); it++) {
+ if (it->first == pclass) {
+ summary_tm[pclass] = it->second;
+ }
+ }
+
+ }
+}
+

void module_info::set_begin(sym_iterator b)
{
@@ -578,6 +635,7 @@ void module_info::output(ostream & out)

void module_info::output_summary(ostream & out)
{
+ /* Note, we do not put out time stamp data for the modules */
for (size_t p = lo; p <= hi; ++p)
(void)xml_support->output_summary_data(out, summary, p);
}
@@ -632,6 +690,7 @@ add_module_symbol(string const & module, string const & app,

// add symbol count to binary count
add_to_summary((*it)->sample.counts);
+ add_tm_to_summary((*it)->sample.count_timestamp);
return;
}

@@ -658,6 +717,7 @@ add_module_symbol(string const & module, string const & app,

// propagate this symbols counts to the module
my_modules[nr_modules-1].add_to_summary((*it)->sample.counts);
+ my_modules[nr_modules-1].add_tm_to_summary((*it)->sample.count_timestamp);
}


@@ -867,6 +927,7 @@ void thread_info::add_module_symbol(string const & n, sym_iterator it)
module_info & m = my_modules[nr_modules++];
m.build_module(n, it, lo, hi);
m.add_to_summary((*it)->sample.counts);
+ m.add_tm_to_summary((*it)->sample.count_timestamp);
}

void thread_info::output(ostream & out)
@@ -911,6 +972,7 @@ bool thread_info::add_modules(string const & module, sym_iterator it)
} else {
// propagate symbols count to module
my_modules[nr_modules-1].add_to_summary((*it)->sample.counts);
+ my_modules[nr_modules-1].add_tm_to_summary((*it)->sample.count_timestamp);
}
return false;
}
diff --git a/libpp/xml_utils.h b/libpp/xml_utils.h
index 668e943..7ae27c4 100644
--- a/libpp/xml_utils.h
+++ b/libpp/xml_utils.h
@@ -48,6 +48,9 @@ public:
size_t sym_id, op_bfd const & abfd);
bool output_summary_data(std::ostream & out, count_array_t const & summary,
size_t pclass);
+ bool output_tm_data(std::ostream & out, count_array_t const & summary,
+ count_tm_map_t const & summary_tm, size_t pclass);
+
size_t get_symbol_index(sym_iterator const it);
void output_program_structure(std::ostream & out);
void build_subclasses(std::ostream & out);
diff --git a/pe_profiling/operf.cpp b/pe_profiling/operf.cpp
index 5585b34..dd95ca8 100644
--- a/pe_profiling/operf.cpp
+++ b/pe_profiling/operf.cpp
@@ -125,6 +125,7 @@ bool system_wide;
bool append;
int pid;
bool callgraph;
+bool collect_timestamps;
int mmap_pages_mult;
string session_dir;
string vmlinux;
@@ -143,6 +144,7 @@ struct option long_options [] =
{"session-dir", required_argument, NULL, 'd'},
{"vmlinux", required_argument, NULL, 'k'},
{"callgraph", no_argument, NULL, 'g'},
+ {"timestamps", no_argument, NULL, 'T'},
{"system-wide", no_argument, NULL, 's'},
{"append", no_argument, NULL, 'a'},
{"pid", required_argument, NULL, 'p'},
@@ -156,7 +158,7 @@ struct option long_options [] =
{NULL, 9, NULL, 0}
};

-const char * short_options = "V:d:k:gsap:e:ctlhuv";
+const char * short_options = "V:d:k:gsaTp:e:ctlhuv";

vector<string> verbose_string;

@@ -175,7 +177,7 @@ static void __print_usage_and_exit(const char * extra_msg)
{
if (extra_msg)
cerr << extra_msg << endl;
- cerr << "usage: operf [ options ] [ --system-wide | --pid <pid> | [ command [ args ] ] ]" << endl;
+ cerr << "usage: operf [ options ] [ --system-wide | --pid <pid> | -T | [ command [ args ] ] ]" << endl;
cerr << "See operf man page for details." << endl;
exit(EXIT_FAILURE);
}
@@ -374,6 +376,7 @@ int start_profiling(void)
operfRecord = new operf_record(outfd, operf_options::system_wide, app_PID,
(operf_options::pid == app_PID), events, vi,
operf_options::callgraph,
+ operf_options::collect_timestamps,
operf_options::separate_cpu, operf_options::post_conversion,
operf_convert_record_write_pipe[0], operf_record_convert_write_pipe[1]);
if (operfRecord->get_valid() == false) {
@@ -1292,6 +1295,9 @@ static int _process_operf_and_app_args(int argc, char * const argv[])
case 'g':
operf_options::callgraph = true;
break;
+ case 'T':
+ operf_options::collect_timestamps = true;
+ break;
case 's':
operf_options::system_wide = true;
break;
diff --git a/pp/opgprof.cpp b/pp/opgprof.cpp
index 6550f21..7907b94 100644
--- a/pp/opgprof.cpp
+++ b/pp/opgprof.cpp
@@ -122,13 +122,13 @@ void output_cg(FILE * fp, op_bfd const & abfd, profile_t const & cg_db)
op_write_u8(fp, GMON_TAG_CG_ARC);
op_write_vma(fp, abfd, abfd.offset_to_pc(from + offset));
op_write_vma(fp, abfd, abfd.offset_to_pc(to + offset));
- u32 count = p_it.first.count();
- if (count != p_it.first.count()) {
+ u32 count = p_it.first.cnt_struct().count;
+ if (count != p_it.first.cnt_struct().count) {
count = (u32)-1;
cerr << "Warning: capping sample count by "
- << p_it.first.count() - count << endl;
+ << p_it.first.cnt_struct().count - count << endl;
}
- op_write_u32(fp, p_it.first.count());
+ op_write_u32(fp, p_it.first.cnt_struct().count);
}
}

diff --git a/pp/opreport.cpp b/pp/opreport.cpp
index 7ad6190..9b70ed7 100644
--- a/pp/opreport.cpp
+++ b/pp/opreport.cpp
@@ -10,6 +10,7 @@
*/

#include <iostream>
+#include <fstream>
#include <iomanip>
#include <vector>
#include <algorithm>
@@ -64,9 +65,12 @@ add_files(list<profile_sample_files> const & files, size_t pclass)
list<profile_sample_files>::const_iterator const end = files.end();

for (; it != end; ++it) {
- count_type count = profile_t::sample_count(it->sample_filename);
- counts[pclass] += count;
- subtotal += count;
+ count_t count_tm;
+ count_tm = profile_t::sample_count(it->sample_filename);
+
+
+ counts[pclass] += count_tm.count;
+ subtotal += count_tm.count;

if (!it->cg_files.empty()) {
throw op_runtime_error("opreport.cpp::add_files(): "
@@ -496,10 +500,19 @@ void output_cg_symbols(callgraph_container const & cg, bool multiple_apps)

int opreport(options::spec const & spec)
{
+ std::ofstream out(DEFAULT_OPREPORT_XML_NAME);
+
want_xml = options::xml;

handle_options(spec);

+ if (options::plot_time_stamp)
+ /* The xml output is written to the standard out by default.
+ * If we need to generate the time stamp graph the output needs
+ * to be directed to a file for further processing later.
+ */
+ std::cout.rdbuf(out.rdbuf());
+
nr_classes = classes.v.size();

if (!options::symbols && !options::xml) {
@@ -579,6 +592,15 @@ int opreport(options::spec const & spec)
output_symbols(samples, multiple_apps);
}

+ if (options::plot_time_stamp) {
+ /* User requested a time stamp plot
+ * be generated
+ */
+ cout << "CARLL COMMAND = " << options::time_stamp_options
+ << endl;
+ system(options::time_stamp_options.c_str());
+ }
+
return 0;
}

diff --git a/pp/opreport_options.cpp b/pp/opreport_options.cpp
index bc58e51..249a883 100644
--- a/pp/opreport_options.cpp
+++ b/pp/opreport_options.cpp
@@ -36,6 +36,7 @@ namespace options {
demangle_type demangle = dmt_normal;
bool symbols;
bool callgraph;
+ bool enable_timestamps;
bool debug_info;
bool details;
bool exclude_dependent;
@@ -50,6 +51,10 @@ namespace options {
bool global_percent;
bool xml;
string xml_options;
+ bool plot_time_stamp;
+ string time_stamp_options;
+ bool time_stamp_line_graph;
+ bool time_stamp_bar_graph;
}


@@ -61,10 +66,17 @@ vector<string> sort;
vector<string> exclude_symbols;
vector<string> include_symbols;
string demangle_option = "normal";
+string time_stamp_ps_file_name = "time_stamp_plot.ps";
+string time_stamp_max_symbols;
+string time_stamp_max_bins;
+string time_stamp_start_time;
+string time_stamp_end_time;

popt::option options_array[] = {
popt::option(options::callgraph, "callgraph", 'c',
"show call graph"),
+ popt::option(options::enable_timestamps, "enable_timestamps", 'T',
+ "show timestamps in XML output"),
popt::option(options::details, "details", 'd',
"output detailed samples for each symbol"),
popt::option(options::symbols, "symbols", 'l',
@@ -109,6 +121,22 @@ popt::option options_array[] = {

popt::option(options::xml, "xml", 'X',
"XML output"),
+ popt::option(options::plot_time_stamp, "plot_ps", 'P',
+ "Generate time stamp graph. Requires the --xml or -X option to be specified as well."),
+ popt::option(time_stamp_ps_file_name, "ts_plot_name", 'F',
+ "Generate time stamp line graph. Requires the --ts_plot or -P option to be specified as well.", "file"),
+ popt::option(options::time_stamp_line_graph, "line_graph", 'L',
+ "Generate time stamp line graph . Requires the --ts_plot or -P option to be specified as well."),
+ popt::option(options::time_stamp_bar_graph, "bar_graph", 'B',
+ "Generate time stamp bar graph . Requires the --ts_plot or -P option to be specified as well."),
+ popt::option(time_stamp_max_symbols, "ts_max_sym", 'M',
+ "Max symbols for time stamp graph . Requires the --ts_plot or -P option to be specified as well.", "num_symbols"),
+ popt::option(time_stamp_max_bins, "ts_max_bins", 'b',
+ "Max symbols for time stamp graph . Requires the --ts_plot or -P option to be specified as well.", "num_bins"),
+ popt::option(time_stamp_start_time, "ts_start", 'S',
+ "Start time for stamp graph . Requires the --ts_plot or -P option to be specified as well.", "start_time"),
+ popt::option(time_stamp_end_time, "ts_end", 'E',
+ "End time for stamp graph . Requires the --ts_plot or -P option to be specified as well.", "stop_time"),

};

@@ -142,6 +170,48 @@ void handle_sort_option()
options::sort_by.add_sort_option(*cit);
}

+void handle_time_stamp_options()
+{
+
+ /* Setup the command string to call the time stamp plotting script
+ * plot_time_stamps.sh. The script requires the name of the xml file
+ * be passed to it.
+ */
+
+ if (!options::plot_time_stamp)
+ return;
+
+ options::time_stamp_options.append(" plot_time_stamps.sh --xml_file ");
+ options::time_stamp_options.append(DEFAULT_OPREPORT_XML_NAME);
+
+ if (!time_stamp_ps_file_name.empty()) {
+ options::time_stamp_options.append(" --ps_file ");
+ options::time_stamp_options.append(time_stamp_ps_file_name);
+ }
+
+ if (options::time_stamp_line_graph) {
+ options::time_stamp_options.append(" --line_graph ");
+ }
+
+ if (options::time_stamp_bar_graph) {
+ options::time_stamp_options.append(" --bar_graph ");
+ }
+
+ if (!time_stamp_max_symbols.empty()) {
+ options::time_stamp_options.append(" --max_symbols ");
+ options::time_stamp_options.append(time_stamp_max_symbols);
+ }
+
+ if (!time_stamp_max_bins.empty()) {
+ options::time_stamp_options.append(" --max_bins ");
+ options::time_stamp_options.append(time_stamp_max_bins);
+ }
+
+ if (!time_stamp_start_time.empty()) {
+ options::time_stamp_options.append(" --start_time ");
+ options::time_stamp_options.append(time_stamp_start_time);
+ }
+}

void handle_output_file()
{
@@ -191,6 +261,79 @@ void check_options(bool diff)
}
}

+ if (enable_timestamps && !xml) {
+ cerr << "--timestamps (-T) only prints the sample "
+ "time stamps in the XML output file. \nYou must "
+ "use the --xml option with the time stamp option."
+ << endl;
+ do_exit = true;
+ }
+
+ if (plot_time_stamp && !enable_timestamps) {
+ cerr << "--ts_plot (-P) time stamp plot can only be generated if "
+ "-T and -X have also been specified.\nYou must "
+ "use the -T and -X options with the time stamp plot option."
+ << endl;
+ do_exit = true;
+ }
+
+ if (time_stamp_line_graph && time_stamp_bar_graph) {
+ cerr << "Can only specify line graph or bar graph but not both.\n"
+ << endl;
+ do_exit = true;
+ }
+
+ if (time_stamp_line_graph && !plot_time_stamp) {
+ cerr << "Line graph of the time stamps can only be generated if "
+ "if -P or --ts_plot have also been specified.\n"
+ << endl;
+ do_exit = true;
+ }
+
+ if (time_stamp_bar_graph && !plot_time_stamp) {
+ cerr << "Bar graph of the time stamps can only be generated if "
+ "if -P or --ts_plot have also been specified.\n"
+ << endl;
+ do_exit = true;
+ }
+
+ if (time_stamp_ps_file_name.empty() && !plot_time_stamp) {
+ cerr << "Name of the postscript file containing time graph can "
+ "only be used if -P or --ts_plot have also been "
+ "specified.\n"
+ << endl;
+ do_exit = true;
+ }
+
+ if (!time_stamp_max_symbols.empty() && !plot_time_stamp) {
+ cerr << "Max number of symbols in the time graph can "
+ "only be used if -P or --ts_plot have also been "
+ "specified.\n"
+ << endl;
+ do_exit = true;
+ }
+
+ if (!time_stamp_max_bins.empty() && !plot_time_stamp) {
+ cerr << "Max number of bins in the time graph can "
+ "only be used if -P or --ts_plot have also been "
+ "specified.\n"
+ << endl;
+ do_exit = true;
+ }
+
+ if (!time_stamp_start_time.empty() && !plot_time_stamp) {
+ cerr << "Time stamp start time can only be used if -P or "
+ "--ts_plot have also been specified.\n"
+ << endl;
+ do_exit = true;
+ }
+
+ if (!time_stamp_end_time.empty() && !plot_time_stamp) {
+ cerr << "Time stamp end time can only be used if -P or "
+ "--ts_plot have also been specified.\n"
+ << endl;
+ do_exit = true;
+ }

if (details && diff) {
cerr << "differential profiles are incompatible with --details" << endl;
@@ -315,6 +458,7 @@ void handle_options(options::spec const & spec)
merge_by = handle_merge_option(mergespec, true, exclude_dependent);
handle_output_file();
demangle = handle_demangle_option(demangle_option);
+ handle_time_stamp_options();
check_options(spec.first.size());

symbol_filter = string_filter(include_symbols, exclude_symbols);
diff --git a/pp/opreport_options.h b/pp/opreport_options.h
index 51ab7a6..6b7621f 100644
--- a/pp/opreport_options.h
+++ b/pp/opreport_options.h
@@ -27,6 +27,7 @@ namespace options {
extern demangle_type demangle;
extern bool symbols;
extern bool callgraph;
+ extern bool enable_timestamps;
extern bool debug_info;
extern bool details;
extern bool reverse_sort;
@@ -39,8 +40,10 @@ namespace options {
extern string_filter symbol_filter;
extern bool show_header;
extern bool accumulated;
+ extern bool plot_time_stamp;
extern bool xml;
extern std::string xml_options;
+ extern std::string time_stamp_options;
}

/// All the chosen sample files.
@@ -55,4 +58,5 @@ extern profile_classes classes2;
*/
void handle_options(options::spec const & spec);

+#define DEFAULT_OPREPORT_XML_NAME "opreport.xml"
#endif // OPREPORT_OPTIONS_H
--
1.7.1




------------------------------------------------------------------------------
William Cohen
2015-11-18 03:05:14 UTC
Permalink
Raw Message
Post by Carl E. Love
Updated version 2, Add time stamp collection to operf, report time stamps in XML output
This patch adds a command line option to operf to collect timestamp data
for each sample. The time stamps are printed to the various oprofile data
files.
The opreport command also has a command line option added. This option
will print the time stamp data in the XML output file for each sample. If
the -d option is used the time stamps will also be printed for each
instruct in the detailed XML output file.
The initial version of the patch had some issues supporting the printing
of the time stamps on multiple events. Thes have been fixed in this
version.
Fixed an issue where there were duplicate entries for the-T option. The
second one was removed. The variable that it set was not used.
Add support to opreport to call graphing scripts
Hi Carl,

It is taking some time to look over the 3000 lines worth of patches.

I used ran the linux kernel's checkpatch.pl and the
oprofile-tests/check_style.py scripts over the patches. There are a
number of places with trailing whitespace that should be elminated
from the patches.

Some printf in the patches don't work on 32-bit processors and need to be made portable:

make[3]: Entering directory '/builddir/build/BUILD/oprofile-1.2.0git/libdb'
gcc -DHAVE_CONFIG_H -I. -I.. -I ../libop -I ../libutil -W -Wall -fno-common -Wdeclaration-after-statement -Werror -O2 -g -pipe -Wall -Werror=format-security -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector-strong --param=ssp-buffer-size=4 -grecord-gcc-switches -specs=/usr/lib/rpm/redhat/redhat-hardened-cc1 -m32 -march=i686 -mtune=atom -fasynchronous-unwind-tables -c -o db_manage.o db_manage.c
db_manage.c: In function 'read_timestamp':
db_manage.c:311:20: error: format '%ld' expects argument of type 'long int', but argument 3 has type 'uint64_t {aka long long unsigned int}' [-Werror=format=]
fprintf(stderr, "ERROR, failed to read enough bytes for "
^
db_manage.c: In function 'odb_write_timestamps':
db_manage.c:419:20: error: format '%lu' expects argument of type 'long unsigned int', but argument 4 has type 'size_t {aka unsigned int}' [-Werror=format=]
fprintf(stderr, "WARNING: missing time stamps "
^
cc1: all warnings being treated as errors



The patches apply cleanly to the current git repository. However,
when trying to build a Fedora RPM I got an error about an unchecked
return value:

Making all in pp
make[2]: Entering directory '/home/wcohen/rpmbuild/BUILD/oprofile-1.2.0git/pp'
g++ -DHAVE_CONFIG_H -I. -I.. -I ../libop -I ../libutil -I ../libdb -I ../libopt++ -I ../libutil++ -I ../libregex -I ../libpp -W -Wall -fno-common -ftemplate-depth-50 -Werror -O2 -g -pipe -Wall -Werror=format-security -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector-strong --param=ssp-buffer-size=4 -grecord-gcc-switches -m64 -mtune=generic -c -o opreport.o opreport.cpp
opreport.cpp: In function 'int {anonymous}::opreport(const options::spec&)':
opreport.cpp:601:46: error: ignoring return value of 'int system(const char*)', declared with attribute warn_unused_result [-Werror=unused-result]
system(options::time_stamp_options.c_str());
^
cc1plus: all warnings being treated as errors


Should the code be throwing a error if the system() command returns a
non-zero value? Something like the patch is the scratchbuild at:

http://koji.fedoraproject.org/koji/taskinfo?taskID=11888018


Is the following statement in opreport.pp leftover from debugging:

cout << "CARLL COMMAND = " << options::time_stamp_options
<< endl;


A run of the oprofile rpm with the patches through coverity looks good
(no additional coverity errors)

There are going to be some machine such as embedded platforms where
gnuplot may not be available or not installed. Has the code been
verified to handle this case in a reasonable manner?

Rather than writing out postscript would it make more sense to generate SVG?
Most webbrowsers can read SVG file directly.

In the doc/plot_time_stamps.1.in shouldn't the synopsis be
plot_time_stamps.sh rather than process_time_stamps.sh. There isn't a
process_time_stamps.sh command (there is a process_time_stamps.prl
file).

If the opreport -T option must be used with used with --xml, why not
force setting the --xml when -T is used?

When running the example "opreport -X -T -P" the process cored after
putting up the plot probably should eliminate the diagnostic messages
in plot_time_stamps.sh:

--------
$ opreport -X -T -P
Using /home/wcohen/rpmbuild/SPECS/oprofile_data/samples/ for samples directory.
warning: /dm_crypt could not be found.
warning: /e1000e could not be found.
warning: /iptable_mangle could not be found.
warning: /kvm could not be found.
warning: /nf_conntrack could not be found.
warning: /nf_conntrack_ipv4 could not be found.
warning: /nf_nat could not be found.
warning: /nouveau could not be found.
warning: /xt_conntrack could not be found.

Processing XML time stamp data from file opreport.xml...

Done processing XML time stamp data.

Calling gnuplot to create postscript file. Output file is: time_stamp_plot.ps .


set mytics 0
^
"./workload_tm_cmd.plt", line 9: warning: Expecting number of intervals
Calling xdg-open to open the postscript file time_stamp_plot.ps .

Segmentation fault (core dumped)
--------

The followin are defined in both libop/tm_array.h and
libop/op_config.h. probably should just be in libop/tm_array.h:

+#define EMPTY_TM_ARRAY ~0x0ULL
+#define VALID_TM_ARRAY_END 0xA5A5A5A55A5A5A5AULL

--------

Should libdb/db_manage.c only be including tm_array.h?

--------

It looks like DEFAULT_OPREPORT_XML_NAME opreport.xml is always being
used for in handle_time_stamp_options. Should it be using some sort of
temporary file or allow selecting the file name (-o) being written out
if plot being generated directly from opreport?


------------------

plot_time_stamps.sh always uses process_time_stamps.out as a temporary
file when running process_time_stamps.prl. Should plot_time_stamps.sh
be using some temporary file instead? Same for workload_tm_data.gpi
and workload_tm_cmd.plt?

plot_time_stamps.sh always calls xdg-open if xdg-open is on the
system. If someone is running plot_time_stamps.sh with --ps_file,
they probably don't want to have a window pop up on the screen.


-Will

------------------------------------------------------------------------------
Carl E. Love
2015-11-18 16:32:15 UTC
Permalink
Raw Message
Post by William Cohen
There are going to be some machine such as embedded platforms where
gnuplot may not be available or not installed. Has the code been
verified to handle this case in a reasonable manner?
Rather than writing out postscript would it make more sense to
generate SVG?
Most webbrowsers can read SVG file directly.
Will:

Thanks for looking at the patch. Yes, it is really big so no worries on
it taking a long time. It is best to take the time and carefully check
it out.

The original project was to just add the time stamps to the XML output.
Then within IBM we had people kicking around ideas on how best to
display the data. So, I did the perl script and GNU plot as a quick
"proof of concept" to explore different ways of looking at the data. I
got a lot of positive feedback on the plots. So then in the internal
reviews of the time stamp support patch, I got pushed to formalize and
include the scripts and integrate it into the tools. That really wasn't
the initial goal for the plotting scripts. Similarly, you had
suggestions of having the scripts called directly by opreport. The
bottom line is gnuplot/postscript was used just because I know them and
could quickly generate them. I am not familar with SVG but I can go
look at it.

No, there wasn't any thought given to embedded platforms. Again, the
issue is the plotting support "evolved" rather then being a well thought
out deliverable and well designed from the start. I hate to admit it
but that is the truth of the matter. :-)

Thanks for the feed back. I will work on fixing the bug and issues you
found. I will take a look at SVG to see how that could be used.
Fundamentally, removing the dependency on gnuplot would be desirable.

Carl Love


------------------------------------------------------------------------------
Carl E. Love
2016-03-23 16:02:31 UTC
Permalink
Raw Message
Will:

Sorry for the long time in getting these patches updated. Your comments
of version 2 are below. I believe that I have addressed all of the
comments. The most significant being the use of gnuplot. You suggested
drawing the graphs using SVG instead. I wrote a new C program that
takes the data from the perl script that extracts the data from the
OProfile XML output file and draws the graphs using SVG. This is really
the most significant change to the patches. The other comments required
relatively small changes.

I have tested opening the SVG graph file on a few different platforms
and browsers. I tested it using Mozilla Firefox on a RedHat linux 7.2
distribution, on Mozilla Firefox and Chrome on a current Mac Air machine
and on Mozilla, Chrome and IE on an old Window Vista box, Mozilla
Firefox on a Windows XP machine. The all of the browsers on these
machines were able to properly open and display graphs correctly.

Please let me know if you see any issues that need additional work.
Thank you.

No rush, I know these are rather large patches to be reviewed.

Carl Love
Post by Ramya Shivalingamurthy -X (rshivali - INFOSYS LIMITED at Cisco)
Hi Carl,
It is taking some time to look over the 3000 lines worth of patches.
I used ran the linux kernel's checkpatch.pl and the
oprofile-tests/check_style.py scripts over the patches. There are a
number of places with trailing whitespace that should be elminated
from the patches.
make[3]: Entering directory
'/builddir/build/BUILD/oprofile-1.2.0git/libdb'
gcc -DHAVE_CONFIG_H -I. -I.. -I ../libop -I ../libutil -W -Wall
-fno-common -Wdeclaration-after-statement -Werror -O2 -g -pipe -Wall
-Werror=format-security -Wp,-D_FORTIFY_SOURCE=2 -fexceptions
-fstack-protector-strong --param=ssp-buffer-size=4
-grecord-gcc-switches -specs=/usr/lib/rpm/redhat/redhat-hardened-cc1
-m32 -march=i686 -mtune=atom -fasynchronous-unwind-tables -c -o
db_manage.o db_manage.c
db_manage.c:311:20: error: format '%ld' expects argument of type 'long
int', but argument 3 has type 'uint64_t {aka long long unsigned
int}' [-Werror=format=]
fprintf(stderr, "ERROR, failed to read enough bytes for "
^
db_manage.c:419:20: error: format '%lu' expects argument of type 'long
unsigned int', but argument 4 has type 'size_t {aka unsigned
int}' [-Werror=format=]
fprintf(stderr, "WARNING: missing time stamps "
^
cc1: all warnings being treated as errors
The patches apply cleanly to the current git repository. However,
when trying to build a Fedora RPM I got an error about an unchecked
Making all in pp
make[2]: Entering directory
'/home/wcohen/rpmbuild/BUILD/oprofile-1.2.0git/pp'
g++ -DHAVE_CONFIG_H -I. -I.. -I ../libop -I ../libutil -I ../libdb
-I ../libopt++ -I ../libutil++ -I ../libregex -I ../libpp -W -Wall
-fno-common -ftemplate-depth-50 -Werror -O2 -g -pipe -Wall
-Werror=format-security -Wp,-D_FORTIFY_SOURCE=2 -fexceptions
-fstack-protector-strong --param=ssp-buffer-size=4
-grecord-gcc-switches -m64 -mtune=generic -c -o opreport.o
opreport.cpp
opreport.cpp: In function 'int {anonymous}::opreport(const
opreport.cpp:601:46: error: ignoring return value of 'int system(const
char*)', declared with attribute warn_unused_result
[-Werror=unused-result]
system(options::time_stamp_options.c_str());
^
cc1plus: all warnings being treated as errors
Should the code be throwing a error if the system() command returns a
http://koji.fedoraproject.org/koji/taskinfo?taskID=11888018
cout << "CARLL COMMAND = " <<
options::time_stamp_options
<< endl;
A run of the oprofile rpm with the patches through coverity looks good
(no additional coverity errors)
There are going to be some machine such as embedded platforms where
gnuplot may not be available or not installed. Has the code been
verified to handle this case in a reasonable manner?
Rather than writing out postscript would it make more sense to
generate SVG?
Most webbrowsers can read SVG file directly.
In the doc/plot_time_stamps.1.in shouldn't the synopsis be
plot_time_stamps.sh rather than process_time_stamps.sh. There isn't a
process_time_stamps.sh command (there is a process_time_stamps.prl
file).
If the opreport -T option must be used with used with --xml, why not
force setting the --xml when -T is used?
When running the example "opreport -X -T -P" the process cored after
putting up the plot probably should eliminate the diagnostic messages
--------
$ opreport -X -T -P
Using /home/wcohen/rpmbuild/SPECS/oprofile_data/samples/ for samples directory.
warning: /dm_crypt could not be found.
warning: /e1000e could not be found.
warning: /iptable_mangle could not be found.
warning: /kvm could not be found.
warning: /nf_conntrack could not be found.
warning: /nf_conntrack_ipv4 could not be found.
warning: /nf_nat could not be found.
warning: /nouveau could not be found.
warning: /xt_conntrack could not be found.
Processing XML time stamp data from file opreport.xml...
Done processing XML time stamp data.
time_stamp_plot.ps .
set mytics 0
^
"./workload_tm_cmd.plt", line 9: warning: Expecting number of
intervals
Calling xdg-open to open the postscript file time_stamp_plot.ps .
Segmentation fault (core dumped)
--------
The followin are defined in both libop/tm_array.h and
+#define EMPTY_TM_ARRAY ~0x0ULL
+#define VALID_TM_ARRAY_END 0xA5A5A5A55A5A5A5AULL
--------
Should libdb/db_manage.c only be including tm_array.h?
--------
It looks like DEFAULT_OPREPORT_XML_NAME opreport.xml is always being
used for in handle_time_stamp_options. Should it be using some sort of
temporary file or allow selecting the file name (-o) being written out
if plot being generated directly from opreport?
------------------
plot_time_stamps.sh always uses process_time_stamps.out as a temporary
file when running process_time_stamps.prl. Should plot_time_stamps.sh
be using some temporary file instead? Same for workload_tm_data.gpi
and workload_tm_cmd.plt?
plot_time_stamps.sh always calls xdg-open if xdg-open is on the
system. If someone is running plot_time_stamps.sh with --ps_file,
they probably don't want to have a window pop up on the screen.
-Will
Carl E. Love
2015-10-22 23:22:58 UTC
Permalink
Raw Message
Updated version 2, OProfile Time stamp processing support

This patch adds two scripts for processing and plotting the time stamp
data collected by operf. The primary script is in utils/plot_time_stamps.sh
This script calls the perl script utils/processs_time_stamps.prl that does
the majority of the data processing.

The first version only supported plotting the time stamps for a profile
collected on a single event. This version adds support for plotting the
events when collecting multiple events at a time. It also includes some
fixes for issues in the original patch found while adding the multiple
event plotting support.

Signed-off-by: Carl Love <***@us.ibm.com>
---
configure.ac | 1 +
doc/Makefile.am | 3 +-
doc/plot_time_stamps.1.in | 85 ++++
pp/opreport_options.cpp | 5 +
utils/Makefile.am | 2 +
utils/plot_time_stamps.sh | 225 ++++++++++
utils/process_time_stamps.prl | 929 +++++++++++++++++++++++++++++++++++++++++
7 files changed, 1249 insertions(+), 1 deletions(-)
create mode 100644 doc/plot_time_stamps.1.in
create mode 100644 utils/plot_time_stamps.sh
create mode 100644 utils/process_time_stamps.prl

diff --git a/configure.ac b/configure.ac
index 72b1515..201a535 100644
--- a/configure.ac
+++ b/configure.ac
@@ -426,6 +426,7 @@ AC_OUTPUT(Makefile \
doc/opimport.1 \
doc/operf.1 \
doc/ocount.1 \
+ doc/plot_time_stamps.1 \
doc/srcdoc/Doxyfile \
libpp/Makefile \
opjitconv/Makefile \
diff --git a/doc/Makefile.am b/doc/Makefile.am
index 43a7781..9a87835 100644
--- a/doc/Makefile.am
+++ b/doc/Makefile.am
@@ -20,7 +20,8 @@ man_MANS = \

if BUILD_FOR_PERF_EVENT
man_MANS += operf.1 \
- ocount.1
+ ocount.1 \
+ plot_time_stamps.1
endif

htmldir = $(prefix)/share/doc/oprofile
diff --git a/doc/plot_time_stamps.1.in b/doc/plot_time_stamps.1.in
new file mode 100644
index 0000000..909228a
--- /dev/null
+++ b/doc/plot_time_stamps.1.in
@@ -0,0 +1,85 @@
+.\" Manpage for operf
+.\" Author: Carl Love <***@us.ibm.com>
+.\" Modifications:
+.TH OPERF 1 "@DATE@" "timestamp processing @VERSION@"
+.SH NAME
+plot_time_stamps.sh \- Script to process and plot time stamp data.
+
+.SH SYNOPSIS
+.B process_time_stamps.sh
+[
+.I options
+]
+[ -f | -l | -b | -s | -e | -m | -S | -p | --xml_file | --line_graph | --bar_graph | --start_time | --end_time | --max_bins | --max_symbols | --ps_file | --help]
+
+
+.SH DESCRIPTION
+OProfile can produce an XML output file that contains the time stamp for each sample. This script
+is used to process the time stamp data and display it in a bar or line graph format. The graph can show
+all of the symbols combined or show the top N symbols individually. The value of N can be specified by a
+command line argument. Each point (bar) on the graph is for a given period of time, referred to as
+a bin. The width of the bin and the number of bins can be set as command line options. The user
+may specify the name of the output postscript file containing the graph.
+
+This is a shell script which calls an additional script and applications to generate and display the
+graph. The bulk of the data processing is done by a perl script process_time_stamps.prl which is part
+of the OProfile package. This script calls gnuplot and xdg-open. Both applications are assumed to
+be installed.
+.P
+
+.TP
+.BI "-f / --xml_file " XML_file_name
+This option allows the user to specify the OProfile XML input file con the time stamp data. This is a
+required entry.
+
+.TP
+.BI "-p / --ps_file " ps_file_name
+This option allows the user to specify the name of the postscript file containing the graph. By default
+the graph is put into file workload_tm_data.ps.
+
+.TP
+.BI " -l / --line_graph"
+This option specifies the data is to be plotted as a line graph. This is the default for plotting the data.
+The user can specify either line graph or bar graph but not both.
+.TP
+.BI " -b / --bar_graph"
+This option specifies the data is to be plotted as a bar graph.
+The user can specify either line graph or bar graph but not both.
+.TP
+
+.BI " -s / --start_time " start_time
+This option allows the user to plot a portion of the time stamps starting at the specified time.
+
+.TP
+.BI " -e / --stop_time " end_time
+This option allows the user to plot a portion of the time stamps ending at the specified time.
+
+.TP
+.BI " -m / --max_bins " number_of_bins
+This option allows the user to adjust the number of bins in the graph. The default is 200 bins.
+
+.TP
+.BI " -S / --max_symbols " max_number_symbols
+This option allows the user to adjust the number of symbols displayed or plot all symbols combined.
+An input value of zero specifies combine all symbols into a single plot. A positive nonzero value,
+N, will plot the N symbols with the most time stamps. All other symbols are combined into symbol
+"other".
+
+.TP
+.BI "--help / -h"
+Display brief usage help message.
+.br
+.RE
+
+.TP
+
+.SH EXAMPLE
+Typical OProfile data collection and processing to create the input XML data file.
+
+ operf -T -e CPU_CLK_UNHALTED:100000 <your workload>
+ opreport -T -X > opreport-out
+
+Process and display the time stamp data.
+
+ plot_time_stamps.sh -f opreport-out
+
diff --git a/pp/opreport_options.cpp b/pp/opreport_options.cpp
index 249a883..7c57fca 100644
--- a/pp/opreport_options.cpp
+++ b/pp/opreport_options.cpp
@@ -211,6 +211,11 @@ void handle_time_stamp_options()
options::time_stamp_options.append(" --start_time ");
options::time_stamp_options.append(time_stamp_start_time);
}
+
+ if (!time_stamp_end_time.empty()) {
+ options::time_stamp_options.append(" --end_time ");
+ options::time_stamp_options.append(time_stamp_end_time);
+ }
}

void handle_output_file()
diff --git a/utils/Makefile.am b/utils/Makefile.am
index 408dc54..65d8c45 100644
--- a/utils/Makefile.am
+++ b/utils/Makefile.am
@@ -9,6 +9,8 @@ LIBS=@POPT_LIBS@ @LIBERTY_LIBS@

bin_PROGRAMS = ophelp op-check-perfevents

+bin_SCRIPTS = plot_time_stamps.sh process_time_stamps.prl
+
op_check_perfevents_SOURCES = op_perf_events_checker.c
op_check_perfevents_CPPFLAGS = ${AM_CFLAGS} @PERF_EVENT_FLAGS@

diff --git a/utils/plot_time_stamps.sh b/utils/plot_time_stamps.sh
new file mode 100644
index 0000000..2911637
--- /dev/null
+++ b/utils/plot_time_stamps.sh
@@ -0,0 +1,225 @@
+#!/bin/sh
+
+# This script takes the name of the OProfile XML output file containing
+# the time stamp data as input. This script calls the perl script
+# utils/process_time_stamps.prl to generate the data and command files
+# needed by gnu plot to plot the time stamp data. This script then
+# invokes gnu plot to display the graph. Finally, the script will invoke
+# xdg-open to display the graph.
+#
+# This script passes the needed options to utils/process_time_stamps.prl
+# if the user specifies any.
+#
+# The OProfile xml file is typically created by running operf and opreport
+# with the -T option. The -T tells operf and opreport to collect and process
+# the time stamp data. The call to opreport must also have the -X option
+# specified to generate the output in xml format.
+#
+# example run:
+#
+# operf -T -e CPU_CLK_UNHALTED:100000 <your workload>
+# opreport -T -X > opreport-out
+# plot_time_stamps.sh -f opreport-out
+#
+# Copyright 2015 OProfile authors
+# Read the file COPYING
+#
+# Created on: Sept. 25, 2015
+# Author Carl Love ***@us.ibm.com
+# (C) Copyright IBM Corp. 2015
+#
+#--------------------------------------------------------------
+
+# Check that the required applications are installed.
+#
+# Check to see if perl is installed
+if ! perl --version > /dev/null 2>&1 ; then
+ echo " "
+ echo " This utility requires perl to process the timestamps."
+ echo " Please install perl and try again. Exiting."
+ echo " "
+ exit
+fi
+
+# Check to see if gnuplot is installed
+if ! gnuplot --version > /dev/null 2>&1 ; then
+ echo " "
+ echo " This utility requires gnuplot to generate the timestamp plot."
+ echo " Please install gnuplot and try again. Exiting."
+ echo " "
+ exit
+fi
+
+# Check to see if xdg-open is installed
+
+if xdg-open --version > /dev/null 2>&1 ; then
+ have_xdg_open="1";
+else
+ have_xdg_open="";
+ echo " "
+ echo " This utility uses xdg-open to display the postscript plot of the data."
+ echo " The postscript file with the plot will be generated but you will"
+ echo " need to open it manually. Install xdg-open if you would like "
+ echo " this utility to automatically display the graph for you."
+ echo " "
+fi
+
+
+#
+function usage
+{
+echo " -f | --xml_file XML input file with the time stamps"
+echo " -l | --line_graph generate a line graph of the time stamps within each bin"
+echo " -b | --bar_graph generate a bar graph of the time stamps within each bin"
+echo " -s | --start_time start plot time, default first time stamp"
+echo " -e | --end_time end plot time, default last time stamp"
+echo " -m | --max_bins number of intervals to be plotted"
+echo " -S | --max_symbols maximum number of symbols to plot, default is "
+echo " -p | --ps_file Output file name for the generate postscript plot"
+echo " zero which prints all symbols combined. A "
+echo " non-zero value will graph each of the top N "
+echo " symbols individually"
+echo " -h | --help print this help guide "
+
+}
+
+xml_input_filename=
+ps_output_filename="time_stamp_plot.ps"
+
+while [ "$1" != "" ]; do
+ case $1 in
+ -f | --xml_file ) shift
+ xml_input_filename=$1 ;;
+
+ -L | --line_graph ) line_graph=1 ;;
+
+ -B | --bar_graph ) bar_graph=1 ;;
+
+ -S | --start_time ) shift
+ start_time=$1 ;;
+
+ -E | --end_time ) shift
+ end_time=$1 ;;
+
+ -b | --max_bins ) shift
+ max_bins=$1 ;;
+
+ -M | --max_symbols ) shift
+ print_symbols=$1 ;;
+
+ -F | --ps_file ) shift
+ ps_output_filename=$1 ;;
+
+ -h | --help ) usage
+ exit
+ ;;
+ * ) echo "plot_time_stamps.sh: Command line argument $1 is not valid"
+ usage
+ exit 1
+ esac
+ shift
+done
+
+# Check the options, input file name is required
+if [ -z $xml_input_filename ]; then
+ echo " "
+ echo "Error: XML input file name not specified. A file name is required.";
+ echo " "
+ exit;
+fi
+
+if [ ! -z $bar_graph ] && [ ! -z $line_graph ]; then
+ echo " "
+ echo "Error: specify line_graph or bar_graph but not both.";
+ echo " "
+ exit;
+fi
+
+# Setup command line for utils/process_time_stamps.prl
+#command=" -debug ";
+command="";
+
+if [ ! -z $line_graph ]; then
+ command="$command -line_graph "
+fi
+
+if [ ! -z $bar_graph ]; then
+ command="$command -bar_graph "
+fi
+
+if [ ! -z $start_time ]; then
+ command="$command -start_time=$start_time "
+fi
+
+if [ ! -z $end_time ]; then
+ command="$command -end_time=$end_time "
+fi
+
+if [ ! -z $max_bins ]; then
+ command="$command -max_bins=$max_bins "
+fi
+
+if [ ! -z $print_symbols ]; then
+ command="$command -max_symbols=$print_symbols "
+fi
+
+if [ ! -z $ps_output_filename ]; then
+ command="$command -ps_output_file=$ps_output_filename "
+fi
+
+# call the perl script to process the data. Note, we will let the perl
+# script use the default gnu plot command and data files but pass it the
+# user's specified postscript file name if specified.
+
+echo " "
+echo " Processing XML time stamp data from file $xml_input_filename... "
+echo " "
+
+process_time_stamps.prl $command < $xml_input_filename > process_time_stamps.out
+
+# Check that the perl script succeeded
+if [ ! $? ]; then
+ echo " "
+ echo " ERROR: perl script failed. Exiting...."
+ exit
+fi
+
+echo " Done processing XML time stamp data."
+echo " "
+
+# call gnuplot to generate the post script file containing the plot.
+echo " Calling gnuplot to create postscript file. Output file is: " $ps_output_filename "."
+echo " "
+
+# command file default
+workload_tm_cmd="workload_tm_cmd.plt"
+gnuplot ./$workload_tm_cmd
+
+# Check that gnuplot succeeded
+if [ ! $? ]; then
+ echo " "
+ echo " ERROR: call to gnuplot failed. Exiting...."
+ exit
+fi
+
+# remove files no longer needed from the processing of the XML files
+rm $xml_input_filename process_time_stamps.out workload_tm_data.gpi workload_tm_cmd.plt
+
+if [ $have_xdg_open ]; then
+ echo " Calling xdg-open to open the postscript file " $ps_output_filename "."
+ echo " "
+
+ xdg-open $ps_output_filename
+
+# Check that the call to xdg-open succeeded
+ if [ ! $? ]; then
+ echo " "
+ echo " ERROR: all to xdg-open failed. Exiting...."
+ echo " "
+ exit
+ fi
+else
+ echo " The histogram plot was generated. It is in file $ps_output_filename"
+ echo " Please open manually."
+ echo " "
+fi
\ No newline at end of file
diff --git a/utils/process_time_stamps.prl b/utils/process_time_stamps.prl
new file mode 100644
index 0000000..a3d76f1
--- /dev/null
+++ b/utils/process_time_stamps.prl
@@ -0,0 +1,929 @@
+#!/usr/bin/perl
+#
+# process_time_stamps.prl
+#
+# This script reads an OProfile xml output file and generates a gnu-plot
+# command and data file.
+#
+# The OProfile xml file is typically created by running operf and opreport
+# with the -T option. The -T tells operf and opreport to collect and process
+# the time stamp data. The call to opreport must also have the -X option
+# specified to generate the output in xml format.
+#
+# example run:
+#
+# operf -T -e CPU_CLK_UNHALTED:100000 <your workload>
+# opreport -T -X > opreport-out
+# plot_time_stamps.sh -f opreport-out
+#
+# Copyright 2015 OProfile authors
+# Read the file COPYING
+#
+# Created on: Sept. 25, 2015
+# Author Carl Love ***@us.ibm.com
+# (C) Copyright IBM Corp. 2015
+#
+use strict;
+use Getopt::Long qw(GetOptions);
+
+###########################
+#main
+my $DATA_SEPARATOR = "\t ";
+
+# Default name for the generated data file to pass to gnuplot
+my $GNU_PLOT_DEFAULT_OUTPUT_DATA_FILE = "workload_tm_data.gpi";
+
+# Default name for the gnuplot command file
+my $GNU_PLOT_DEFAULT_OUTPUT_COMMAND_FILE = "workload_tm_cmd.plt";
+
+#default name for the output postscript file containing the plot
+my $PS_DEFAULT_OUTPUT_FILE = "workload_tm_data.ps";
+
+# Command line options
+# -debug enable debug prints
+
+# -start_time Beginning of time to display, default beginning of
+# data.
+# -end_time End of time to display, default end of data.
+#
+# -gnu_plot_data_file File name for the generated data file containing
+# the data to be plotted by gnu plot.
+#
+# -gnu_plot_cmd_file File name for the generated command file to input to
+# gnu plot.
+#
+# -ps_output_file Postscript output file name for the gnu plot
+#
+# -print_symbol_threshold 0 - combine all symbol time stamps in a single data set.
+# if greater then zero, display the top N symbols where
+# N is the argument of symbol_threshold
+
+# Process the command line arguments
+#
+my $debug = 0;
+my $usr_start_time = 0;
+my $usr_end_time = -1;
+my $line_graph = 0;
+my $bar_graph = 0;
+my $max_bins = 200;
+my $gnu_plot_data_file = $GNU_PLOT_DEFAULT_OUTPUT_DATA_FILE;
+my $gnu_plot_cmd_file = $GNU_PLOT_DEFAULT_OUTPUT_COMMAND_FILE;
+my $ps_output_file = $PS_DEFAULT_OUTPUT_FILE;
+my $print_symbol_threshold = 0;
+
+GetOptions (
+ 'debug!' => \$debug,
+ 'start_time=s' => \$usr_start_time,
+ 'end_time=s' => \$usr_end_time,
+ 'line_graph!' => \$line_graph,
+ 'bar_graph!' => \$bar_graph,
+ 'max_bins=s' => \$max_bins,
+ 'max_symbols=s' => \$print_symbol_threshold,
+ 'gnu_plot_data_file=s' => \$gnu_plot_data_file,
+ 'gnu_plot_cmd_file=s' => \$gnu_plot_cmd_file,
+ 'ps_output_file=s' => \$ps_output_file,
+ ) or die "Unknown command line option\n";
+
+
+if ($debug) {
+ printf " process_time_stamps.prl, Command line argument settings are: \n";
+ printf " debug = $debug \n";
+ printf " start_time = $usr_start_time \n";
+ printf " end_time = $usr_end_time \n";
+ printf " line_graph = $line_graph \n";
+ printf " bar_graph = $bar_graph \n";
+ printf " max_symbols = $max_bins \n";
+ printf " max_bins = $max_bins \n";
+ printf " ps_output_file = $ps_output_file \n";
+}
+
+## Check command line argument
+if ($line_graph && $bar_graph) {
+ die "Error, cannot specify both line and bar graph styles.\n";
+}
+if (!$line_graph && !$bar_graph) {
+ # must specify line_graph or bar_graph
+ $line_graph=1;
+}
+
+if ($max_bins < 0) {
+ die "The number of bins for the bar graph style must be positive.\n"
+}
+
+my $num_symbols = 0;
+my $found_tm = 0;
+my $found_symbol = 0;
+my $min_tm = -1;
+my $max_tm = -1;
+
+my ($i, $j, $k, $n, $print_rank, $data_column, $bin_width);
+my ($end_time, $max_bin_count, $sum, $x_coordinate, $bin_time, $value);
+my ($all_symbols, $print_symbol, $name, $id_name, $rank, $delta);
+my ($symb_min_tm, $symb_max_tm, $top_index, $top_count, $slice_num);
+my ($offset, $start_time, $end_time);
+my (@sym_name, @sym_rank, @bin_count, @tm_array, @fields, @count, @fields);
+my (@symbol_max_tm, @symbol_min_tm, @subfields);
+
+my (@classes, $found_classes, $ev_num, $ev_number, $class_name, @class_mapping, $element);
+my ($max_events, @event_name, $name, $pr_color);
+### Global data
+my $included_count = 0;
+my $excluded_count = 0;
+
+##############################
+### get data
+&read_xml_file($num_symbols, $min_tm, $max_tm, @count, @sym_name, @sym_rank, @tm_array, @symbol_min_tm, @symbol_max_tm);
+
+# Size of class_mapping is the number of events in the data set.
+# When the data set consits of a single event, there is no event
+# to class mapping. This results in the size of class_mapping
+# being set to-1.
+if ($#class_mapping == -1) {
+ $max_events = 1;
+} else {
+ $max_events = $#class_mapping + 1;
+}
+
+## Enable debuging the parsing of the data file
+if ($debug) {
+ &debug_print_extracted_data();
+}
+
+######################################
+
+### Display symbols
+# 0 - Collapse all symbol data into a single line
+# 3 - Show time stamps for symbols counts in the top N
+
+##############################################
+### SET the graph start/end time
+
+
+### Setup to display the time range. The assumption is that the
+# user is inputting an adjusted start/end time based on a
+# previously viewed graph.
+
+if ($usr_start_time <= 0) {
+ $start_time = $min_tm;
+} else {
+ $start_time = $usr_start_time + $min_tm;
+}
+
+print "USER start time = $usr_start_time\n";
+print "USER input stop time = $usr_end_time\n";
+print "MAX TIME = $max_tm\n";
+
+if ($usr_end_time == -1) {
+ $end_time = $max_tm;
+} elsif ($usr_end_time < ($max_tm -$min_tm)) {
+ $end_time = $usr_end_time + $min_tm;
+ printf "SET END_TIME TO UNNORMALIZED USR END TIME, $end_time\n";
+} else {
+ $end_time = $max_tm;
+}
+$bin_width = ($end_time - $start_time) / $max_bins;
+
+if ($debug) {
+ print "Display_window = 1, Initial, min_tm = $min_tm, max_tm = $max_tm\n";
+ print "Display_window = 1, start_time = $start_time, end_time = $end_time\n";
+ print "print_symbol_threshold = $print_symbol_threshold \n";
+ print "gnu_plot_data_file = $gnu_plot_data_file\n";
+ print "gnu_plot_cmd_file = $gnu_plot_cmd_file\n";
+ print "ps_output_file = $ps_output_file\n";
+ print "line_graph = $line_graph\n";
+ print "bar_graph = $bar_graph\n";
+ print "user start time = $usr_start_time\n";
+ print "user end time = $usr_end_time\n";
+}
+print "user start time = $usr_start_time\n";
+print "user end time = $usr_end_time\n";
+print "start time = $start_time\n";
+print "end time = $end_time\n";
+
+#################################################
+# currently not supporting the &print_dot_plot_script_file but
+# the routine is still included if desired to support again
+# in the future.
+
+$ev_number = 0;
+if ($line_graph == 1) {
+ &print_bin_line_plot_script_file();
+ &print_bin_data_file_for_plot();
+} elsif ($bar_graph == 1) {
+ &print_bin_hist_plot_script_file();
+ &print_bin_data_file_for_plot();
+} else {
+ print "ERROR, unknown value of graph style\n";
+}
+
+################################
+
+#print "Slice size = ", $slice_size, "\n";
+print "Start time = ", $start_time, "\n";
+print "bin width = ", $bin_width, "\n";
+print "End time = ", $end_time, "\n";
+
+
+&print_timestamp_range_for_symbols();
+
+###################### End of main
+
+
+#### subroutines #############################################
+
+sub get_class_event_number {
+ $i = 0;
+
+ while( $i <= $#class_mapping)
+ {
+ # check passed name
+ if ($_[0] eq $class_mapping[$i]) {
+ return $i;
+ }
+ $i = $i + 1;
+ }
+# In the case of a data set with a single event, there will
+# not be a class mapping. Return 0 for the event.
+ return 0;
+}
+
+sub generate_symbol_rank (@sym_rank) {
+ #initialize the rank for all symbols and events
+ for ($n = 0; $n < $max_events; $n = $n + 1) {
+ for ($i = 0; $i <= $num_symbols; $i = $i + 1) {
+ $sym_rank[$n][$i] = 0;
+ }
+ }
+
+ for ($n = 0; $n < $max_events; $n = $n + 1) {
+ # go through the list of symbols and assign the rank of 1 to
+ # num_symbols where the symbol with the highest count is 1,
+ # the next highest is 2,...
+ $rank = 1;
+
+ for ($i = 0; $i < $num_symbols; $i = $i + 1) {
+ $top_index = -1;
+ $top_count = 0;
+ for ($j = 0; $j < $num_symbols; $j = $j + 1) {
+ if (($sym_rank[$n][$j] == 0) && ($top_index == -1)) {
+ $top_index = $j;
+ $top_count = $count[$n][$j];
+ } elsif (($count[$n][$j] > $top_count) && ($sym_rank[$n][$j] == 0)) {
+ $top_index = $j;
+ $top_count = $count[$n][$j];
+ }
+ }
+ $sym_rank[$n][$top_index] = $rank;
+ $rank = $rank + 1;
+ }
+ }
+
+ if ($debug) {
+ for ($n = 0; $n < $max_events; $n = $n + 1) {
+ for ($j = 0; $j < $num_symbols; $j = $j + 1) {
+ print "Event $n, Symbol $sym_name[$j], at rank $sym_rank[$n][$j], count $count[$n][$j].\n";
+ }
+ }
+ }
+}
+
+sub read_xml_file ($num_symbols, $min_tm, $max_tm, @count, @sym_name, @sym_rank, @tm_array, @symbol_min_tm, @symbol_max_tm) {
+# read the input
+
+ while(<>) {
+ # look for the symbol name
+ @fields = split(' ', $_);
+
+ if ($debug) {
+ print "LINE: $_\n";
+ }
+
+ if ($fields[0] eq "<symbol") {
+ @subfields = split('>', $fields[1]);
+# change " to ' otherwise it messes up my title string.
+ $name = $subfields[0];
+ $name=~ s/"/'/g;
+ $sym_name[$num_symbols] = $name;
+
+ $found_symbol = 1;
+ if ($debug) {
+ print "Found symbol number $num_symbols = $sym_name[$num_symbols] \n";
+ }
+ }
+
+ if ($fields[0] eq "</symbol>") {
+ $found_symbol = 0;
+ $num_symbols = $num_symbols + 1;
+ if ($debug) {
+ print "found </symbol>, num_symbols incremented to $num_symbols\n";
+ }
+ }
+
+ if ($fields[0] eq "<eventsetup") {
+ @subfields = split('"', $fields[1]);
+ $ev_num = $subfields[1];
+ @subfields = split('"', $fields[2]);
+ $name = $subfields[1];
+ $event_name[$ev_num] = $name;
+
+ if ($debug) {
+ print "found eventsetup ev_num = $ev_num, name = $name\n";
+ }
+ }
+
+ if ($found_classes == 1) {
+ if ($fields[0] eq "<class") { # form <class name="c0" event="0"/>
+ @subfields = split('"', $fields[1]);
+ $class_name = $subfields[1];
+ @subfields = split('"', $fields[2]);
+ $ev_num = $subfields[1];
+ $class_mapping[$ev_num] = $class_name;
+ print "Class $class_name Event $ev_num\n";
+ $name=~ s/"/'/g;
+ }
+ }
+
+ if ((($found_tm == 1) && ($found_symbol == 1))) {
+ # the entry may be <timestamp 0xfffff where the tag and data are
+ # the same line
+ $found_tm = 0;
+ if ($debug) {
+ print "Found time stamps, number TMs, event num $ev_num, $count[$ev_num][$num_symbols] \n";
+ }
+
+ if ($fields[0] =~ /\<timestamp/) {
+ # time stamps start in field 1 in this case
+ $offset = 1;
+ } else {
+ $offset = 0;
+ }
+
+ $symb_min_tm = -1;
+ $symb_max_tm = -1;
+
+ $i = 0;
+ while ( $fields[$i+$offset] ne "</timestamp>") {
+ $value = oct($fields[$i+$offset]);
+ if ($debug) {
+ print "TM value = $value\n";
+ }
+
+ if ($min_tm == -1) {
+ $min_tm = $value;
+ } elsif ($min_tm > $value) {
+ $min_tm = $value;
+ }
+
+ if ($max_tm == -1) {
+ $max_tm = $value;
+ } elsif ($max_tm < $value) {
+ $max_tm = $value;
+ }
+
+ if ($symb_min_tm == -1) {
+ $symb_min_tm = $value;
+ } elsif ($symb_min_tm > $value) {
+ $symb_min_tm = $value;
+ }
+
+ if ($symb_max_tm == -1) {
+ $symb_max_tm = $value;
+ } elsif ($symb_max_tm < $value) {
+ $symb_max_tm = $value;
+ }
+
+ if ($debug) {
+ printf( "found tm_array[$ev_num][$num_symbols][$i] = 0x%x\n", $value);
+ }
+ $tm_array[$ev_num][$num_symbols][$i] = $value;
+ $i = $i +1;
+ }
+ $count[$ev_num][$num_symbols] = $i;
+ $symbol_min_tm[$ev_num][$num_symbols] = $symb_min_tm;
+ $symbol_max_tm[$ev_num][$num_symbols] = $symb_max_tm;
+ if ($debug) {
+ print "symbol_min_tm[$ev_num][$num_symbols] = $symbol_min_tm[$ev_num][$num_symbols] \n";
+ print "symbol_max_tm[$ev_num][$num_symbols] = $symbol_max_tm[$ev_num][$num_symbols] \n";
+ }
+ }
+
+ if ($fields[0] eq "<symboldata") {
+ # Found a symbol table entry, update symbol id in sym_name
+ # with the actual symbol name
+ @subfields = split('"', $fields[2]);
+ $name = $subfields[1];
+ $id_name = $fields[1];
+ $id_name=~ s/"/'/g; # changed " to ' when storing id
+ $id_name=~ s/id=/idref=/g;
+
+ for ($i = 0; $i < $num_symbols; $i = $i + 1) {
+ #search for id_name in $sym_name and update with actual name
+ if ($sym_name[$i] eq $id_name) {
+ if ($debug) {
+ print "Replace name $sym_name[$i] at index $i with $name\n";
+ }
+ $sym_name[$i] = $name;
+ }
+ }
+ }
+
+ if ($fields[0] =~ /\<classes\>/) { # field has substring <count
+ if ($debug) {
+ print "Found classes entry \n";
+ }
+ $found_classes = 1;
+ }
+
+ if ($fields[0] eq "<timestamp>") { # time stamps on next line
+ # single event
+ $ev_num = 0;
+ if ($debug) {
+ print "Found time stamp entry \n";
+ }
+ $found_tm = 1;
+ }
+
+ if ($fields[0] eq "<timestamp") { # time stamps on next line
+ # data consists of multiple events
+ @subfields = split('"', $fields[1]);
+ $class_name = $subfields[1];
+ print "EVENT NAME = $class_name\n";
+ if ($debug) {
+ print "Found time stamp entry \n";
+ }
+ $ev_num = get_class_event_number($class_name);
+ $found_tm = 1;
+ }
+ }
+}
+
+sub debug_print_extracted_data {
+ print "\n\nEXTRACTED DATA \n\n";
+
+ print " Number of events = $max_events\n";
+ print " Number of symbols found = $num_symbols\n";
+ print " Min time stamp = $min_tm\n";
+ print " Max time stamp = $max_tm\n\n";
+
+ for ($ev_num = 0; $ev_num < $max_events; $ev_num = $ev_num + 1) {
+ for ($i = 0; $i <= $num_symbols; $i = $i + 1) {
+ print "Event number $k\n";
+ print "Symbol = $sym_name[$i], count[$ev_num][$i] = $count[$ev_num][$i]\n";
+ print "symbol_min_tm = $symbol_min_tm[$ev_num][$i]\n";
+ print "symbol_max_tm = $symbol_max_tm[$ev_num][$i]\n\n";
+
+ for ($j = 0; $j < $count[$ev_num][$i]; $j = $j + 1) {
+ print "tm_array[$ev_num][$i][$j] = $tm_array[$ev_num][$i][$j] \n";
+ }
+ print "\n\n";
+ }
+ }
+ print "\n\nEND OF EXTRACTED DATA \n\n";
+}
+
+
+# print selected symbols with time stamps
+sub print_timestamp_range_for_symbols {
+ $ev_num = $_[0];
+
+ print "Minimum raw time ", $min_tm, "\n";
+ print "Maximum raw time ", $max_tm, "\n\n";
+
+ print "Minimum adjusted time ", $min_tm - $min_tm, "\n";
+ print "Maximum adjusted time ", $max_tm - $min_tm, "\n\n";
+
+ for ($i = 0; $i < $num_symbols; $i = $i + 1) {
+ print "Symbol: ", $sym_name[$i], "\n";
+ print " Min time stamp = ", $symbol_min_tm[$ev_num][$i] - $min_tm, "\n";
+ print " Max time stamp = ", $symbol_max_tm[$ev_num][$i] - $min_tm, "\n";
+ printf("\n");
+ }
+}
+
+sub print_bin_data_file_for_plot {
+# count samples within the bin size, plot counts within each bin, for the specified event
+ $all_symbols = 1; # print all symbols in one line
+
+ $bin_width = ($end_time - $start_time) / $max_bins;
+
+ open FH_DATA_FILE, "> $gnu_plot_data_file";
+
+ $print_symbol = 0;
+
+ $bin_time = $start_time;
+
+ for ($k = 0; $k < $max_bins; $k = $k + 1) {
+ for ($n = 0; $n < $max_events; $n = $n + 1) {
+ for ($i = 0; $i < $num_symbols; $i = $i + 1) {
+ $bin_count[$n][$i][$k] = 0;
+
+ if ($debug) {
+ print "range[$bin_time, $bin_time+$bin_width] \n";
+ }
+ for ($j = 0; $j < $count[$n][$i]; $j = $j + 1) {
+ $value = $tm_array[$n][$i][$j];
+ if ($debug) {
+ print "tm_array[$n][$i][$j] = $tm_array[$n][$i][$j]\n";
+ }
+ if (($value >= $bin_time) &&
+ ($value <= ($bin_time + $bin_width))) {
+ $bin_count[$n][$i][$k] = $bin_count[$n][$i][$k] + 1;
+ }
+ }
+ if ($debug) {
+ print "bin_count[$n][$i][$k] = $bin_count[$n][$i][$k]\n";
+ }
+ }
+ }
+ $bin_time = $bin_time + $bin_width;
+ }
+
+
+ if ($print_symbol_threshold == 0) {
+ for ($k = 0; $k < $max_bins; $k = $k + 1) {
+ $x_coordinate = $k * $bin_width;
+ print FH_DATA_FILE $x_coordinate, $DATA_SEPARATOR;
+
+ # print the data for each event
+ for ($n = 0; $n < $max_events; $n = $n + 1) {
+ $sum = 0;
+ for ($i = 0; $i < $num_symbols; $i = $i + 1) {
+ $sum = $sum + $bin_count[$n][$i][$k];
+
+ }
+ if ($debug) {
+ print " counts in bin[$k][$n] = $sum\n";
+ }
+ print FH_DATA_FILE "$sum ", $DATA_SEPARATOR;
+ }
+
+ print FH_DATA_FILE "\n";
+ }
+ } elsif ($print_symbol_threshold > 0) {
+ for ($k = 0; $k < $max_bins; $k = $k + 1) {
+ $x_coordinate = $k * $bin_width;
+ print FH_DATA_FILE $x_coordinate, $DATA_SEPARATOR;
+
+ # print the data for each event
+ for ($ev_num = 0; $ev_num < $max_events; $ev_num = $ev_num + 1) {
+ # print the N symbols
+ for ($n = 0; $n < $print_symbol_threshold; $n = $n + 1) {
+ $print_rank = $n + 1; # column 1 is X data
+ for ($i = 0; $i < $num_symbols; $i = $i + 1) {
+ if ($sym_rank[$ev_num][$i] == $print_rank) {
+ if ($debug) {
+ print "Print data for event $event_name[$ev_num], $sym_name[$i] print_rank = $print_rank\n";
+ }
+ print FH_DATA_FILE $bin_count[$ev_num][$i][$k], $DATA_SEPARATOR;
+ }
+ }
+ }
+
+ # Sum counts for all symbols whose rank is greater
+ # then top N symbols and print them in the last
+ # column for other
+ $sum = 0;
+ for ($n = $print_symbol_threshold; $n < $num_symbols; $n = $n + 1) {
+ $print_rank = $n + 1;
+ for ($i = 0; $i < $num_symbols; $i = $i + 1) {
+ if ($sym_rank[$ev_num][$i] >= $print_symbol_threshold) {
+ $sum = $sum + $bin_count[$ev_num][$i][$k];
+ }
+ }
+ }
+ print FH_DATA_FILE "$sum", $DATA_SEPARATOR;;
+ }
+ print FH_DATA_FILE "\n ";
+ }
+
+ } else {
+ print "ERROR, print_symbol_threshold value not valid in print_bin_data_file_for_plot\n";
+ }
+ close FH_DATA_FILE;
+}
+
+sub print_base_plot_script {
+# This routine opens the output script file and writes the
+# gnuplot commands that are generic to the various plots
+# being made. It is called from the routine that is doing
+# a specific plot type.
+
+ open FH_GNU_SCRIPT, '>', $gnu_plot_cmd_file;
+
+ print FH_GNU_SCRIPT "# Start time = ", $start_time, "\n";
+ print FH_GNU_SCRIPT "# End time = ", $end_time, "\n";
+ print FH_GNU_SCRIPT "set terminal postscript\n";
+ print FH_GNU_SCRIPT "set output \"$ps_output_file\"\n";
+
+ if ($line_graph == 1) {
+ ## unfortunately gnuplot does not use the X-axis value for histograms
+ ## and box graphs. The x-axis is labeled by the bin number.
+ print FH_GNU_SCRIPT "set xlabel \"Time in ns, since plot start time.\" \n";
+ print FH_GNU_SCRIPT "set ylabel \"Counts in bin. Bin size is $bin_width ns.\" \n";
+ } elsif ($bar_graph == 1) {
+ print FH_GNU_SCRIPT "set xlabel \"Time in ns is bin number times bin_width = $bin_width.\" \n";
+ print FH_GNU_SCRIPT "set ylabel \"Counts in bin.\" \n";
+
+ } else {
+ die "ERROR: neither line_graph or bar_graph was set\n";
+ }
+
+# print FH_GNU_SCRIPT "set ytics 1\n";
+ print FH_GNU_SCRIPT "set xrange [0:*] \n";
+ print FH_GNU_SCRIPT "set yrange [0:*] \n";
+
+ print FH_GNU_SCRIPT "set mytics 0\n";
+}
+
+sub print_line_style_color {
+ print FH_GNU_SCRIPT "# black\n";
+ print FH_GNU_SCRIPT "set style line 99 lt rgbcolor \"#0000\"\n\n";
+
+ print FH_GNU_SCRIPT "# red\n";
+ print FH_GNU_SCRIPT "set style line 1 lt rgbcolor \"#FF0000\"\n\n";
+
+ print FH_GNU_SCRIPT "# aqua\n";
+ print FH_GNU_SCRIPT "set style line 2 lt rgbcolor \"#00FFFF\"\n\n";
+
+ print FH_GNU_SCRIPT "# bisque\n";
+ print FH_GNU_SCRIPT "set style line 3 lt rgbcolor \"#FFE4C4\"\n\n";
+
+ print FH_GNU_SCRIPT "# blue\n";
+ print FH_GNU_SCRIPT "set style line 4 lt rgbcolor \"#0000FF\"\n\n";
+
+ print FH_GNU_SCRIPT "# brown\n";
+ print FH_GNU_SCRIPT "set style line 6 lt rgbcolor \"#A52A2A\"\n\n";
+
+ print FH_GNU_SCRIPT "# burlywood\n";
+ print FH_GNU_SCRIPT "set style line 7 lt rgbcolor \"#DEB887\"\n\n";
+
+ print FH_GNU_SCRIPT "# cadetblue\n";
+ print FH_GNU_SCRIPT "set style line 8 lt rgbcolor \"#5F9EA0\"\n\n";
+
+ print FH_GNU_SCRIPT "# cartreuse\n";
+ print FH_GNU_SCRIPT "set style line 9 lt rgbcolor \"#7FFF00\"\n\n";
+
+ print FH_GNU_SCRIPT "# chocolate\n";
+ print FH_GNU_SCRIPT "set style line 10 lt rgbcolor \"#D2691E\"\n\n";
+
+ print FH_GNU_SCRIPT "# coral\n";
+ print FH_GNU_SCRIPT "set style line 11 lt rgbcolor \"#FF7F50\"\n\n";
+
+ print FH_GNU_SCRIPT "# cornflowerblue\n";
+ print FH_GNU_SCRIPT "set style line 12 lt rgbcolor \"#6495ED\"\n\n";
+
+ print FH_GNU_SCRIPT "# crimson\n";
+ print FH_GNU_SCRIPT "set style line 13 lt rgbcolor \"#DC143C\"\n\n";
+
+ print FH_GNU_SCRIPT "# darkcyan\n";
+ print FH_GNU_SCRIPT "set style line 14 lt rgbcolor \"#008B8B\"\n\n";
+
+ print FH_GNU_SCRIPT "# darkgoldenrod\n";
+ print FH_GNU_SCRIPT "set style line 15 lt rgbcolor \"#B8860B\"\n\n";
+
+ print FH_GNU_SCRIPT "# green\n";
+ print FH_GNU_SCRIPT "set style line 16 lt rgbcolor \"#008000\"\n\n";
+
+ print FH_GNU_SCRIPT "# greenyellow\n";
+ print FH_GNU_SCRIPT "set style line 17 lt rgbcolor \"#ADFF2F\"\n\n";
+
+ print FH_GNU_SCRIPT "# hotpink\n";
+ print FH_GNU_SCRIPT "set style line 18 lt rgbcolor \"#FF69B4\"\n\n";
+
+ print FH_GNU_SCRIPT "# lawngreend\n";
+ print FH_GNU_SCRIPT "set style line 19 lt rgbcolor \"#7CFC00\"\n\n";
+
+ print FH_GNU_SCRIPT "# lightseagreen\n";
+ print FH_GNU_SCRIPT "set style line 20 lt rgbcolor \"#20B2AA\"\n\n";
+
+ print FH_GNU_SCRIPT "# lightskyblue\n";
+ print FH_GNU_SCRIPT "set style line 21 lt rgbcolor \"#87CEFA\"\n\n";
+
+ print FH_GNU_SCRIPT "# lightslategray\n";
+ print FH_GNU_SCRIPT "set style line 22 lt rgbcolor \"#778899\"\n\n";
+
+ print FH_GNU_SCRIPT "# limegreen\n";
+ print FH_GNU_SCRIPT "set style line 23 lt rgbcolor \"#32CD32\"\n\n";
+
+ print FH_GNU_SCRIPT "# indigo\n";
+ print FH_GNU_SCRIPT "set style line 24 lt rgbcolor \"#4B0082\"\n\n";
+
+ print FH_GNU_SCRIPT "# lime\n";
+ print FH_GNU_SCRIPT "set style line 25 lt rgbcolor \"#00FF00\"\n\n";
+
+ print FH_GNU_SCRIPT "# linen\n";
+ print FH_GNU_SCRIPT "set style line 26 lt rgbcolor \"#FAF0E6\"\n\n";
+
+ print FH_GNU_SCRIPT "# blueviolet\n";
+ print FH_GNU_SCRIPT "set style line 5 lt rgbcolor \"#8A2BE2\"\n\n";
+
+ print FH_GNU_SCRIPT "# magenta\n";
+ print FH_GNU_SCRIPT "set style line 27 lt rgbcolor \"#FF00FF\"\n\n";
+
+ print FH_GNU_SCRIPT "# maroon\n";
+ print FH_GNU_SCRIPT "set style line 28 lt rgbcolor \"#800000\"\n\n";
+
+ print FH_GNU_SCRIPT "# mediumslateblue\n";
+ print FH_GNU_SCRIPT "set style line 29 lt rgbcolor \"#7B68EE\"\n\n";
+
+ print FH_GNU_SCRIPT "# mediumturquoise\n";
+ print FH_GNU_SCRIPT "set style line 30 lt rgbcolor \"#48D1CC\"\n\n";
+}
+
+sub print_bin_line_plot_script_file() {
+# script for making a dot plot
+ $bin_width = ($end_time - $start_time) / $max_bins;
+ if ($debug) {
+ print "print_bin_line_plot_script_file(), bin_width = $bin_width\n";
+ }
+
+ &print_base_plot_script();
+
+ if (($print_symbol_threshold == 0) && ($max_events == 1)) {
+ # Note if there is only one event, the XML file does not contain the
+ # event name thus event_name[] is empty.
+
+ print FH_GNU_SCRIPT "set title \"Line-Histogram\"\n";
+ print FH_GNU_SCRIPT "plot \"$gnu_plot_data_file\" using 1:2 with linespoints lc rgb \"#0000FF\" title 'all symbols'";
+
+ } elsif (($print_symbol_threshold == 0) && ($max_events > 1)){
+ &print_line_style_color();
+ print FH_GNU_SCRIPT "set title \"Line-Histogram\"\n";
+ print FH_GNU_SCRIPT "plot ";
+ $data_column = 2; # column 1 is X data
+ for ($n = 0; $n < $max_events-1; $n = $n + 1) {
+ $ev_num = $n + 1;
+ print FH_GNU_SCRIPT "\"$gnu_plot_data_file\" using 1:$data_column with lines ls $ev_num title '$event_name[$n]', ";
+
+ $data_column = $data_column + 1;
+
+ }
+ # column 1 is X data, last column other y data
+ print FH_GNU_SCRIPT "\"$gnu_plot_data_file\" using 1:$data_column with lines ls $ev_num+1 title '$event_name[$max_events-1]'\n";
+
+ } elsif (($print_symbol_threshold > 0) && ($max_events == 1)) {
+ # Note if there is only one event, the XML file does not contain the
+ # event name thus event_name[] is empty.
+ &print_line_style_color();
+
+ $ev_num = 0; # only have one event
+ &generate_symbol_rank(@sym_rank); # also needed by the print
+ # data routine
+ print FH_GNU_SCRIPT "plot ";
+
+ $data_column = 2; # column 1 is X data
+
+ for ($n = 0; $n < $print_symbol_threshold; $n = $n + 1) {
+ # Last column is sum of counts for all other symbols
+ $print_rank = $n + 1;
+ for ($i = 0; $i < $num_symbols; $i = $i + 1) {
+ if ($sym_rank[$ev_num][$i] == $print_rank) {
+ print FH_GNU_SCRIPT "\"$gnu_plot_data_file\" using 1:$data_column with lines ls $print_rank title '$sym_name[$i]'";
+ if ($n != ($print_symbol_threshold - 1)) {
+ print FH_GNU_SCRIPT ", ";
+ } else {
+ print FH_GNU_SCRIPT "\n";
+ }
+ $data_column = $data_column + 1;
+ }
+ }
+ }
+
+ } elsif (($print_symbol_threshold > 0) && ($max_events > 1)) {
+ &print_line_style_color();
+ &generate_symbol_rank(@sym_rank); # also needed by the print
+ # data routine
+ print FH_GNU_SCRIPT "plot ";
+
+ $data_column = 2; # column 1 is X data
+ $pr_color = 1;
+
+ for ($ev_num = 0; $ev_num < $max_events; $ev_num = $ev_num + 1) {
+ $print_rank = 1;
+ for ($n = 0; $n < $print_symbol_threshold; $n = $n + 1) {
+ # Last column is sum of counts for all other symbols
+ for ($i = 0; $i < $num_symbols; $i = $i + 1) {
+ if ($sym_rank[$ev_num][$i] == $print_rank) {
+ print FH_GNU_SCRIPT "\"$gnu_plot_data_file\" using 1:$data_column with lines ls $pr_color title '$event_name[$ev_num]-$sym_name[$i]', ";
+ $data_column = $data_column + 1;
+ $pr_color = $pr_color + 1;
+ }
+ }
+ $print_rank = $print_rank + 1;
+ }
+
+ # column 1 is X data, last column other y data
+ print FH_GNU_SCRIPT "\"$gnu_plot_data_file\" using 1:$data_column with lines ls $pr_color title '$event_name[$ev_num]-Other'";
+ $pr_color = $pr_color + 1;
+ $data_column = $data_column + 1;
+
+ if ($ev_num != ($max_events - 1)) {
+ print FH_GNU_SCRIPT ", ";
+ } else {
+ print FH_GNU_SCRIPT "\n";
+ }
+ }
+
+ } else {
+ print "ERROR, unsupported value of print_symbol_threshold = $print_symbol_threshold in print_bin_line_plot_script_file\n";
+ }
+
+
+ close FH_GNU_SCRIPT;
+}
+
+sub print_bin_hist_plot_script_file {
+# script for making a histogram plot
+ $bin_width = ($end_time - $start_time) / $max_bins;
+
+ &print_base_plot_script();
+ print FH_GNU_SCRIPT "set title \"Histogram\"\n";
+
+ print FH_GNU_SCRIPT "set key invert reverse Left outside\n";
+ print FH_GNU_SCRIPT "set style data histogram\n";
+ print FH_GNU_SCRIPT "set style histogram rowstacked\n";
+ print FH_GNU_SCRIPT "set style fill solid noborder\n";
+ print FH_GNU_SCRIPT "set boxwidth 0.5\n";
+
+ if (($print_symbol_threshold == 0) && ($max_events == 1)) {
+ # use blue #0000FF color
+ print FH_GNU_SCRIPT "plot \"$gnu_plot_data_file\" using 2 lc rgb \"#0000FF\" title 'all symbols'\n";
+
+ } elsif (($print_symbol_threshold == 0) && ($max_events > 1)) {
+ &print_line_style_color();
+ print FH_GNU_SCRIPT "plot ";
+
+ $data_column = 2; # X data in column 1
+ for ($n = 0; $n < $max_events-1; $n = $n + 1) {
+ $ev_num = $n + 1;
+
+ print FH_GNU_SCRIPT "\"$gnu_plot_data_file\" using $data_column with boxes ls $data_column title '$event_name[$n]-all symbols]', ";
+ $data_column = $data_column + 1;
+
+# print FH_GNU_SCRIPT "\"$gnu_plot_data_file\" using $ev_num lc $n '$event_name[$n]-all symbols', ";
+ }
+ print FH_GNU_SCRIPT "\"$gnu_plot_data_file\" using $data_column with boxes ls $data_column title '$event_name[$max_events-1]-all symbols'\n ";
+
+ } elsif (($print_symbol_threshold > 0) && ($max_events == 1)) {
+ &print_line_style_color();
+ &generate_symbol_rank(@sym_rank); # also needed by the print
+ # data routine
+ print FH_GNU_SCRIPT "plot ";
+ $data_column = 2; # X data in column 1
+ $ev_num = 0; # only have 1 event
+
+ for ($n = 0; $n < $print_symbol_threshold; $n = $n + 1) {
+ # Last column is sum of counts for all other symbols
+ $print_rank = $n + 1; # column 0 is X data
+ for ($i = 0; $i < $num_symbols; $i = $i + 1) {
+ if ($sym_rank[$ev_num][$i] == $print_rank) {
+ print FH_GNU_SCRIPT "\"$gnu_plot_data_file\" using $data_column with boxes ls $print_rank title '$sym_name[$i]'";
+ if ($n != ($print_symbol_threshold - 1)) {
+ print FH_GNU_SCRIPT ", ";
+ } else {
+ print FH_GNU_SCRIPT "\n";
+ }
+ $data_column = $data_column + 1;
+ }
+ }
+ }
+
+ } elsif (($print_symbol_threshold > 0) && ($max_events > 1)) {
+ &print_line_style_color();
+ &generate_symbol_rank(@sym_rank); # also needed by the print
+ # data routine
+ print FH_GNU_SCRIPT "plot ";
+ $data_column = 2; # X data in column 1
+ $pr_color = 1;
+
+ for ($ev_num = 0; $ev_num < $max_events; $ev_num = $ev_num + 1) {
+ $print_rank = 1; # column 0 is X data
+ for ($n = 0; $n < $print_symbol_threshold; $n = $n + 1) {
+ # Last column is sum of counts for all other symbols
+ for ($i = 0; $i < $num_symbols; $i = $i + 1) {
+ if ($sym_rank[$ev_num][$i] == $print_rank) {
+ print FH_GNU_SCRIPT "\"$gnu_plot_data_file\" using $data_column with boxes ls $pr_color title '$event_name[$ev_num]-$sym_name[$i]', ";
+ $data_column = $data_column + 1;
+ $pr_color = $pr_color + 1;
+ }
+ }
+ $print_rank = $print_rank + 1;
+ }
+
+ print FH_GNU_SCRIPT "\"$gnu_plot_data_file\" using $data_column with boxes ls $pr_color title '$event_name[$ev_num]-Other'";
+ $pr_color = $pr_color + 1;
+ $data_column = $data_column + 1;
+
+ if ($ev_num != ($max_events - 1)) {
+ print FH_GNU_SCRIPT ", ";
+ } else {
+ print FH_GNU_SCRIPT "\n";
+ }
+ }
+
+ } else {
+ print "ERROR, unsupported value of print_symbol_threshold = $print_symbol_threshold in print_bin_hist_plot_script_file\n";
+ }
+ close FH_GNU_SCRIPT;
+
+}
--
1.7.1




------------------------------------------------------------------------------
Loading...