Re: [Xenomai] Round robin scheduling seem not working in a specific case...

[Christophe Carton <christophe.carton@ixblue.com>]

Le 05/11/2014 14:33, Philippe Gerum a écrit :
> On 11/05/2014 12:25 PM, Christophe Carton wrote:
>> Le 04/11/2014 15:09, Christophe Carton a écrit :
>>> Le 04/11/2014 15:05, Philippe Gerum a écrit :
>>>> On 11/04/2014 02:49 PM, Christophe Carton wrote:
>>>>> Le 04/11/2014 14:22, Philippe Gerum a écrit :
>>>>>> On 11/04/2014 12:46 PM, Gilles Chanteperdrix wrote:
>>>>>>> On Tue, Nov 04, 2014 at 12:43:00PM +0100, Philippe Gerum wrote:
>>>>>>>> On 11/04/2014 11:34 AM, Christophe Carton wrote:
>>>>>>>>> Hello,
>>>>>>>>>
>>>>>>>>> I am currently working with Xenomai 2.6.4 with native skin and
>>>>>>>>> with a
>>>>>>>>> Linux kernel 3.14.17.
>>>>>>>>> The linux and the xenomai have been taken from the following Git
>>>>>>>>> repositories :
>>>>>>>>> * http://git.xenomai.org/xenomai-2.6.git - tag v2.6.4
>>>>>>>>> * http://git.xenomai.org/ipipe.git - tag ipipe-core-3.14.17-x86-4
>>>>>>>>>
>>>>>>>>> I am encountering a problem to enable the Round Robin scheduler
>>>>>>>>> in a
>>>>>>>>> specific case :
>>>>>>>>> * Two tasks ("rr task 1" and "rr task 2") of priority 10 are
>>>>>>>>> launched by
>>>>>>>>> a task ("init task") of priority 90.
>>>>>>>>> * All 3 of them are configured with a RR scheduler via
>>>>>>>>> "rt_task_slice"
>>>>>>>>> API before they are started.
>>>>>>>>> In this case the FIFO scheduling seems to be applied (could be seen
>>>>>>>>> via
>>>>>>>>> rt_printf logs).
>>>>>>>>>
>>>>>>>>> I have found a thread on the mailing list that gives an example
>>>>>>>>> demonstrating the good behavior of the RR scheduler.
>>>>>>>>> http://www.xenomai.org/pipermail/xenomai/2011-November/024897.html
>>>>>>>>> http://www.xenomai.org/pipermail/xenomai/2011-November/024899.html
>>>>>>>>> This example implies that the tasks are locked via a semaphore at
>>>>>>>>> startup and that this semaphore is unlocked by the main when all
>>>>>>>>> threads
>>>>>>>>> have been started.
>>>>>>>>> This is necessary in this case due to the fact that the main
>>>>>>>>> function is
>>>>>>>>> no an RT task.
>>>>>>>>>
>>>>>>>>> This implementation (with the semaphore) applied to my test
>>>>>>>>> works. Why
>>>>>>>>> is the semaphore needed in my case?
>>>>>>>> init_task() is switched to non-rt mode by rt_task_create(), so
>>>>>>>> that a
>>>>>>>> regular pthread is first created by the glibc, prior to extending it
>>>>>>>> with Xenomai capabilities. In 2.6.x, this operation leaves the
>>>>>>>> caller
>>>>>>>> (i.e. init_task() in your case) in relaxed/secondary mode, which
>>>>>>>> means
>>>>>>>> that it is assigned the lowest priority level in the Xenomai
>>>>>>>> scheduler,
>>>>>>>> below the RR class.
>>>>>>>>
>>>>>>>> Given that, in your code, no Xenomai syscall following the first
>>>>>>>> rt_task_create() have the requirement to switch the caller back to
>>>>>>>> primary/rt mode, including rt_task_start() which is issued for
>>>>>>>> task_1.
>>>>>>>> Hence init_task() won't compete with task() which is assigned the
>>>>>>>> real-time RR priority you asked for on entry.
>>>>>>>>
>>>>>>>> IOW, if you don't make the children wait on a barrier until the
>>>>>>>> parent
>>>>>>>> has set the whole thing up, the first call to rt_task_start() will
>>>>>>>> unleash task_1, which will in turn start spinning immediately in its
>>>>>>>> work loop as init_task() is on a lower priority level, locking up
>>>>>>>> CPU#1.
>>>>>>>>
>>>>>>> Right. You can probably avoid that by enabling the deprecated option
>>>>>>> CONFIG_XENO_OPT_PRIOCPL in the kernel configuration.
>>>>>>>
>>>>>> I would not recommend to rely on this option, as you know we killed it
>>>>>> in 3.x because we could never have it working 100% reliably. The only
>>>>>> sane way otherwise is to synchronize the parent and the child thread
>>>>>> internally at thread creation to preserve the priority order, without
>>>>>> requiring the start call to switch to secondary mode, but only 3.x
>>>>>> implements this.
>>>>>>
>>>>> Thanks for your replies.
>>>>> I do now understand why my code example is not working like I supposed
>>>>> it should have.
>>>>>
>>>>> It looks like rt_task_create() and rt_task_start() switches the caller
>>>>> in relaxed/secondary mode. This explains the behavior that I have
>>>>> noticed.
>>>>> I have read the doxygen documentation about those two API and I did not
>>>>> find this behavior explained.
>>>>> How could we know which API switches the caller's mode to primary/rt or
>>>>> to relaxed/secondary or maybe does not affect the mode?
>>>>>
>>>> This behavior was not documented in the 2.6.x series, which is clearly
>>>> unfortunate. As a suggestion, here is fallback option :
>>>>
>>>> - first refer to the 3.x documentation for the same call, looking for
>>>> the service "Tags" section, e.g. for rt_task_create() that would be:
>>>> http://www.xenomai.org/documentation/xenomai-3/html/xeno3prm/group__alchemy__task.html#ga03387550693c21d0223f739570ccd992
>>>>
>>>> with tags mentioning "thread-unrestricted, switch-secondary".
>>>> Clicking on the tags will get you the explanation:
>>>> http://www.xenomai.org/documentation/xenomai-3/html/xeno3prm/api-tags.html
>>>>
>>>>
>>>> - then cross-check with the 2.x -> 3.x migration info that the
>>>> documented behavior did not change, or in which way it did change. For
>>>> the task-related stuff from the API you are using, the info would be
>>>> there:
>>>> http://xenomai.org/migrating-from-xenomai-2-x-to-3-x/#Task_management
>>>>
>>>> Well, ok. I agree in advance that it's not that handy.
>>>>
>>> OK.
>>> I will do with this fallback option for the moment until I migrate to
>>> Xenomai 3.x.
>>> Thanks to the team for the quick replies.
>>>
>>> Best regards,
>>>
>> Hi,
>>
>> I have taken into account your previous replies and added after
>> rt_task_create(), rt_task_set_mode(0, T_CONFORMING, nullptr) to set
>> init_task()'s mode from relaxed/secondary mode to primary/rt mode.
>> task_1 and task_2 are launched when init_task() calls the rt_task_join()
>> which is the waited behavior.
>> Nevertheless, they are are still not scheduled in RR...
>> As init_task() is in primary/rt mode and of higher priority than task_1
>> and task_2, shouldn't we have task_1 and task_2 launched "at the same
>> time" and scheduled in RR?
> No. As I mentioned in my previous reply on this issue, rt_task_start()
> does switch to secondary mode as well. Sidenote: switching modes
> manually via rt_task_set_mode() from the application code is almost
> always a bad idea. The kernel knows better when doing so is required and
> efficient; raising the conforming flag is normally reserved to internal
> library code.
>

