Logging timestamps for generating timing diagrams

Dear Orocos Devs,

Over in HIGHWIND, we have about 10 components, and would like to log
2-4 timestamps per component, at up to about 100 Hz. The plan is to
hack up a python script that scrapes a log file and generates timing
diagrams semi-automatically, so that we can more easily sanity check
the timing in the running system, and maybe even use the output in
publications. I want it to look something like the output of
drawtiming:

http://drawtiming.sourceforge.net/samples.html

but since I want to draw the signals to scale in time and no timing
diagram tool I've seen actually seems to support that, I'll have to
spend a day or so hacking up something similar in python+cairo -> svg.

Anyway, to get accurately logged timestamps, should we build something
on top of the real time logger OCL::Logging instructions from here:

http://www.orocos.org/wiki/rtt/examples-and-tutorials/using-real-time-lo...

or should we make an output port for every event we want to time and
use the NetCDFReporting component?

P.S. I have read the recent posts about real-time logging, and it's
still not clear to me what the appropriate tool is.

Thanks!
Andrew

AttachmentSize
my_plan.jpeg20.02 KB

Logging timestamps for generating timing diagrams

<shameless advertisement>
You could also use the Rock logger to log some base::Time samples, which
can very easily log this little amount of data without a noticeable CPU
usage, and either plot using the Rock plotting widget (online/offline)
or export to CSV and use whichever tool you wish.
</shameless advertisement>

Logging timestamps for generating timing diagrams

Hi Peter, thanks; I'm planning on doing the plotting myself anyway, so
it sounds like the real-time logging component is better for us
anyway.

Hi Sylvain, thanks for the suggestion, but we don't want ROS or Rock
or any other meta-operating system as a dependency of our flight code.
Since nobody is currently maintaining a git repo for the whole
toolchain that you can just check out and build, we ~do use the
bootstrap_linux script to get a working orocos toolchain, but that's
it.

Cheers,
Andrew

2013/5/31 Sylvain Joyeux <sylvain [dot] joyeux [..] ...>:
> <shameless advertisement>
> You could also use the Rock logger to log some base::Time samples, which
> can very easily log this little amount of data without a noticeable CPU
> usage, and either plot using the Rock plotting widget (online/offline)
> or export to CSV and use whichever tool you wish.
> </shameless advertisement>
>
> --
> Sylvain Joyeux (Dr.Ing.)
> Senior Researcher
>
> Space & Security Robotics
> Underwater Robotics
>
> !!! Achtung, neue Telefonnummer!!!
>
> Standort Bremen:
> DFKI GmbH
> Robotics Innovation Center
> Robert-Hooke-Straße 5
> 28359 Bremen, Germany
>
> Phone: +49 (0)421 178-454136
> Fax: +49 (0)421 218-454150
> E-Mail: robotik [..] ...
>
> Weitere Informationen: http://www.dfki.de/robotik
> -----------------------------------------------------------------------
> Deutsches Forschungszentrum fuer Kuenstliche Intelligenz GmbH
> Firmensitz: Trippstadter Straße 122, D-67663 Kaiserslautern
> Geschaeftsfuehrung: Prof. Dr. Dr. h.c. mult. Wolfgang Wahlster
> (Vorsitzender) Dr. Walter Olthoff
> Vorsitzender des Aufsichtsrats: Prof. Dr. h.c. Hans A. Aukes
> Amtsgericht Kaiserslautern, HRB 2313
> Sitz der Gesellschaft: Kaiserslautern (HRB 2313)
> USt-Id.Nr.: DE 148646973
> Steuernummer: 19/673/0060/3
> -----------------------------------------------------------------------
>
> --
> Orocos-Users mailing list
> Orocos-Users [..] ...
> http://lists.mech.kuleuven.be/mailman/listinfo/orocos-users

Logging timestamps for generating timing diagrams

On 05/31/2013 01:25 PM, Andrew Wagner wrote:
> Hi Sylvain, thanks for the suggestion, but we don't want ROS or Rock
> or any other meta-operating system as a dependency of our flight code.
> Since nobody is currently maintaining a git repo for the whole
> toolchain that you can just check out and build, we ~do use the
> bootstrap_linux script to get a working orocos toolchain, but that's
> it.
FYI, given that you already have an orocos toolchain, the only things
you would need additionally to get a full logger with base::Time would be:

base/types: pure CMake package, no additional dependencies
base/orogen/types: oroGen (you need an orogen generation step + then
normal CMake compilation). No additional dependencies
tools/logger: oroGen (you need an orogen generation step + then normal
CMake compilation). No additional dependencies
tools/pocolog: pure ruby (add pocolog/lib to RUBYLIB and pocolog/bin
to PATH). No additional dependencies

Logging timestamps for generating timing diagrams

(the last one):

http://www.mathworks.nl/products/xpctarget/examples.html?file=/products/...

Does anyone know of something like that is available for linux
threads? I'm not sure if orocos or the components even have enough
information to generate diagrams of when they were pre-empted by what.
Perhaps there is general purpose linux kernel profiling software that
could log the data needed for this diagram? i.e. some tool that I
feed the relevant PID's for the threads that I care about, and hooks
in to the scheduler to log when they were active on which cores....

