developerWorks : aW : Visual Performance Analyzer : Trace Analyzer problem in using custom ...

mootoh

Posts: 1
Registered: Jun 19, 2009 05:54:33 AM

Trace Analyzer problem in using custom trace_control on Cell BE
Posted: Jun 19, 2009 06:04:22 AM

I developed a custom trace library for Cell BE/SPE using PDT.
It consists of some trace_interval_entry() /trace_interval_exit() and a PDT config XML that describes custom interval events.
Though it works fine on pdt and the pdtr report seems great, VPA cannot visualize its trace files.

It says:

"Problem Occurred:
Error opening the editor. (Time of error: ...)
Reason: java.util.NoSuchElementException

If I use existing events instead, VPA displays correct output.

Is it possible to use VPA for visualizing custom events?

biberstein

Posts: 5
Registered: Dec 03, 2007 09:47:38 AM

Re: Trace Analyzer problem in using custom trace_control on Cell BE
Posted: Jun 21, 2009 06:30:47 AM

in response to: mootoh's post

Reply

mootoh,

VPA supports traces with custom events collected using the PDT. If you can send me an example of a failing trace to biberstein@il.ibm.com, I can look closer into it.

defbond

Posts: 4
Registered: Jul 08, 2009 09:41:09 AM

Re: Trace Analyzer problem in using custom trace_control on Cell BE
Posted: Jul 08, 2009 09:52:43 AM

in response to: biberstein's post

Reply

Hello,

I am also trying to do the same thing :

I'm doing the same things than in libsync : define a custom event (and assigning it any given id) and add some more information to the payload_t.
I've also written a custom config xml file inspired by the one for libsync, where I define a group, and the description of my payload in <recordtype> items.

The trace is created fine, but when I try to open the file in VPA, I have the same java.util.NoSuchElementException.

What is the correct way to add custom detailed events in a trace ?

Thank you

Here is the content of my .pex :


<metadata version="2.0" isTraceBigEndian="true" traceRecordTypeExpression="#" traceSource="PDT:Cell" endianess="bigEndian" numberOfTraceFiles="1">

<group name="CLS" description="Clever ScheduleEvents" id="0x03" >

<view yStart="0.6" yEnd="0.8" color="0xFFFF00" />

</group>

<recordType name="PPE_TRACE_EVENT_PROCESS_TASK" description="PPE: process a task" id="0x000F" type="interval" pdtRecordClass="user_interval">

  <physicalField name="EventID" description="Event ID and Group ID" type="short" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="Processor" description="Processor type" type="byte" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="Reserved1" description="Reserved" type="byte" toString="0x%x" visible="false" pdtheader="true"/>

  <physicalField name="EventCount" description="Event number (ID)" type="int" toString="%d" visible="true" pdtheader="true"/>

  <physicalField name="CallingThread" description="The pthread that called the event" type="long" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="StartTime" description="Start of interval TimeBase register sample" type="long" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="EndTime" description="Record write time TimeBase register sample (end of interval)" type="long" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="ProgramCounter" description="Program Counter" type="long" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="StartPhysicalID" description="Processor physical ID of interval start" type="short" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="PhysicalID" description="Processor physical ID" type="short" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="Reserved2" description="Reserved" type="int" toString="0x%x" visible="false" pdtheader="true"/>

  <physicalField name="task_id" description="Task ID" type="int" toString="%d" visible="true"/>

  <physicalField name="instance" description="Treated Instance" type="int" toString="%d" visible="true"/>

  <physicalField name="empty4" description="empty slot 4" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty5" description="empty slot 5" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty6" description="empty slot 6" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty7" description="empty slot 7" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty8" description="empty slot 8" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty9" description="empty slot 9" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty10" description="empty slot 10" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty11" description="empty slot 11" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty12" description="empty slot 12" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty13" description="empty slot 13" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty14" description="empty slot 14" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty15" description="empty slot 15" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty16" description="empty slot 16" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty17" description="empty slot 17" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty18" description="empty slot 18" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty19" description="empty slot 19" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty20" description="empty slot 20" type="int" toString="0x%x" visible="false"/>