Hum...
Then I still have a problem. My logs does not demonstrate this behavior.
If rt_task_start() switches the caller to secondary mode, I should see 
in my logs :
* Logs related to the beginning of init_task(),
* Logs related to task_1(), (init_task in secondary mode => lowest level)
* Logs related task_2(),
* Logs related to the end of init_task().
But, logs of task_1 and task_2() are displayed after all the logs of 
init_task().

--------------------------- Start of log ---------------------------
*---------------------------------------*
* Step 1 - start of init_task() => OK
*---------------------------------------*
[init_task]
     - Mode switches = 0
     - Base Prio     = 90
     - Current Prio  = 90
[rt_task_create 2]
     - Mode switches = 1
     - Base Prio     = 90
     - Current Prio  = 90
*---------------------------------------*
* Step 2 - call to rt_task_start() done here
* (The following logs are generated after the call to both rt_task_start())
*---------------------------------------*
[rt_task_start 2]
     - Mode switches = 1
     - Base Prio     = 90
     - Current Prio  = 90
*---------------------------------------*
* Step 3 - start of task_2 starts here => KO? => should be done before 
previous log (just after Step 2)... no?
*---------------------------------------*
[task]
     - Mode switches = 0
     - Base Prio     = 10
     - Current Prio  = 10
141582241865329 Running [rr task 2] priority [10] at : [328250 ns]
141582241865559 Running [rr task 2] priority [10] at : [652314 ns]
141582241865791 Running [rr task 2] priority [10] at : [976721 ns]
141582241866023 Running [rr task 2] priority [10] at : [1300607 ns]
...
141582241904786 Running [rr task 2] priority [10] at : [55220227 ns]
141582241905017 Running [rr task 2] priority [10] at : [55535826 ns]
141582241905248 Running [rr task 2] priority [10] at : [55858857 ns]
141582241905478 Running [rr task 2] priority [10] at : [56176394 ns]
[task]
     - Mode switches = 0
     - Base Prio     = 10
     - Current Prio  = 10
141582241937353 Running [rr task 1] priority [10] at : [369341 ns]
141582241937580 Running [rr task 1] priority [10] at : [709177 ns]
141582241937808 Running [rr task 1] priority [10] at : [1038358 ns]
141582241938038 Running [rr task 1] priority [10] at : [1363228 ns]
...
141582242008366 Running [rr task 1] priority [10] at : [99105804 ns]
141582242008594 Running [rr task 1] priority [10] at : [99435278 ns]
141582242008825 Running [rr task 1] priority [10] at : [99755428 ns]
141582242009055 Running [rr task 1] priority [10] at : [100071315 ns]

