Problem with a trivial timers example

[teuget]

Hi,

I am a newbie to ACE, and started to play around with some of the
tutorial examples to get a feel for how things work. I did run into a
strange problem with timers, and I cannot figure out what I do wrong.

The problem is that my handle_timeout() method only gets called when I
use very specific ACE_Time_Values. Any time value >=1 sec will not
work at all. The timeouts just never occur. When I use only musecs it
sort of works, but erratic, e.g. it stops rescheduling after some 12
expirations.

Note that I am running this code on VMWare. Is anyone aware of
timer-related problems on such an environment? If anyone can hint me at
what I'm doing wrong, I'd appreciate it!

Below the code. The main application sets up the TimerQueue and the
Timer object of class "Hello".

>>>>>>>
#define ACE_NTRACE 0

#include "ace/OS.h"
#include "ace/Log_Msg.h"
#include "ace/Timer_Queue_Adapters.h"
#include "ace/Timer_Heap.h"

#include "HelloMain.h"
#include "Hello.h"

typedef ACE_Thread_Timer_Queue_Adapter<ACE_Timer_Heap> TimerQueue;

int ACE_TMAIN(int, ACE_TCHAR *[])
{
ACE_TRACE(ACE_TEXT("main"));

// Instantiate and start timer infrastructure
TimerQueue vTQ;
vTQ.activate();

// Timer callback implemented here
Hello vHello;

printf("XXX CALLING SCHEDULE()\n");
ACE_Time_Value vCurTime = vTQ.timer_queue()->gettimeofday();
//vTQ.schedule(&vHello, NULL, vCurTime + ACE_Time_Value(1, 0),
ACE_Time_Value(1,0)); // does not work, timeout never called
//vTQ.schedule(&vHello, NULL, vCurTime + ACE_Time_Value(0, 1000),
ACE_Time_Value(1,0)); // works once
vTQ.schedule(&vHello, NULL, vCurTime + ACE_Time_Value(0, 1000),
ACE_Time_Value(0,1000)); // works 12 times

printf("XXX CALLING WAIT()\n");
ACE_Thread_Manager::instance()->wait();
printf("XXX RETURNING FROM WAIT()\n"); // not reached
return 0;
}
<<<<<

For completeness, this is what Hello looks like;

>>>>>>
#define ACE_NTRACE 0

#include "ace/OS.h"
#include "ace/Log_Msg.h"
#include "Hello.h"

Hello::Hello()
{
ACE_TRACE(ACE_TEXT("Hello World - in constructor"));
}

Hello::~Hello()
{
ACE_TRACE(ACE_TEXT("Hello World - in destructor"));
}

int Hello::handle_timeout (const ACE_Time_Value &current_time, const
void *act)
{
ACE_TRACE(ACE_TEXT("Hello World - handle_timeout"));
printf("XXX TIMEOUT\n");
return 0;
}
<<<<<<<

Thanks, Tom!

[Douglas C. Schmidt]

Hi Tom,

>I am a newbie to ACE,

Welcome!

>and started to play around with some of the
>tutorial examples to get a feel for how things work. I did run into a
>strange problem with timers, and I cannot figure out what I do wrong.

To ensure that we have proper version/platform/compiler information,
please make sure you fill out the appropriate problem report form
(PRF), which is in

$ACE_ROOT/PROBLEM-REPORT-FORM
$TAO_ROOT/PROBLEM-REPORT-FORM

or in

$ACE_ROOT/BUG-REPORT-FORM
$TAO_ROOT/BUG-REPORT-FORM

in older versions of ACE+TAO. Make sure to include this information
when asking any questions about ACE+TAO since otherwise we have to
"guess" what version/platform/compiler/options you've using, which is
very error-prone and slows down our responsiveness. If you don't use
the PRF, therefore, it is less likely that someone from the core
ACE+TAO developer team will be able to answer your question.
Naturally, we encourage and appreciate other members of the ACE+TAO
user community who can respond to questions that they have the answers
to.

>The problem is that my handle_timeout() method only gets called when I
>use very specific ACE_Time_Values. Any time value >=1 sec will not
>work at all. The timeouts just never occur. When I use only musecs it
>sort of works, but erratic, e.g. it stops rescheduling after some 12
>expirations.
>
>Note that I am running this code on VMWare. Is anyone aware of
>timer-related problems on such an environment? If anyone can hint me at
>what I'm doing wrong, I'd appreciate it!
>
>Below the code. The main application sets up the TimerQueue and the
>Timer object of class "Hello".

