student for gsoc2008

[Joel Sherrill]

Chris Johns wrote:
> Joel Sherrill wrote:
>   
>> Reng Zeng wrote:
>>     
>>> Hi Joel, Chris,
>>>
>>> I do not understand your "class" and data along with it below, Could
>>> you please explain it a little more?
>>>
>>>       
>> Did my separate post help?
>>     
>>> That is still TBD.  It could be a "class" indicator byte followed by an
>>> class specific
>>> event.  Something like:
>>>
>>> + class
>>> + class specific message indicator
>>> + size of data following
>>> + data
>>>
>>> For the trace points to add, I understand as below:
>>>
>>> 1. Write code to generate the wrapped version for each function to
>>> trace, such as
>>> void *__wrap_symbol(arguments)
>>> {
>>>   void *p;
>>>   void *__real_symbol(arguments);
>>>
>>>   Event_ID eid = Get_Event_ID(symbol);
>>>
>>>   if (TriggerSet(eid))
>>>          pass all the arguments to the SOLE handler in capture engine.
>>>          together with the data refered by arguments.
>>>
>>>   p = __real_symbol(size);
>>>
>>>   if (TriggerSet(eid))
>>>       pass the return value to the SOLE handler in capture engine.
>>>     together with the data refered by return value.
>>>
>>>   return p;
>>> }
>>>       
>> I wish Chris was back from his honeymoon.
>>     
>
> Wish we could have one but have no time at the moment. Anyway I am back and here.
>
>   
>> But as far I understand that is generally correct.  You want to log entry
>> and exit status from every wrapped call.
>>
>>     
>
> Yes this is correct. We need to flatten the argument list to a block of memory
> to capture. The wrapper code generator will know all the details of the
> function's signature so can determine the amount of stack used to hold
> arguments. The variable argument functions such as printf are something I am
> yet to figure out. This is part of the work.
>
> The capture engine's role changes a little when logging wrapped calls. When in
> the context switch path performance is key while in the wrapped mode the
> overhead of the block copy of arguments is something we know has to happen and
> have to factor in.
>
> The example code above it is close. We need to decide if we log only once when
> we have the return value with 2 time stamps (entry/exit). This lowers the
> overheads down but complicates the data stream on the host side as nested
> traced calls will appear before the current call.
>
>   
I think entry/exit makes sense on potentially blocking
synchronization primitives. 

Consider this sequence:

+ sem obtain blocks
   - context switch
   time passes        
  - context switch back
+ sem obtain returns

At the first context switch, without logging entry we do not know why
it blocked.  At the return point, without logging the exit we do not know
the reason why it unblocked.

It is just something that needs to be worked through.  Do we log entry
and exit to read()?  If you don't you won't know if that blocked you forever
or how many bytes were read.