We're now running linux 3.4 with the PREEMPT RT patches (installed
from a package provided by some audio guy) if it matters:

$ uname -a
Linux planepower-pc 3.4.29-rt41 #2 SMP PREEMPT RT Sun Feb 10 21:19:29
CET 2013 x86_64 x86_64 x86_64 GNU/Linux

On Fri, May 31, 2013 at 1:42 PM, Sylvain Joyeux <sylvain [dot] joyeux [..] ...> wrote:
> On 05/31/2013 01:25 PM, Andrew Wagner wrote:
>> Hi Sylvain, thanks for the suggestion, but we don't want ROS or Rock
>> or any other meta-operating system as a dependency of our flight code.
>> Since nobody is currently maintaining a git repo for the whole
>> toolchain that you can just check out and build, we ~do use the
>> bootstrap_linux script to get a working orocos toolchain, but that's
>> it.
> FYI, given that you already have an orocos toolchain, the only things
> you would need additionally to get a full logger with base::Time would be:
>
> base/types: pure CMake package, no additional dependencies
> base/orogen/types: oroGen (you need an orogen generation step + then
> normal CMake compilation). No additional dependencies
> tools/logger: oroGen (you need an orogen generation step + then normal
> CMake compilation). No additional dependencies
> tools/pocolog: pure ruby (add pocolog/lib to RUBYLIB and pocolog/bin
> to PATH). No additional dependencies
>
> --
> Sylvain Joyeux (Dr.Ing.)
> Senior Researcher
>
> Space & Security Robotics
> Underwater Robotics
>
> !!! Achtung, neue Telefonnummer!!!
>
> Standort Bremen:
> DFKI GmbH
> Robotics Innovation Center
> Robert-Hooke-Straße 5
> 28359 Bremen, Germany
>
> Phone: +49 (0)421 178-454136
> Fax: +49 (0)421 218-454150
> E-Mail: robotik [..] ...
>
> Weitere Informationen: http://www.dfki.de/robotik
> -----------------------------------------------------------------------
> Deutsches Forschungszentrum fuer Kuenstliche Intelligenz GmbH
> Firmensitz: Trippstadter Straße 122, D-67663 Kaiserslautern
> Geschaeftsfuehrung: Prof. Dr. Dr. h.c. mult. Wolfgang Wahlster
> (Vorsitzender) Dr. Walter Olthoff
> Vorsitzender des Aufsichtsrats: Prof. Dr. h.c. Hans A. Aukes
> Amtsgericht Kaiserslautern, HRB 2313
> Sitz der Gesellschaft: Kaiserslautern (HRB 2313)
> USt-Id.Nr.: DE 148646973
> Steuernummer: 19/673/0060/3
> -----------------------------------------------------------------------
>
> --
> Orocos-Users mailing list
> Orocos-Users [..] ...
> http://lists.mech.kuleuven.be/mailman/listinfo/orocos-users

Logging timestamps for generating timing diagrams

Hi Andrew,