I just tried running this on my Linux machine and everything worked just
fine, so I think there's something wrong with your VMWare configuration
(what this problem might be is a mystery to me ;-)). Here's the test
program that I used.

Take care,

Doug

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

// #define ACE_NTRACE 0

#include "ace/OS.h"
#include "ace/Log_Msg.h"
#include "ace/Timer_Queue_Adapters.h"
#include "ace/Timer_Heap.h"

class Hello : public ACE_Event_Handler
{
public:
Hello ()

{
ACE_TRACE(ACE_TEXT("Hello World - in constructor"));
}

~Hello()

{
ACE_TRACE(ACE_TEXT("Hello World - in destructor"));
}

int handle_timeout (const ACE_Time_Value &current_time, const void *act)

{
ACE_TRACE(ACE_TEXT("Hello World - handle_timeout"));

ACE_DEBUG((LM_DEBUG, "(%t) XXX TIMEOUT\n"));
return 0;
}
};

typedef ACE_Thread_Timer_Queue_Adapter<ACE_Timer_Heap> TimerQueue;

int ACE_TMAIN(int, ACE_TCHAR *[])
{
ACE_TRACE(ACE_TEXT("main"));

// Instantiate and start timer infrastructure
TimerQueue vTQ;
vTQ.activate();

// Timer callback implemented here
Hello vHello;

ACE_DEBUG((LM_DEBUG, "(%t) CALLING SCHEDULE()\n"));

ACE_Time_Value vCurTime = vTQ.timer_queue()->gettimeofday();

// vTQ.schedule(&vHello, NULL, vCurTime + ACE_Time_Value(1, 0), ACE_Time_Value(1,0)); // does not work, timeout never called
// vTQ.schedule(&vHello, NULL, vCurTime + ACE_Time_Value(0, 1000), ACE_Time_Value(1,0)); // works once

vTQ.schedule(&vHello, NULL, vCurTime + ACE_Time_Value(0, 1000), ACE_Time_Value(0,1000)); // works 12 times

ACE_DEBUG ((LM_DEBUG, "(%t) CALLING WAIT()\n"));
ACE_Thread_Manager::instance()->wait();
ACE_DEBUG ((LM_DEBUG, "(%t) RETURNING FROM WAIT()\n")); // not reached
return 0;
}

[Martin Corino]

Hi Tom,

On Thursday 02 November 2006 18:50, Douglas C. Schmidt wrote:
<snip>

>
> >The problem is that my handle_timeout() method only gets called when I
> >use very specific ACE_Time_Values. Any time value >=1 sec will not
> >work at all. The timeouts just never occur. When I use only musecs it
> >sort of works, but erratic, e.g. it stops rescheduling after some 12
> >expirations.
> >
> >Note that I am running this code on VMWare. Is anyone aware of
> >timer-related problems on such an environment?

I know from personal experience that depending on your host CPU and host
OS/guest OS combination VMWare guests can display weird timing effects.
In general it's difficult to reliably test timings in Virtual Machines.

regards,
Martin.

> _______________________________________________
> ace-users mailing list
> ace-...@mail.cse.wustl.edu
> http://mail.cse.wustl.edu/mailman/listinfo/ace-users

--
----------------------------------------------------------------------
                           Martin J.N. Corino | Remedy IT Expertise BV
          Postbus 101 |  2650 AC Berkel en Rodenrijs | The Netherlands
                       tel: +31 (10) 522 0139 | fax: +31 (33) 246 6511
                                  World Wide Web: http://www.remedy.nl
----------------------------------------------------------------------

[Martin Corino]

[teuget]

Tx for quick reactions. I dug some more into the problem and traced it
down to weird behavior (or my lack of understanding) of
ACE_Condition.wait(). PRF below.

ACE VERSION: 5.5.3

HOST MACHINE and OPERATING SYSTEM: SUSE Linux 10.1 on VMWare, Intel

TARGET MACHINE and OPERATING SYSTEM, if different from HOST: same

COMPILER NAME AND VERSION (AND PATCHLEVEL): gcc 4.1.0

THE $ACE_ROOT/ace/config.h FILE : config-linux.h

THE $ACE_ROOT/include/makeinclude/platform_macros.GNU FILE :
platform_linux.GNU

CONTENTS OF
$ACE_ROOT/bin/MakeProjectCreator/config/default.features
(used by MPC when you generate your own makefiles): not found

AREA/CLASS/EXAMPLE AFFECTED:
ACE_Condition.wait(const ACE_Time_Value*)

DOES THE PROBLEM AFFECT:
EXECUTION