Hard issues..
>> I believe Chris has an idea where the trigger is actually in the capture
>> engine and users can provide boolean expressions.  Greatly simplifies
>> the logging.
>>     
>
> We need generate some sort of id which is specific to a function's signature
> and then have a way to match this with the running target image and finally
> the resulting data. Once we have this the capture engine can handle the
> trigger and filter processing keeping this code in one place.
>
> We may have the tool generate code that is compiled into the application to
> handle static filters and triggers rather than a user interface. This code is
> just making calls to the capture engine.
>
> Let me explain. We could have a target that is connected to via TCP. The user
> has wrapped a list of functions then interacts with the running target to set
> filters and triggers dynamically in a series of runs to isolate a bug. The
> second example is a system where the list of wrapped functions is generated
> from the static filter and trigger commands which are also turned into target
> code run during initialisation. Both systems use the same capture engine code.
>
>   
>> Plus with the wrapping idea, you turn the wrapper completely off via
>> ld arguments.  That part can be done manually or via a GUI to generate
>> a file that is passed to the ld command line.
>>     
>
> This is something we need to figure out. For example do I build my RTEMS
> application as I do then say capture tool relink to be a traceable executable
> or do users application build systems need to know what to do. The issue here
> is how we manage or help the user with the build process when wrapping.
>
>   
>>> 2. Triggers are to be managed by the event ID.
>>>       
>
> I call "event ID" trace points. We can have system trace points like we
> currently have in the capture enigine, function trace points (wrapped
> functions) and user trace points where a user makes an explicit call.
>
>   
>>> 3. I has no idea about the filter for these events. For existing task
>>> related one, we could filter by priority, but how about the wrapped
>>> one? Could you tell some example for me to consider?
>>>
>>>       
>> Based upon the id of the executing thread. Try this example:
>>
>> log all semaphore manager calls for thread 32.
>> log all context switches
>> log all malloc/free calls for thread 75.
>>
>> Start tracing after 10 seconds and log for 15 seconds.
>>     
>
> The first examples are filters while the last one is a trigger. The way to
> think about this is to consider a hardware logic analyser. You can filter the
> signals you want to look at then you specify a trigger. Once triggered you
> capture based on the filtering.
>
> The detail of the implementation is the way in which a user says "malloc" and
> we match that to a specific trace point (id) which has a set of flags we check
> against. The example filter:
>
>   log all semaphore manager calls for thread 32
>
> is rather complex because we need to pattern match "rtems_semaphore_*" to find
> all the calls and the id's then add the thread id to each trace point's
> control data. The check of the thread id is similar to the "by" fields
> currently in the capture control structure. The above could be written as:
>
>   filter rtems_semaphore_* from 32
>
> To filter another task as well run the command again with a new thread id.
>
>   
>>> Regarding to other parts of the project, I understand as below, please
>>> comment.
>>> 1. Transmission of logged data to host
>>>
>>>           o The first challenge of this part is to make the system and
>>>             the log survive from high traffic.
>>>           o The second challenge is to implement it in TCP while
>>>             providing the flexibility for other transports in future.
>>>           o The third challenge is to trade off minimizing the data to
>>>             be sent across the network against the over-head to
>>>             compress data.
>>>
>>>       
>> Right.  This is something to investigate and do the trade-offs in the
>> early phase of the project.
>>     
>
> We also need to handle the control data to manage dynamic triggers and filters.
>
>   
>> The "communications transport" code must be pluggable and replaceable
>> byu the user.  This simplifies your job because a simple TCP stream could
>> be the first implementation.  Leaving it as a plugin point, lets it be
>> changed
>> by a user or a subsequent developer.  You provide a baseline.
>>     
>>> 2. Receipt of logged data on host
>>>
>>>           o Use Python to write a CLI to receive data into a file.
>>>
>>>       
>> That's the first step. You have to receive the raw log data.
>>
>> Chris is a Python fan.. I am concerned about the functionality.  If python
>> makes it easier, so be it.  It does make it portable to other hosts.
>>     
>>> 3. Decoding of logged data on host
>>>
>>>           o From the compressed data received, decode it for
>>>             high-level application to display as tracing data.
>>>
>>>       
>> Right.  Next step.. an ascii dump.  Not pretty but accurate.
>>     
>>> 4. GUI Timeline Visualization tool
>>>
>>>           o Use GNUplot to integrate the decoded data into
>>>             visualization format. What kind of visualization is expected?
>>>
>>>
>>>       
>> You don't have to use GNUplot and you might not even get to this phase.
>> There
>> is likely a lot of work to do.
>>
>> The Linux Trace Toolkit, WindView, and Spyker are similar tools for other
>> OSes.  Take a look at them.  I know Skyker has a scrolling timeline type
>> interface where you are kind of reading an "EKG" type look at system
>> events marked on the timeline.
>>     
>>> Thanks,
>>> Alan
>>>
>>>
>>> 2008/3/23, Joel Sherrill <joel.sherrill at oarcorp.com
>>> <mailto:joel.sherrill at oarcorp.com>>:
>>>
>>>     > [Alan] What is the event type indicator here? Current capture engine
>>>     > provide specific handler for each event. Now to integrate to capture
>>>     > engine from ALL the wrapper function, it would have SOLE handler in
>>>     > capture engine, is that right? Then besides all the arguments
>>>     could be
>>>     > passed into
>>>
>>>     That is still TBD.  It could be a "class" indicator byte followed
>>>     by an
>>>     class specific
>>>     event.  Something like:
>>>
>>>     + class
>>>     + class specific message indicator
>>>     + size of data following
>>>     + data
>>>
>>>     Then the SOLE capture engine is just moving data which is decoded
>>>     on the
>>>     host side.  Each "class" could provide a decode routine.
>>>
>>>     > capture engine, what kind of event type indicator could be passed
>>>     > along here?
>>>     >
>>>     >     Chris was sure he could take the same list of function
>>>     prototypes
>>>     >     and auto
>>>     >     generate python code to decode the trace log.
>>>
>>>
>>>       
>>     


-- 
Joel Sherrill, Ph.D.             Director of Research & Development
joel.sherrill at OARcorp.com        On-Line Applications Research
Ask me about RTEMS: a free RTOS  Huntsville AL 35805
   Support Available             (256) 722-9985