inconsistent reporting period

I am running rtt_2.0 and ocl_2.0.

To save a number of experimental data (robot positions, drive voltages et
cetera), I would like to report data from dataports to a text file at a
fixed period (in the example code below with a period of 1 second). For this
I have added an OCL::FileReporting component to my deploy file. The deploy
file also contains an nAxesGenerator and robot control components running in
real time (ORO_SCHED_RT) at 1 millisecond periods. The reporting component
is running in non-realtime (ORO_SCHED_OTHER), since it has non-real time
activities (writing to the hard disk).

When I only start the reporting component, it is indeed running at 1 second
intervals (in the example below I first started the reporting component and
then started the other components around 37 seconds later). From the moment
I start the other components however I see extremely inconsistent reporting
behavior: I get data in the file much faster but at very irregular intervals
than the 1 second intervals it should be.

I can fully understand that, since the reporting activity is non-realtime,
under heavy system load I would get missing reporting data, but I don't see
why there is reporting data faster than the 1 second interval the reporting
component should be running. The update hook seems to get triggered by
something??

Below I have included part of the deploy file, the reporter cpf file and the
resulting reports.txt.

Any idea what is going wrong?

Merci par avance,
Sebastien

---

part of the deploy file:

<struct name="Reporter" type="OCL::FileReporting">
<struct name="Activity" type="PeriodicActivity">
<simple name="Period" type="double"><value>1<value><simple>
<simple name="Priority" type="short"><value>0<value><simple>
<simple
name="Scheduler"type="string"><value>ORO_SCHED_OTHER<value><simple>
<struct>
<simple name="AutoConf" type="boolean"><value>1<value><simple>
<simple name="AutoStart" type="boolean"><value>0<value><simple>
<simple
name="LoadProperties"type="string"><value>controllerreporter.cpf<value><simple>
<struct name="Peers" type="PropertyBag">
<simple type="string"><value>nAxesGeneratorPos<value><simple>
<simple type="string"><value>nAxesControllerPosVel<value><simple>
<simple type="string"><value>CRSnAxesVelocityController<value><simple>
<struct>
<struct>

---

reporter cpf file:

<?xml version="1.0" encoding="UTF-8"?>
&lt;!DOCTYPE properties SYSTEM "cpf.dtd"&gt;
<properties>
<simple name="AutoTrigger" type="boolean"><description>When set to
1, the data is taken upon each update(), otherwise, the data is only
taken when the user invokes
'snapshot()'.<description><value>1<value><simple>
<simple name="WriteHeader" type="boolean"><description>Set to true to
start each report with a header.<description><value>1<value><simple>
<simple name="Decompose" type="boolean"><description>Set to false in order
to create multidimensional array in
netcdf<description><value>0<value><simple>
<simple name="ReportFile" type="string"><description>Location ondisc to
store the reports.<description><value>report.txt<value><simple>
<simple name="Synchronize" type="boolean"><description>Set to true if the
timestamp should be synchronized with the
logging<description><value>0<value><simple>
<simple name="NullSample" type="string"><description>The characters
written to the log to indicate that no new data was available for that port
during a snapshot(). As a special value, the string 'last' is interpreted as
repeating the last value.<description><value>last<value><simple>

<struct name="ReportData" type="PropertyBag">
<description>A PropertyBag which defines which ports or components to
report.<description>
<simple name="Port" type="string"><description>Report all output ports
of this
component.<description><value>nAxesGeneratorPos.nAxesDesiredPosition<value><simple>
<simple name="Port" type="string"><description>Report all output ports
of this
component.<description><value>nAxesGeneratorPos.nAxesDesiredVelocity<value><simple>
<simple name="Port" type="string"><description>Report all output ports
of this
component.<description><value>CRSnAxesVelocityController.Position_Value<value><simple>
<simple name="Port" type="string"><description>Report all output ports
of this
component.<description><value>CRSnAxesVelocityController.OuputVoltage<value><simple>
<simple name="Port" type="string"><description>Report all output ports
of this
component.<description><value>nAxesControllerPosVel.nAxesOutputVelocity<value><simple>
<struct>
<properties>

---

resulting reports.txt file