--------------------------- End of log ---------------------------

Moreover, logs of task_2 are displayed before logs of task_1.

Best regards

-- 

*Christophe Carton *


-------------- next part --------------
#include <stdlib.h>
#include <unistd.h>
#include <sys/mman.h>
#include <math.h>
#include <assert.h>

#include <xenomai/native/timer.h>
#include <xenomai/native/task.h>
#include <xenomai/native/sem.h>

#include <rtdk.h>

#define NB_TASKS (2UL)

#define EXECTIME_NS (100e6) // 100 ms
#define WORKTIME_NS (500e3) // 500 µs
#define CPU_ID (1)
RT_SEM synchro_sem;

RTIME slice = 2; //rt_timer_ns2ticks(20000);

#define ERROR_MGR(fct) \
do { \
	int err = fct; \
	if ( err != 0 ) \
	{ \
		rt_fprintf(stderr, "%s-%s error %d\n", __FUNCTION__, #fct, err); \
		abort(); \
	} \
}while(0)

#define TASK_INQUIRE(str) \
do \
{ \
	RT_TASK_INFO info; \
	ERROR_MGR( rt_task_inquire(nullptr, &info) ); \
	rt_printf( \
		"[%s]\n" \
		"\t- Mode switches = %d\n" \
		"\t- Base Prio     = %d\n" \
		"\t- Current Prio  = %d\n", \
		str, \
		info.modeswitches, \
		info.bprio, info.cprio); \
} while(0)

#define TASK2PRIMARY() \
do { \
	ERROR_MGR( rt_task_set_mode(0, T_CONFORMING, nullptr) ); \
}while(0)

static void task(void *)
{
	TASK_INQUIRE(__FUNCTION__);

//	ERROR_MGR( rt_task_sleep(rt_timer_ns2ticks(500000000)) );
//	ERROR_MGR( rt_sem_p(&synchro_sem, TM_INFINITE) );

	RT_TASK_INFO curtaskinfo;
	RT_TASK *curtask = nullptr;
	ERROR_MGR( rt_task_inquire(curtask, &curtaskinfo) );
	for(  ; curtaskinfo.exectime < EXECTIME_NS ;  )
	{
		rt_timer_spin(WORKTIME_NS);
		// dummy average processing
		ERROR_MGR( rt_task_inquire(curtask, &curtaskinfo) );
		RTIME timepoint = rt_timer_read();
		rt_printf(
				"%lu Running [%s] priority [%d] at : [%lu ns]\n",
				timepoint,
				curtaskinfo.name,
				curtaskinfo.cprio,
				curtaskinfo.exectime);
	}
}

static void init_task(void *)
{
	RT_TASK task_desc_1, task_desc_2;

	TASK_INQUIRE(__FUNCTION__);

	ERROR_MGR( rt_task_create ( &task_desc_1, "rr task 1", 0, 10, T_JOINABLE | T_CPU(CPU_ID) ) );

	ERROR_MGR( rt_task_create ( &task_desc_2, "rr task 2", 0, 10, T_JOINABLE | T_CPU(CPU_ID) ) );
	TASK_INQUIRE("rt_task_create 2");
	TASK2PRIMARY();

//	rt_printf("slice ticks = %lu\n", slice);
	ERROR_MGR( rt_task_slice( &task_desc_1, slice ) );

	ERROR_MGR( rt_task_slice( &task_desc_2, slice ) );

	ERROR_MGR( rt_task_start( &task_desc_1, &task, nullptr ) );

	ERROR_MGR( rt_task_start( &task_desc_2, &task, nullptr ) );
	TASK_INQUIRE("rt_task_start 2");

//	rt_printf("Launch!!!\n");
//	rt_task_sleep(rt_timer_ns2ticks(500000000UL));
//	ERROR_MGR( rt_sem_broadcast(&synchro_sem) );

	ERROR_MGR( rt_task_join( &task_desc_1 ) );
	ERROR_MGR( rt_task_join( &task_desc_2 ) );
}

int main (int argc, char* argv[])
{
	(void)argc;
	(void)argv;
	RT_TASK init_task_desc;
	
	ERROR_MGR( mlockall( MCL_CURRENT | MCL_FUTURE ) );

	rt_print_auto_init(1);

	// semaphore to sync task startup on
	ERROR_MGR( rt_sem_create(&synchro_sem, "Synchro sem", 0, S_FIFO) );

	ERROR_MGR( rt_task_create( &init_task_desc, "init task", 0, 90, T_JOINABLE | T_CPU(CPU_ID) ) );

	ERROR_MGR( rt_task_slice( &init_task_desc, slice ) );

	ERROR_MGR( rt_task_start( &init_task_desc, &init_task, nullptr ) );

	ERROR_MGR( rt_task_join( &init_task_desc ) );

	ERROR_MGR( rt_sem_delete(&synchro_sem) );

	return EXIT_SUCCESS;
}