SYNOPSIS:
ACE_Condition.wait(const ACE_Time_Value*) never comes out of 1-sec
wait.

DESCRIPTION:
I stumbled over this problem while trying the "Active Timer" example
from the tutorials.
Timers were never fired. I traced the problem down to a
condition.wait() call that does
not seem to honor its timeout. Below the example code - it does a 1-sec
wait on a condition which never returns. This sort of mimics the inner
workings of the timer thread which also never comes out of the wait()
call.

#define ACE_NTRACE 0

#include "ace/config.h"
#include "ace/OS.h"
#include "ace/Thread_Manager.h"
#include "ace/Condition_Recursive_Thread_Mutex.h"

class ConditionTest
{
public:
ConditionTest(void): condition_(mutex_) {};
virtual ~ConditionTest(void) {};

ACE_SYNCH_RECURSIVE_MUTEX mutex_;
ACE_SYNCH_RECURSIVE_CONDITION condition_;

int test()
{
ACE_GUARD_RETURN (ACE_SYNCH_RECURSIVE_MUTEX, guard, this->mutex_,
-1);
ACE_ERROR ((LM_ERROR, ACE_TEXT("ZZZ CALLING WAIT\n")));
const ACE_Time_Value vExpTime = ACE_OS::gettimeofday() +
ACE_Time_Value(1,0);
this->condition_.wait(&vExpTime); // expect this to return in 1 sec,
but doesn't
ACE_ERROR ((LM_ERROR, ACE_TEXT("ZZZ WAIT RETURNING\n"))); // not
reached
return 0; // not reached
}
};

int ACE_TMAIN(int, ACE_TCHAR *[])
{

ACE_ERROR ((LM_ERROR, ACE_TEXT("XXX Condition Test()\n"))); // not
reached
ConditionTest vCT;
vCT.test(); // this never returns
return 0; // not reached
}

Oddly enough, the ACE test suite reports no problems with the
Recursive_Condition_Test. I must therefore be doing something wrong
when building / linking my test application. I included the output of
the eclipse managed make build below. I tried linking with the exact
same set and ordering of libs as the test suite, but no luck so far.
Any hints appreciated, because I have no clue I'm doing wrong.

**** Build of configuration Debug for project HelloMain ****

make -k all
Building file: ../HelloMain.cpp
Invoking: GCC C++ Compiler
g++ -I/data/ACE_wrappers -O0 -g3 -Wall -c -fmessage-length=0 -MMD -MP
-MF"HelloMain.d" -MT"HelloMain.d" -o"HelloMain.o" "../HelloMain.cpp"
Finished building: ../HelloMain.cpp

Building target: HelloMain
Invoking: GCC C++ Linker
g++ -nodefaultlibs -L/data/ACE_wrappers/build/ace/.libs -pthread
-o"HelloMain" ./HelloMain.o -lm -lc -lgcc_s -lACE -lstdc++ -lrt -ldl
Finished building target: HelloMain

Build complete for project HelloMain

REPEAT BY:
I just run the above app. In my case, the last output I see is "ZZZ
CALLING WAIT" and then it hangs.

SAMPLE FIX/WORKAROUND:
No clue.

Thanks! Tom.

[Douglas C. Schmidt]

Hi Tom,

>Tx for quick reactions. I dug some more into the problem and traced it
>down to weird behavior (or my lack of understanding) of
>ACE_Condition.wait(). PRF below.

This looks like another problem with VMWare and/or the way you're
build your application. If things are working fine for the existing
ACE tests I recommend you try reusing one of the existing project
files in the ACE_ROOT/tests directory as the basis for your tests to
see if you can get things working that way.

Thanks,

Doug

--
Dr. Douglas C. Schmidt Professor and Associate Chair
Electrical Engineering and Computer Science TEL: (615) 343-8197
Vanderbilt University WEB: www.dre.vanderbilt.edu/~schmidt
Nashville, TN 37203 NET: d.sc...@vanderbilt.edu

[teuget]

Just a follow-up. There was indeed some mysterious problem with the
output of the earlier ACE build. May have been a filesystem issue. In
any case, a clean rebuild of ACE fixed my problems. Everything now
works fine.

Thanks!

Tom

[Douglas C. Schmidt]

Hi Tom,

>Just a follow-up. There was indeed some mysterious problem with the
>output of the earlier ACE build. May have been a filesystem issue. In
>any case, a clean rebuild of ACE fixed my problems. Everything now
>works fine.

That's great news!! Thanks for letting us know.

Doug