TimeStamp nAxesGeneratorPos.nAxesDesiredPosition
nAxesGeneratorPos.nAxesDesiredVelocity
CRSnAxesVelocityController.Position_Value
CRSnAxesVelocityController.OuputVoltage
nAxesControllerPosVel.nAxesOutputVelocity
34.429 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
0.686967 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
1.68697 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
2.68697 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
3.68697 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
4.68697 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
5.68697 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
6.68697 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
7.68697 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
8.68697 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
9.68697 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
10.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
11.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
12.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
13.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
14.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
15.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
16.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
17.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
18.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
19.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
20.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
21.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
22.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
23.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
24.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
25.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
26.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
27.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
28.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
29.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
30.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
31.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
32.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
33.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
34.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
35.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
36.687 {0, 0, 0, 0}
{0, 0, 0, 0}
{} {} {0,
0, 0, 0}
37.687 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.5,
0.05, 0.05, -0.05} {0, 0, 0, 0}
37.6886 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.525253, 0.0904048,
0.0651518, -0.0853542} {0, 0, 0, 0}
37.689 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.549696, 0.142079,
-0.11769, -0.119574} {0, 0, 0, 0}
37.6897 {0, 0, 0, 0}
{0, 0, 0, 0} {} {-0.227462, 0.182028,
-0.103367, -0.154529} {0, 0, 0, 0}
37.6901 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.177315, 0.234019,
-0.0957996, -0.189025} {0, 0, 0, 0}
37.6907 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.209054, 0.274885,
0.11077, -0.224784} {0, 0, 0, 0}
37.6911 {0, 0, 0, 0}
{0, 0, 0, 0} {} {-0.191248, 0.314467,
0.320815, -0.259417} {0, 0, 0, 0}
37.6917 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.231532, 0.354914,
0.145493, -0.294809} {0, 0, 0, 0}
37.6921 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.644076, 0.381053,
0.359524, -0.328675} {0, 0, 0, 0}
37.6929 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.266433, 0.420854,
0.179645, -0.363501} {0, 0, 0, 0}
37.6936 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.670179, 0.255886,
0.414827, -1.49908} {0, 0, 0, 0}
37.6941 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.478383, 0.255886,
0.247477, -1.54171} {0, 0, 0, 0}
37.6947 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.0839784, 0.255886,
0.436956, -1.55486} {0, 0, 0, 0}
37.6951 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.478308, 0.255886,
0.239011, -1.58977} {0, 0, 0, 0}
37.6957 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.479555, 0.255886,
0.424023, -1.6029} {0, 0, 0, 0}
37.6961 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.487371, 0.255886,
0.231549, -1.638} {0, 0, 0, 0}
37.6967 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.481213, 0.255886,
0.410833, -1.65109} {0, 0, 0, 0}
37.6971 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.479707, 0.255886,
0.405106, -1.68588} {0, 0, 0, 0}
37.6981 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.486786, 0.255886,
0.404868, -1.69907} {0, 0, 0, 0}
37.6988 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.485364, 0.255886,
0.399191, -1.73394} {0, 0, 0, 0}
37.6992 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.494268, 0.255886,
0.207413, -1.74726} {0, 0, 0, 0}
37.6999 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.484639, 0.255886,
0.578927, -1.78203} {0, 0, 0, 0}
37.7002 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.489741, 0.255886,
0.38769, -1.81691} {0, 0, 0, 0}
38.687 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.486693, 0.255886,
0.380976, -1.8299} {0, 0, 0, 0}
38.6875 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.0835442, 0.255886,
0.571164, -1.86463} {0, 0, 0, 0}
38.6898 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.469402, 0.255886,
0.566544, -1.87727} {0, 0, 0, 0}
38.6904 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.490909, 0.255886,
0.38384, -1.91227} {0, 0, 0, 0}
38.691 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.489237, 0.255886,
0.765377, -1.92541} {0, 0, 0, 0}
38.6915 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.488832, 0.255886,
0.576369, -1.9385} {0, 0, 0, 0}
38.6924 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.516415, 0.255886,
0.589835, -1.97413} {0, 0, 0, 0}
38.693 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.501716, 0.255886,
0.582964, -1.9875} {0, 0, 0, 0}
38.6935 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.463932, 0.255886,
0.564917, -1.99975} {0, 0, 0, 0}
38.6941 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.496241, 0.255886,
0.774259, -2.01289} {0, 0, 0, 0}
38.6948 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.125579, 0.255886,
0.234707, -1.33635} {0, 0, 0, 0}
38.6952 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.517819, 0.255886,
0.230466, -1.32789} {0, 0, 0, 0}
38.6959 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.536625, 0.255886,
0.232965, -1.28892} {0, 0, 0, 0}
38.6963 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.107004, 0.255886,
0.0168355, -1.28013} {0, 0, 0, 0}
38.6969 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.515604, 0.255886,
0.21029, -1.27168} {0, 0, 0, 0}
38.6982 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.504901, 0.255886,
0.198677, -1.26287} {0, 0, 0, 0}
38.6989 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.509194, 0.255886,
0.19666, -1.23238} {0, 0, 0, 0}
38.6994 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.51842, 0.255886,
0.00490829, -1.2239} {0, 0, 0, 0}
38.7 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.51143, 0.255886,
0.183842, -1.21517} {0, 0, 0, 0}
38.7004 {0, 0, 0, 0}
{0, 0, 0, 0} {} {0.127488, 0.255886,
0.188296, -1.20681} {0, 0, 0, 0}

inconsistent reporting period

On Monday 23 August 2010 19:18:51 seb ferris wrote:
> I am running rtt_2.0 and ocl_2.0.
>
> To save a number of experimental data (robot positions, drive voltages et
> cetera), I would like to report data from dataports to a text file at a
> fixed period (in the example code below with a period of 1 second). For
> this I have added an OCL::FileReporting component to my deploy file. The
> deploy file also contains an nAxesGenerator and robot control components
> running in real time (ORO_SCHED_RT) at 1 millisecond periods. The
> reporting component is running in non-realtime (ORO_SCHED_OTHER), since it
> has non-real time activities (writing to the hard disk).
>
> When I only start the reporting component, it is indeed running at 1 second
> intervals (in the example below I first started the reporting component and
> then started the other components around 37 seconds later). From the moment
> I start the other components however I see extremely inconsistent reporting
> behavior: I get data in the file much faster but at very irregular
> intervals than the 1 second intervals it should be.

You can run the reporter 'sampling' based (periodic) or event base (non
periodic).

When the thread is periodic, 'trigger()' is ignored, so the inconsistent
sampling is not due to that. I believe that it just logs all values that were
written to the port being reported, and does so 'every second'.

This is probably not what you expected. We could change the reporter that when
it's sampling, only the most recent sample is printed, and when it is event
driven, all data is logged.

Peter