</recordType>

<recordType name="SPE_TRACE_EVENT_PROCESS_TASK" description="SPE: process a task" id="0x010F" type="interval" pdtRecordClass="user_interval">

  <physicalField name="EventID" description="Event ID and Group ID" type="short" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="Processor" description="Processor type" type="byte" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="PhysicalID" description="Processor physical ID" type="byte" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="EventCount" description="Event number (ID)" type="int" toString="%d" visible="true" pdtheader="true"/>

  <physicalField name="SPEcontext" description="The spe context id (logical)" type="long" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="StartTime" description="Start of interval Decrementer sample" type="long" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="EndTime" description="Record write time decrementer sample (end of interval)" type="long" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="PPEContextRunEventCount" description="spe context run event ID" type="int" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="ProgramCounter" description="Program Counter" type="int" toString="0x%x" visible="true" pdtheader="true"/>

  <physicalField name="DiffTime" description="Difference between write time and event time" type="int" toString="0x%x" visible="false" pdtheader="true"/>

  <physicalField name="Reserved" description="Reserved" type="int" toString="0x%x" visible="false" pdtheader="true"/>

  <physicalField name="task_id" description="Task ID" type="int" toString="%d" visible="true"/>

  <physicalField name="instance" description="Treated Instance" type="int" toString="%d" visible="true"/>

  <physicalField name="empty4" description="empty slot 4" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty5" description="empty slot 5" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty6" description="empty slot 6" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty7" description="empty slot 7" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty8" description="empty slot 8" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty9" description="empty slot 9" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty10" description="empty slot 10" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty11" description="empty slot 11" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty12" description="empty slot 12" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty13" description="empty slot 13" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty14" description="empty slot 14" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty15" description="empty slot 15" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty16" description="empty slot 16" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty17" description="empty slot 17" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty18" description="empty slot 18" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty19" description="empty slot 19" type="int" toString="0x%x" visible="false"/>

  <physicalField name="empty20" description="empty slot 20" type="int" toString="0x%x" visible="false"/>

</recordType>

</metadata>

biberstein

Posts: 5
Registered: Dec 03, 2007 09:47:38 AM

Re: Trace Analyzer problem in using custom trace_control on Cell BE
Posted: Jul 08, 2009 12:23:07 PM

in response to: defbond's post

Reply

defbond,

Thanks for the data! Did you attach the complete pex file? Then I think I know what the problem is. The trace seems to have been created without the core PDT tracing, which collects events such as thread creation and destruction, context switches, etc. Trace Analyzer relies on these events to restore the trace timeline, as the raw trace data only contains thread-local timestamps. I'll ask the PDT team for more data/instructions.

defbond

Posts: 4
Registered: Jul 08, 2009 09:41:09 AM

Re: Trace Analyzer problem in using custom trace_control on Cell BE
Posted: Jul 09, 2009 03:48:23 AM

in response to: biberstein's post

Reply

Hi,

unfortunately, it's not the complete pex file :-( I removed all the non-custom parts. Here is the complete one :

http://graal.ens-lyon.fr/~mjacquel/files/trace.pex

Here are my custom xml config files from wich I generate the trace:

http://graal.ens-lyon.fr/~mjacquel/files/cls.xml

and

http://graal.ens-lyon.fr/~mjacquel/files/cls_config.xml

I generate trace using these libsync-inspired headers:

#define __PPU_TRACEHOOKS_H__ #include <trace_events.h> #ifndef _LEVEL #define _LEVEL 0 #endif #define PPE_TRACE_EVENT_PROCESS_TASK 0x0003 #define TRACE_PROCESS_TASK_ENTRY(_INTERVAL) \ trace_interval_p _INTERVAL = trace_interval_entry(PPE_TRACE_EVENT_PROCESS_TASK, _LEVEL) #define TRACE_PROCESS_TASK_EXIT(_INTERVAL,task_id,instance) { \ trace_payload_t payload; \ payload.word[0]=(unsigned int)task_id; \ payload.word[1]=(unsigned int)instance; \ trace_interval_exit(_INTERVAL, 2, &payload, "Event=%d, task_id=0x%x, instance=0x%x"); \ } #endif
and

#ifndef __SPU_TRACEHOOKS_H__ #define __SPU_TRACEHOOKS_H__ #include <trace_events.h> #ifndef _LEVEL #define _LEVEL 0 #endif #define SPE_TRACE_EVENT_PROCESS_TASK 0x0103 #define TRACE_PROCESS_TASK_ENTRY(_INTERVAL) \ trace_interval_p _INTERVAL = trace_interval_entry(SPE_TRACE_EVENT_PROCESS_TASK, _LEVEL) #define TRACE_PROCESS_TASK_EXIT(_INTERVAL,task_id,instance) { \ trace_payload_t payload; \ payload.word[0]=(unsigned int)task_id; \ payload.word[1]=(unsigned int)instance; \ trace_interval_exit(_INTERVAL, 2, &payload, "Event=%d, task_id=0x%x, instance=0x%x"); \ } #endif
Thank you very much for your support AND the fast answer !

biberstein

Posts: 5
Registered: Dec 03, 2007 09:47:38 AM

Re: Trace Analyzer problem in using custom trace_control on Cell BE
Posted: Jul 09, 2009 04:18:34 AM

in response to: defbond's post

Reply

There goes my beautiful hypothesis... Maybe you could also upload the trace file itself (trace.1.trace)? Or, if this is more convenient, send it to me at biberstein@il.ibm.com? I'd like to recreate the problem on my machine.

Thanks!

defbond

Posts: 4
Registered: Jul 08, 2009 09:41:09 AM

Re: Trace Analyzer problem in using custom trace_control on Cell BE
Posted: Jul 09, 2009 04:28:32 AM

in response to: biberstein's post

Reply

Okay, I've just sent the file to you,

I keep posting on the forum because it might help people experiencing the same problem :-)

biberstein

Posts: 5
Registered: Dec 03, 2007 09:47:38 AM

Re: Trace Analyzer problem in using custom trace_control on Cell BE
Posted: Jul 09, 2009 05:54:36 AM

in response to: defbond's post

Reply

Thanks for the file! The problem was that the custom record types were 4 bytes too short. PDT records are always 128 bytes long, but Trace Analyzer is not a PDT-specific tool, and relies only on the definitions in the .pex file for reading the traces. Therefore, if the pex only contains definitions for 124 bytes worth of fields, Trace Analyzer parses the last field of such record as the first field of the next record.

Here are the new definitions for the custom types in the pex. As you see, I only added an invisible "empty3" field into each type. With those changes, Trace Analyzer successfully read and showed the trace:

<group name="CLS" description="Clever ScheduleEvents" id="0x03" >
<view yStart="0.6" yEnd="0.8" color="0xFFFF00" />
</group>
<recordType name="PPE_TRACE_EVENT_PROCESS_TASK" description="PPE: process a task" id="0x0003" type="interval">
<physicalField name="EventID" description="Event ID and Group ID" type="short" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="Processor" description="Processor type" type="byte" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="Reserved1" description="Reserved" type="byte" toString="0x%x" visible="false" pdtheader="true"/>
<physicalField name="EventCount" description="Event number (ID)" type="int" toString="%d" visible="true" pdtheader="true"/>
<physicalField name="CallingThread" description="The pthread that called the event" type="long" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="StartTime" description="Start of interval TimeBase register sample" type="long" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="EndTime" description="Record write time TimeBase register sample (end of interval)" type="long" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="ProgramCounter" description="Program Counter" type="long" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="StartPhysicalID" description="Processor physical ID of interval start" type="short" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="PhysicalID" description="Processor physical ID" type="short" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="Reserved2" description="Reserved" type="int" toString="0x%x" visible="false" pdtheader="true"/>
<physicalField name="task_id" description="Task ID" type="int" toString="%d" visible="true"/>
<physicalField name="instance" description="Treated Instance" type="int" toString="%d" visible="true"/>
<physicalField name="empty3" description="empty slot 3" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty4" description="empty slot 4" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty5" description="empty slot 5" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty6" description="empty slot 6" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty7" description="empty slot 7" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty8" description="empty slot 8" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty9" description="empty slot 9" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty10" description="empty slot 10" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty11" description="empty slot 11" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty12" description="empty slot 12" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty13" description="empty slot 13" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty14" description="empty slot 14" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty15" description="empty slot 15" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty16" description="empty slot 16" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty17" description="empty slot 17" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty18" description="empty slot 18" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty19" description="empty slot 19" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty20" description="empty slot 20" type="int" toString="0x%x" visible="false"/>
</recordType>
<recordType name="SPE_TRACE_EVENT_PROCESS_TASK" description="SPE: process a task" id="0x0103" type="interval">
<physicalField name="EventID" description="Event ID and Group ID" type="short" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="Processor" description="Processor type" type="byte" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="PhysicalID" description="Processor physical ID" type="byte" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="EventCount" description="Event number (ID)" type="int" toString="%d" visible="true" pdtheader="true"/>
<physicalField name="SPEcontext" description="The spe context id (logical)" type="long" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="StartTime" description="Start of interval Decrementer sample" type="long" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="EndTime" description="Record write time decrementer sample (end of interval)" type="long" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="PPEContextRunEventCount" description="spe context run event ID" type="int" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="ProgramCounter" description="Program Counter" type="int" toString="0x%x" visible="true" pdtheader="true"/>
<physicalField name="DiffTime" description="Difference between write time and event time" type="int" toString="0x%x" visible="false" pdtheader="true"/>
<physicalField name="Reserved" description="Reserved" type="int" toString="0x%x" visible="false" pdtheader="true"/>
<physicalField name="task_id" description="Task ID" type="int" toString="%d" visible="true"/>
<physicalField name="instance" description="Treated Instance" type="int" toString="%d" visible="true"/>
<physicalField name="empty3" description="empty slot 3" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty4" description="empty slot 4" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty5" description="empty slot 5" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty6" description="empty slot 6" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty7" description="empty slot 7" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty8" description="empty slot 8" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty9" description="empty slot 9" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty10" description="empty slot 10" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty11" description="empty slot 11" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty12" description="empty slot 12" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty13" description="empty slot 13" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty14" description="empty slot 14" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty15" description="empty slot 15" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty16" description="empty slot 16" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty17" description="empty slot 17" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty18" description="empty slot 18" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty19" description="empty slot 19" type="int" toString="0x%x" visible="false"/>
<physicalField name="empty20" description="empty slot 20" type="int" toString="0x%x" visible="false"/>
</recordType>

defbond

Posts: 4
Registered: Jul 08, 2009 09:41:09 AM

Re: Trace Analyzer problem in using custom trace_control on Cell BE
Posted: Jul 09, 2009 06:17:23 AM

in response to: biberstein's post

Reply

Well thanks a lot !

Now I feel confuse because I seem to have copied the configuration file of libsync a bit too fast :)
(there was a long recordtype which is why there was a missing empty field)

Thanks again for your help, I'll push my experiments further.

biberstein

Posts: 5
Registered: Dec 03, 2007 09:47:38 AM

Re: Trace Analyzer problem in using custom trace_control on Cell BE
Posted: Jul 09, 2009 06:43:17 AM

in response to: defbond's post

Reply

I think this kind of problem can occur very easily, once you start replacing the placeholder fields with your own. I'll ask the PDT team to consider checking for such configuration errors, but for now you are on your own :)

Good luck with your experiments!