Some time ago, i wrote a patch (http://bugs.orocos.org/show_bug.cgi?id=1016) that allow to name threads. If you map one thread per task, it allow to see all your tasks when you call "top -H -p <pid>"...

This work was done in order to use the lttng suite in order to trace my program.

lttng allow to trace program (see userspace tracer http://lttng.org/ust) with a small overhead, then trace plots (http://lttng.org/eclipse).

I didn't managed to import my trace in eclipse the last time i tried, but the support on the mailing list was very reactive...

If you are interested, let me know. I will post more information, or even write a little page on the wiki.

Regards.

Paul.

On 10/29/2013 10:18 AM, Andrew Wagner wrote:
> Update: Here's another example of the sort of plot that I lust after
> (the last one):
>
> http://www.mathworks.nl/products/xpctarget/examples.html?file=/products/...
>
>
> Does anyone know of something like that is available for linux
> threads? I'm not sure if orocos or the components even have enough
> information to generate diagrams of when they were pre-empted by what.
> Perhaps there is general purpose linux kernel profiling software that
> could log the data needed for this diagram? i.e. some tool that I
> feed the relevant PID's for the threads that I care about, and hooks
> in to the scheduler to log when they were active on which cores....
>
> We're now running linux 3.4 with the PREEMPT RT patches (installed
> from a package provided by some audio guy) if it matters:
>
> $ uname -a
> Linux planepower-pc 3.4.29-rt41 #2 SMP PREEMPT RT Sun Feb 10 21:19:29
> CET 2013 x86_64 x86_64 x86_64 GNU/Linux
>
> On Fri, May 31, 2013 at 1:42 PM, Sylvain Joyeux <sylvain [dot] joyeux [..] ...> wrote:
>> On 05/31/2013 01:25 PM, Andrew Wagner wrote:
>>> Hi Sylvain, thanks for the suggestion, but we don't want ROS or Rock
>>> or any other meta-operating system as a dependency of our flight code.
>>> Since nobody is currently maintaining a git repo for the whole
>>> toolchain that you can just check out and build, we ~do use the
>>> bootstrap_linux script to get a working orocos toolchain, but that's
>>> it.
>> FYI, given that you already have an orocos toolchain, the only things
>> you would need additionally to get a full logger with base::Time would be:
>>
>> base/types: pure CMake package, no additional dependencies
>> base/orogen/types: oroGen (you need an orogen generation step + then
>> normal CMake compilation). No additional dependencies
>> tools/logger: oroGen (you need an orogen generation step + then normal
>> CMake compilation). No additional dependencies
>> tools/pocolog: pure ruby (add pocolog/lib to RUBYLIB and pocolog/bin
>> to PATH). No additional dependencies
>>
>> --
>> Sylvain Joyeux (Dr.Ing.)
>> Senior Researcher
>>
>> Space & Security Robotics
>> Underwater Robotics
>>
>> !!! Achtung, neue Telefonnummer!!!
>>
>> Standort Bremen:
>> DFKI GmbH
>> Robotics Innovation Center
>> Robert-Hooke-Straße 5
>> 28359 Bremen, Germany
>>
>> Phone: +49 (0)421 178-454136
>> Fax: +49 (0)421 218-454150
>> E-Mail: robotik [..] ...
>>
>> Weitere Informationen: http://www.dfki.de/robotik
>> -----------------------------------------------------------------------
>> Deutsches Forschungszentrum fuer Kuenstliche Intelligenz GmbH
>> Firmensitz: Trippstadter Straße 122, D-67663 Kaiserslautern
>> Geschaeftsfuehrung: Prof. Dr. Dr. h.c. mult. Wolfgang Wahlster
>> (Vorsitzender) Dr. Walter Olthoff
>> Vorsitzender des Aufsichtsrats: Prof. Dr. h.c. Hans A. Aukes
>> Amtsgericht Kaiserslautern, HRB 2313
>> Sitz der Gesellschaft: Kaiserslautern (HRB 2313)
>> USt-Id.Nr.: DE 148646973
>> Steuernummer: 19/673/0060/3
>> -----------------------------------------------------------------------
>>
>> --
>> Orocos-Users mailing list
>> Orocos-Users [..] ...
>> http://lists.mech.kuleuven.be/mailman/listinfo/orocos-users

Logging timestamps for generating timing diagrams

Hi Paul!

I was just about to post thread naming as a feature request for
orocos! I manually played around a bit with adding pthread_setname_np
calls to my configure hooks, and trying to find the threads using top,
htop, ps, etc...

I was planning to write shell scripts that grep around in /proc and
/sys/kernel/debug to find the processes I care about, and manage
priorities from there. IMHO, setting the priorities in deployer
scripts isn't all that great; I think it would be a lot easier to mess
around with priorities while your control algorithm is running
(assuming you won't break any hardware).

Maybe it's even possible to have some semi-generalized performance
metrics that are also computed completely outside of your deployment
and component definitions...

I glanced at your patch description. A couple comments:

1. It sounds like you provide a hook for setting the name of a task...
ideally I would like task names to be set to some sensible defaults,
like the class name of a (and often the only) component assigned to
it. I have no idea how hard this is...

2. pthread_setname_np is a newer, ultimately, more portable way to set
the thread names; seems like it will be standardized POSIX if its not
already...

The LTTNG suite looks interesting... sounds like these tools are
combining userspace debugger-like functionality (that are aware of the
C,C++ symbols, hopefully), with tracing at the kernel level...

Cheers,
Andrew

On Tue, Oct 29, 2013 at 10:20 PM, Paul Chavent <paul [dot] chavent [..] ...> wrote:
> Hi Andrew,
>
> Some time ago, i wrote a patch (http://bugs.orocos.org/show_bug.cgi?id=1016) that allow to name threads. If you map one thread per task, it allow to see all your tasks when you call "top -H -p <pid>"...
>
> This work was done in order to use the lttng suite in order to trace my program.
>
> lttng allow to trace program (see userspace tracer http://lttng.org/ust) with a small overhead, then trace plots (http://lttng.org/eclipse).
>
> I didn't managed to import my trace in eclipse the last time i tried, but the support on the mailing list was very reactive...
>
> If you are interested, let me know. I will post more information, or even write a little page on the wiki.
>
> Regards.
>
> Paul.
>
>
> On 10/29/2013 10:18 AM, Andrew Wagner wrote:
>> Update: Here's another example of the sort of plot that I lust after
>> (the last one):
>>
>> http://www.mathworks.nl/products/xpctarget/examples.html?file=/products/...
>>
>>
>> Does anyone know of something like that is available for linux
>> threads? I'm not sure if orocos or the components even have enough
>> information to generate diagrams of when they were pre-empted by what.
>> Perhaps there is general purpose linux kernel profiling software that
>> could log the data needed for this diagram? i.e. some tool that I
>> feed the relevant PID's for the threads that I care about, and hooks
>> in to the scheduler to log when they were active on which cores....
>>
>> We're now running linux 3.4 with the PREEMPT RT patches (installed
>> from a package provided by some audio guy) if it matters:
>>
>> $ uname -a
>> Linux planepower-pc 3.4.29-rt41 #2 SMP PREEMPT RT Sun Feb 10 21:19:29
>> CET 2013 x86_64 x86_64 x86_64 GNU/Linux
>>
>> On Fri, May 31, 2013 at 1:42 PM, Sylvain Joyeux <sylvain [dot] joyeux [..] ...> wrote:
>>> On 05/31/2013 01:25 PM, Andrew Wagner wrote:
>>>> Hi Sylvain, thanks for the suggestion, but we don't want ROS or Rock
>>>> or any other meta-operating system as a dependency of our flight code.
>>>> Since nobody is currently maintaining a git repo for the whole
>>>> toolchain that you can just check out and build, we ~do use the
>>>> bootstrap_linux script to get a working orocos toolchain, but that's
>>>> it.
>>> FYI, given that you already have an orocos toolchain, the only things
>>> you would need additionally to get a full logger with base::Time would be:
>>>
>>> base/types: pure CMake package, no additional dependencies
>>> base/orogen/types: oroGen (you need an orogen generation step + then
>>> normal CMake compilation). No additional dependencies
>>> tools/logger: oroGen (you need an orogen generation step + then normal
>>> CMake compilation). No additional dependencies
>>> tools/pocolog: pure ruby (add pocolog/lib to RUBYLIB and pocolog/bin
>>> to PATH). No additional dependencies
>>>
>>> --
>>> Sylvain Joyeux (Dr.Ing.)
>>> Senior Researcher
>>>
>>> Space & Security Robotics
>>> Underwater Robotics
>>>
>>> !!! Achtung, neue Telefonnummer!!!
>>>
>>> Standort Bremen:
>>> DFKI GmbH
>>> Robotics Innovation Center
>>> Robert-Hooke-Straße 5
>>> 28359 Bremen, Germany
>>>
>>> Phone: +49 (0)421 178-454136
>>> Fax: +49 (0)421 218-454150
>>> E-Mail: robotik [..] ...
>>>
>>> Weitere Informationen: http://www.dfki.de/robotik
>>> -----------------------------------------------------------------------
>>> Deutsches Forschungszentrum fuer Kuenstliche Intelligenz GmbH
>>> Firmensitz: Trippstadter Straße 122, D-67663 Kaiserslautern
>>> Geschaeftsfuehrung: Prof. Dr. Dr. h.c. mult. Wolfgang Wahlster
>>> (Vorsitzender) Dr. Walter Olthoff
>>> Vorsitzender des Aufsichtsrats: Prof. Dr. h.c. Hans A. Aukes
>>> Amtsgericht Kaiserslautern, HRB 2313
>>> Sitz der Gesellschaft: Kaiserslautern (HRB 2313)
>>> USt-Id.Nr.: DE 148646973
>>> Steuernummer: 19/673/0060/3
>>> -----------------------------------------------------------------------
>>>
>>> --
>>> Orocos-Users mailing list
>>> Orocos-Users [..] ...
>>> http://lists.mech.kuleuven.be/mailman/listinfo/orocos-users
>
> --
> Orocos-Users mailing list
> Orocos-Users [..] ...
> http://lists.mech.kuleuven.be/mailman/listinfo/orocos-users

Logging timestamps for generating timing diagrams

Hi

On 10/30/2013 11:23 AM, Andrew Wagner wrote:
> Hi Paul!
>
> I was just about to post thread naming as a feature request for
> orocos! I manually played around a bit with adding pthread_setname_np
> calls to my configure hooks, and trying to find the threads using top,
> htop, ps, etc...
>
> I was planning to write shell scripts that grep around in /proc and
> /sys/kernel/debug to find the processes I care about, and manage
> priorities from there. IMHO, setting the priorities in deployer
> scripts isn't all that great; I think it would be a lot easier to mess
> around with priorities while your control algorithm is running
> (assuming you won't break any hardware).

I'm not really confident with dynamic scheduling. Otherwise the SCHED_DEADLINE is something i will be watching...

>
> Maybe it's even possible to have some semi-generalized performance
> metrics that are also computed completely outside of your deployment
> and component definitions...
>
> I glanced at your patch description. A couple comments:
>
> 1. It sounds like you provide a hook for setting the name of a task...
> ideally I would like task names to be set to some sensible defaults,
> like the class name of a (and often the only) component assigned to
> it. I have no idea how hard this is...

If i remember, it is already done at the component level. In ocl, for instance, see /deployment/DeploymentComponent.cpp in setNamedActivity around line 1969. For standard case, it instanciate an RTT::Activity by passing the component name. In rtt, rtt/Activity.cpp there is 1-1 mapping between the activity and the thread so the thread can be named according to the activity.

The same thing could be done for the non periodic activity, but for an unknown reason, the name of the component isn't passed to the Activity ctor :(. It could be a trivial patch IMHO.

For other kind of activities, its less easy to solve the naming of threads...

>
> 2. pthread_setname_np is a newer, ultimately, more portable way to set
> the thread names; seems like it will be standardized POSIX if its not
> already...

Yes, i also prefer the pthread_setname_np. But i let the comment with alternative solution.

>
> The LTTNG suite looks interesting... sounds like these tools are
> combining userspace debugger-like functionality (that are aware of the
> C,C++ symbols, hopefully), with tracing at the kernel level...

I also look for tools that could generate these kind of diagrams for strace outpouts... If you know some project related to this subject, i'm interested.

>
> Cheers,
> Andrew

Cheers,
Paul.

>
> On Tue, Oct 29, 2013 at 10:20 PM, Paul Chavent <paul [dot] chavent [..] ...> wrote:
>> Hi Andrew,
>>
>> Some time ago, i wrote a patch (http://bugs.orocos.org/show_bug.cgi?id=1016) that allow to name threads. If you map one thread per task, it allow to see all your tasks when you call "top -H -p <pid>"...
>>
>> This work was done in order to use the lttng suite in order to trace my program.
>>
>> lttng allow to trace program (see userspace tracer http://lttng.org/ust) with a small overhead, then trace plots (http://lttng.org/eclipse).
>>
>> I didn't managed to import my trace in eclipse the last time i tried, but the support on the mailing list was very reactive...
>>
>> If you are interested, let me know. I will post more information, or even write a little page on the wiki.
>>
>> Regards.
>>
>> Paul.
>>
>>
>> On 10/29/2013 10:18 AM, Andrew Wagner wrote:
>>> Update: Here's another example of the sort of plot that I lust after
>>> (the last one):
>>>
>>> http://www.mathworks.nl/products/xpctarget/examples.html?file=/products/...
>>>
>>>
>>> Does anyone know of something like that is available for linux
>>> threads? I'm not sure if orocos or the components even have enough
>>> information to generate diagrams of when they were pre-empted by what.
>>> Perhaps there is general purpose linux kernel profiling software that
>>> could log the data needed for this diagram? i.e. some tool that I
>>> feed the relevant PID's for the threads that I care about, and hooks
>>> in to the scheduler to log when they were active on which cores....
>>>
>>> We're now running linux 3.4 with the PREEMPT RT patches (installed
>>> from a package provided by some audio guy) if it matters:
>>>
>>> $ uname -a
>>> Linux planepower-pc 3.4.29-rt41 #2 SMP PREEMPT RT Sun Feb 10 21:19:29
>>> CET 2013 x86_64 x86_64 x86_64 GNU/Linux
>>>
>>> On Fri, May 31, 2013 at 1:42 PM, Sylvain Joyeux <sylvain [dot] joyeux [..] ...> wrote:
>>>> On 05/31/2013 01:25 PM, Andrew Wagner wrote:
>>>>> Hi Sylvain, thanks for the suggestion, but we don't want ROS or Rock
>>>>> or any other meta-operating system as a dependency of our flight code.
>>>>> Since nobody is currently maintaining a git repo for the whole
>>>>> toolchain that you can just check out and build, we ~do use the
>>>>> bootstrap_linux script to get a working orocos toolchain, but that's
>>>>> it.
>>>> FYI, given that you already have an orocos toolchain, the only things
>>>> you would need additionally to get a full logger with base::Time would be:
>>>>
>>>> base/types: pure CMake package, no additional dependencies
>>>> base/orogen/types: oroGen (you need an orogen generation step + then
>>>> normal CMake compilation). No additional dependencies
>>>> tools/logger: oroGen (you need an orogen generation step + then normal
>>>> CMake compilation). No additional dependencies
>>>> tools/pocolog: pure ruby (add pocolog/lib to RUBYLIB and pocolog/bin
>>>> to PATH). No additional dependencies
>>>>
>>>> --
>>>> Sylvain Joyeux (Dr.Ing.)
>>>> Senior Researcher
>>>>
>>>> Space & Security Robotics
>>>> Underwater Robotics
>>>>
>>>> !!! Achtung, neue Telefonnummer!!!
>>>>
>>>> Standort Bremen:
>>>> DFKI GmbH
>>>> Robotics Innovation Center
>>>> Robert-Hooke-Straße 5
>>>> 28359 Bremen, Germany
>>>>
>>>> Phone: +49 (0)421 178-454136
>>>> Fax: +49 (0)421 218-454150
>>>> E-Mail: robotik [..] ...
>>>>
>>>> Weitere Informationen: http://www.dfki.de/robotik
>>>> -----------------------------------------------------------------------
>>>> Deutsches Forschungszentrum fuer Kuenstliche Intelligenz GmbH
>>>> Firmensitz: Trippstadter Straße 122, D-67663 Kaiserslautern
>>>> Geschaeftsfuehrung: Prof. Dr. Dr. h.c. mult. Wolfgang Wahlster
>>>> (Vorsitzender) Dr. Walter Olthoff
>>>> Vorsitzender des Aufsichtsrats: Prof. Dr. h.c. Hans A. Aukes
>>>> Amtsgericht Kaiserslautern, HRB 2313
>>>> Sitz der Gesellschaft: Kaiserslautern (HRB 2313)
>>>> USt-Id.Nr.: DE 148646973
>>>> Steuernummer: 19/673/0060/3
>>>> -----------------------------------------------------------------------
>>>>
>>>> --
>>>> Orocos-Users mailing list
>>>> Orocos-Users [..] ...
>>>> http://lists.mech.kuleuven.be/mailman/listinfo/orocos-users
>>
>> --
>> Orocos-Users mailing list
>> Orocos-Users [..] ...
>> http://lists.mech.kuleuven.be/mailman/listinfo/orocos-users
>

Logging timestamps for generating timing diagrams

Thanks for looking into it Paul!

I can't comment on strace; I've only ever used it to figure out which
files a process was (usually failing to) open silently. As for the
thread naming...

I am using the current orocos release version (2.6), installed via the
autoproj package manager....

Looking at the source I see the same bits of source, i.e. where
setActivity is internally calling setNamedActivity:

bool DeploymentComponent::setActivity(const std::string& comp_name,
double period, int priority,
int scheduler)
{
if ( this->setNamedActivity(comp_name, "Activity", period,
priority, scheduler) ) {...

This is how we are launching our activities at the moment:
$ grep Activity dmhe_testing.ops
setActivity("soemMaster", 0.001, soemPrio, ORO_SCHED_RT)
setActivity("masterTimer", 1.0 / base_hz, masterTimerPrio, ORO_SCHED_RT)
setActivity("mcuHandler", 0.002, sensorPrio, ORO_SCHED_RT)
setActivity("voltageController", 0.01, sensorPrio, ORO_SCHED_RT)
setActivity("encoder", 0.0, sensorPrio, ORO_SCHED_RT)
...
setActivity("lineAngleReporter", 0.0, LowestPriority, ORO_SCHED_RT)
setActivity("mheReporter", 0.0, LowestPriority, ORO_SCHED_RT)

Note that some of the components are periodic, and some are not (since
their period is set to 0.0). However, I do not observe any automatic
naming of any of my component threads:

$ ps -eL | grep depl
4359 4359 pts/0 00:00:00 depl:McuHandler
4359 4360 pts/0 00:00:00 deployer-gnulin
...
4359 4389 pts/0 00:00:05 deployer-gnulin
4359 4390 pts/0 00:00:03 deployer-gnulin
4359 4391 pts/0 00:00:00 deployer-gnulin
4359 4392 pts/0 00:00:00 depl:McuHandler

Only the thread associated with my McuHandler component is showing up,
as I have manually named it in the component's configureHook:

$ grep -C 4 pthread mcuHandler.cpp
#include <pthread.h>
bool McuHandler::configureHook()
{
pthread_setname_np(pthread_self(), "depl:McuHandler");
return true;
}

before I updated to the pthread call, I also tried the prctl method
and it worked too, so it's not a prctl vs. pthread thing.

my kernel at the moment is 3.2.0-30-generic (ubuntu 12.04)
my libc is:
$ aptitude show libc6 | grep Version
Version: 2.15-0ubuntu10

I have not studied the sources well enough to know if it's a bug, or a
feature that just isn't fully implemented yet in orocos 2.6.... anyone
know?

If someone thinks automatic thread naming is working in the latest dev
version, I can try building that with the new catkin meta meta build
system...

On Wed, Oct 30, 2013 at 9:35 PM, Paul Chavent <paul [dot] chavent [..] ...> wrote:
> Hi
>
>
> On 10/30/2013 11:23 AM, Andrew Wagner wrote:
>>
>> Hi Paul!
>>
>> I was just about to post thread naming as a feature request for
>> orocos! I manually played around a bit with adding pthread_setname_np
>> calls to my configure hooks, and trying to find the threads using top,
>> htop, ps, etc...
>>
>> I was planning to write shell scripts that grep around in /proc and
>> /sys/kernel/debug to find the processes I care about, and manage
>> priorities from there. IMHO, setting the priorities in deployer
>> scripts isn't all that great; I think it would be a lot easier to mess
>> around with priorities while your control algorithm is running
>> (assuming you won't break any hardware).
>
>
> I'm not really confident with dynamic scheduling. Otherwise the
> SCHED_DEADLINE is something i will be watching...
>
>
>>
>> Maybe it's even possible to have some semi-generalized performance
>> metrics that are also computed completely outside of your deployment
>> and component definitions...
>>
>> I glanced at your patch description. A couple comments:
>>
>> 1. It sounds like you provide a hook for setting the name of a task...
>> ideally I would like task names to be set to some sensible defaults,
>> like the class name of a (and often the only) component assigned to
>> it. I have no idea how hard this is...
>
>
> If i remember, it is already done at the component level. In ocl, for
> instance, see /deployment/DeploymentComponent.cpp in setNamedActivity around
> line 1969. For standard case, it instanciate an RTT::Activity by passing the
> component name. In rtt, rtt/Activity.cpp there is 1-1 mapping between the
> activity and the thread so the thread can be named according to the
> activity.
>
> The same thing could be done for the non periodic activity, but for an
> unknown reason, the name of the component isn't passed to the Activity ctor
> :(. It could be a trivial patch IMHO.
>
> For other kind of activities, its less easy to solve the naming of
> threads...
>
>
>
>
>>
>> 2. pthread_setname_np is a newer, ultimately, more portable way to set
>> the thread names; seems like it will be standardized POSIX if its not
>> already...
>
>
> Yes, i also prefer the pthread_setname_np. But i let the comment with
> alternative solution.
>
>
>>
>> The LTTNG suite looks interesting... sounds like these tools are
>> combining userspace debugger-like functionality (that are aware of the
>> C,C++ symbols, hopefully), with tracing at the kernel level...
>
>
> I also look for tools that could generate these kind of diagrams for strace
> outpouts... If you know some project related to this subject, i'm
> interested.
>
>>
>> Cheers,
>> Andrew
>
>
> Cheers,
> Paul.
>
>
>
>>
>> On Tue, Oct 29, 2013 at 10:20 PM, Paul Chavent <paul [dot] chavent [..] ...>
>> wrote:
>>>
>>> Hi Andrew,
>>>
>>> Some time ago, i wrote a patch
>>> (http://bugs.orocos.org/show_bug.cgi?id=1016) that allow to name threads. If
>>> you map one thread per task, it allow to see all your tasks when you call
>>> "top -H -p <pid>"...
>>>
>>> This work was done in order to use the lttng suite in order to trace my
>>> program.
>>>
>>> lttng allow to trace program (see userspace tracer http://lttng.org/ust)
>>> with a small overhead, then trace plots (http://lttng.org/eclipse).
>>>
>>> I didn't managed to import my trace in eclipse the last time i tried, but
>>> the support on the mailing list was very reactive...
>>>
>>> If you are interested, let me know. I will post more information, or even
>>> write a little page on the wiki.
>>>
>>> Regards.
>>>
>>> Paul.
>>>
>>>
>>> On 10/29/2013 10:18 AM, Andrew Wagner wrote:
>>>>
>>>> Update: Here's another example of the sort of plot that I lust after
>>>> (the last one):
>>>>
>>>>
>>>> http://www.mathworks.nl/products/xpctarget/examples.html?file=/products/...
>>>>
>>>>
>>>> Does anyone know of something like that is available for linux
>>>> threads? I'm not sure if orocos or the components even have enough
>>>> information to generate diagrams of when they were pre-empted by what.
>>>> Perhaps there is general purpose linux kernel profiling software that
>>>> could log the data needed for this diagram? i.e. some tool that I
>>>> feed the relevant PID's for the threads that I care about, and hooks
>>>> in to the scheduler to log when they were active on which cores....
>>>>
>>>> We're now running linux 3.4 with the PREEMPT RT patches (installed
>>>> from a package provided by some audio guy) if it matters:
>>>>
>>>> $ uname -a
>>>> Linux planepower-pc 3.4.29-rt41 #2 SMP PREEMPT RT Sun Feb 10 21:19:29
>>>> CET 2013 x86_64 x86_64 x86_64 GNU/Linux
>>>>
>>>> On Fri, May 31, 2013 at 1:42 PM, Sylvain Joyeux <sylvain [dot] joyeux [..] ...>
>>>> wrote:
>>>>>
>>>>> On 05/31/2013 01:25 PM, Andrew Wagner wrote:
>>>>>>
>>>>>> Hi Sylvain, thanks for the suggestion, but we don't want ROS or Rock
>>>>>> or any other meta-operating system as a dependency of our flight code.
>>>>>> Since nobody is currently maintaining a git repo for the whole
>>>>>> toolchain that you can just check out and build, we ~do use the
>>>>>> bootstrap_linux script to get a working orocos toolchain, but that's
>>>>>> it.
>>>>>
>>>>> FYI, given that you already have an orocos toolchain, the only things
>>>>> you would need additionally to get a full logger with base::Time would
>>>>> be:
>>>>>
>>>>> base/types: pure CMake package, no additional dependencies
>>>>> base/orogen/types: oroGen (you need an orogen generation step +
>>>>> then
>>>>> normal CMake compilation). No additional dependencies
>>>>> tools/logger: oroGen (you need an orogen generation step + then
>>>>> normal
>>>>> CMake compilation). No additional dependencies
>>>>> tools/pocolog: pure ruby (add pocolog/lib to RUBYLIB and
>>>>> pocolog/bin
>>>>> to PATH). No additional dependencies
>>>>>
>>>>> --
>>>>> Sylvain Joyeux (Dr.Ing.)
>>>>> Senior Researcher
>>>>>
>>>>> Space & Security Robotics
>>>>> Underwater Robotics
>>>>>
>>>>> !!! Achtung, neue Telefonnummer!!!
>>>>>
>>>>> Standort Bremen:
>>>>> DFKI GmbH
>>>>> Robotics Innovation Center
>>>>> Robert-Hooke-Straße 5
>>>>> 28359 Bremen, Germany
>>>>>
>>>>> Phone: +49 (0)421 178-454136
>>>>> Fax: +49 (0)421 218-454150
>>>>> E-Mail: robotik [..] ...
>>>>>
>>>>> Weitere Informationen: http://www.dfki.de/robotik
>>>>> -----------------------------------------------------------------------
>>>>> Deutsches Forschungszentrum fuer Kuenstliche Intelligenz GmbH
>>>>> Firmensitz: Trippstadter Straße 122, D-67663 Kaiserslautern
>>>>> Geschaeftsfuehrung: Prof. Dr. Dr. h.c. mult. Wolfgang Wahlster
>>>>> (Vorsitzender) Dr. Walter Olthoff
>>>>> Vorsitzender des Aufsichtsrats: Prof. Dr. h.c. Hans A. Aukes
>>>>> Amtsgericht Kaiserslautern, HRB 2313
>>>>> Sitz der Gesellschaft: Kaiserslautern (HRB 2313)
>>>>> USt-Id.Nr.: DE 148646973
>>>>> Steuernummer: 19/673/0060/3
>>>>> -----------------------------------------------------------------------
>>>>>
>>>>> --
>>>>> Orocos-Users mailing list
>>>>> Orocos-Users [..] ...
>>>>> http://lists.mech.kuleuven.be/mailman/listinfo/orocos-users
>>>
>>>
>>> --
>>> Orocos-Users mailing list
>>> Orocos-Users [..] ...
>>> http://lists.mech.kuleuven.be/mailman/listinfo/orocos-users
>>
>>
>

Logging timestamps for generating timing diagrams

On Di, Okt 29, 2013 at 10:18:57 +0100, Andrew Wagner wrote:
>Update: Here's another example of the sort of plot that I lust after
>(the last one):
>
>http://www.mathworks.nl/products/xpctarget/examples.html?file=/products/demos/shipping/xpc/dxpcmdsdemo.html
>
>
>Does anyone know of something like that is available for linux
>threads? I'm not sure if orocos or the components even have enough

Maybe this can help you:

https://www.osadl.org/Single-View.111+M5d51b7830c8.0.html

Markus

Logging timestamps for generating timing diagrams

Ooooo the code from the osadl website looks promising; thanks for the
link! It seems in my kernel version ( 3.4.29-rt41) that the
sched_switch tracer has been modified/merged into the wakeup/wakeup_rt
tracers.

$ cat /sys/kernel/debug/tracing/available_tracers
blk function_graph mmiotrace wakeup_rt wakeup function nop

https://lkml.org/lkml/2012/2/8/64

Hopefully the tracer output format didn't change too dramatically and
I can update the sched_switch code easily...

Cheers,
Andrew

On Tue, Oct 29, 2013 at 2:53 PM, Markus Klotzbuecher
<markus [dot] klotzbuecher [..] ...> wrote:
> On Di, Okt 29, 2013 at 10:18:57 +0100, Andrew Wagner wrote:
>>Update: Here's another example of the sort of plot that I lust after
>>(the last one):
>>
>>http://www.mathworks.nl/products/xpctarget/examples.html?file=/products/demos/shipping/xpc/dxpcmdsdemo.html
>>
>>
>>Does anyone know of something like that is available for linux
>>threads? I'm not sure if orocos or the components even have enough
>
> Maybe this can help you:
>
> https://www.osadl.org/Single-View.111+M5d51b7830c8.0.html
>
> Markus
> --
> Orocos-Users mailing list
> Orocos-Users [..] ...
> http://lists.mech.kuleuven.be/mailman/listinfo/orocos-users

Logging timestamps for generating timing diagrams

On Di, Okt 29, 2013 at 03:58:57 +0100, Andrew Wagner wrote:
>Ooooo the code from the osadl website looks promising; thanks for the
>link! It seems in my kernel version ( 3.4.29-rt41) that the
>sched_switch tracer has been modified/merged into the wakeup/wakeup_rt
>tracers.
>
>$ cat /sys/kernel/debug/tracing/available_tracers
>blk function_graph mmiotrace wakeup_rt wakeup function nop

Yes, right.

>https://lkml.org/lkml/2012/2/8/64
>
>Hopefully the tracer output format didn't change too dramatically and
>I can update the sched_switch code easily...

Good luck, it would be great if you let us know if it worked out!

Markus

Logging timestamps for generating timing diagrams

On Tue, Oct 29, 2013 at 10:18:57AM +0100, Andrew Wagner wrote:
> Update: Here's another example of the sort of plot that I lust after
> (the last one):
>
> http://www.mathworks.nl/products/xpctarget/examples.html?file=/products/...

Here is another example, but it works only for QNX:
http://www.qnx.org.uk/developers/docs/6.3.0SP3/neutrino/sys_arch/trace.h...

--
Piotr Trojanek

Logging timestamps for generating timing diagrams

On Thu, May 30, 2013 at 7:17 PM, Andrew Wagner
<andrew [dot] wagner [..] ...> wrote:
> Dear Orocos Devs,
>
> Over in HIGHWIND, we have about 10 components, and would like to log
> 2-4 timestamps per component, at up to about 100 Hz. The plan is to
> hack up a python script that scrapes a log file and generates timing
> diagrams semi-automatically, so that we can more easily sanity check
> the timing in the running system, and maybe even use the output in
> publications. I want it to look something like the output of
> drawtiming:
>
> http://drawtiming.sourceforge.net/samples.html
>
> but since I want to draw the signals to scale in time and no timing
> diagram tool I've seen actually seems to support that, I'll have to
> spend a day or so hacking up something similar in python+cairo -> svg.
>
> Anyway, to get accurately logged timestamps, should we build something
> on top of the real time logger OCL::Logging instructions from here:
>
> http://www.orocos.org/wiki/rtt/examples-and-tutorials/using-real-time-lo...
>
> or should we make an output port for every event we want to time and
> use the NetCDFReporting component?
>
> P.S. I have read the recent posts about real-time logging, and it's
> still not clear to me what the appropriate tool is.

Setting up a logging port + netcdf reporting is certainly the least
intrusive and easiest to do for logging data streams. You'd then
create a struct which contains this timestamping data and send that
struct in a single port. You'd then need matlab or kst2 (from source)
or another netcdf reader to plot your data though.

You can log + scrape your events using the real-time logging component too,
which is indeed a bit better suited for event based logs, but the
postprocessing is then your full responsibility...

Peter