[Xenomai-core] Fwd: Re: preemptive doesn't work

[Roberto Bielli <roberto.bielli@domain.hid>]

[-- Attachment #1.1: Type: text/plain, Size: 2604 bytes --]

Hi Gilles,

have you received the trace ?
Have you find a weird behaviour ?

In attach you find the same trace.

Thanks a lot in advance.

-------- Messaggio originale --------
Oggetto: 	Re: [Xenomai-core] preemptive doesn't work
Data: 	Wed, 07 Mar 2012 19:13:59 +0100
Mittente: 	Roberto Bielli <roberto.bielli@domain.hid>
A: 	Gilles Chanteperdrix <gilles.chanteperdrix@xenomai.org>
CC: 	xenomai@xenomai.org



Hi Gilles,

this is the trace and the test.

It seems that '__ipipe_dispatch_event' last about ~84 milliseconds with
disable interrupts.


Thanks a lot for your time.



Il 07/03/2012 14:44, Gilles Chanteperdrix ha scritto:
>  On 03/07/2012 01:59 PM, Roberto Bielli wrote:
>>  Hi Gilles,
>>
>>  we are sure that when a task execute NO INTERRUPTS arrives in interrupt
>>  service routine in assembler in the kernel,
>>  until it sleeps. It's not a problem of secondary mode.
>  Show me the trace and I will believe you (approximately fourth time I ask).
>


-- 
+------------------------------------------------------------------------------------------------+
							
Roberto Bielli
Sviluppo Software					
Axel S.r.l.					
							
Via Del Cannino, 3 				
21020 Crosio Della Valle			
Varese - Italy					
							
Telefono: +39 0332 949600			
Fax:      +39 0332 969315			
							
E-mail:   roberto.bielli@domain.hid	
Web Site: www.axelsw.it

+------------------------------------------------------------------------------------------------+

Si precisa che le informazioni contenute in questo messaggio sono riservate e ad uso esclusivo del destinatario.
Qualora il messaggio in parola Le fosse pervenuto per errore, La preghiamo di eliminarlo senza copiarlo e di non inoltrarlo a terzi,
dandocene gentilmente comunicazione. Grazie.
Informativa sul trattamento dei dati personali (D. Lgs. 196/2003).
I dati utilizzati per la spedizione del presente messaggio sono utilizzati da Axel S.r.l., titolare del trattamento,
per l'invio delle comunicazioni dei diversi settori aziendali, non essendo autorizzata la divulgazione a terzi.
Potrete rivolgere alla seguente mail richieste di verifica, rettifica o cancellazione dei Vostri dati: info@domain.hid

This e-mail and any attachments is confidential and may contain privileged information
intended for the addressee(s) only. Dissemination, copying, printing or use by anybody
else is unauthorised. If you are not the intended recipient,
please delete this message and any attachments and advise the sender
by return e-mail.Thank you.  			
							
+------------------------------------------------------------------------------------------------+




[-- Attachment #1.2: Type: text/html, Size: 4090 bytes --]

[-- Attachment #2: Ipipe.txt --]
[-- Type: text/plain, Size: 11222 bytes --]

I-pipe frozen back-tracing service on 2.6.31/ipipe-1.16-02
------------------------------------------------------------
CPU: 0, Freeze: 2038911849125 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 1.044 us

 +----- Hard IRQs ('|': locked)
 |+---- <unused>
 ||+--- <unused>
 |||+-- Xenomai
 ||||+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
 |||||                        +---------- Delay flag ('+': > 1 us, '!': > 10 us)
 |||||                        |        +- NMI noise ('N')
 |||||                        |        |
      Type    User Val.   Time    Delay  Function (Parent)
:|   #func               -84864+   1.313  __ipipe_handle_irq+0x14 (__ipipe_grab_irq+0x68)
:|   #func               -84863+   1.164  __ipipe_ack_timerirq+0x10 (__ipipe_handle_irq+0x9c)
:|   #func               -84862+   1.462  __ipipe_ack_level_irq+0x10 (__ipipe_ack_timerirq+0x24)
:|   #func               -84860+   1.358  mxc_mask_irq+0x10 (__ipipe_ack_level_irq+0x3c)
:|   #func               -84859+   1.432  mxc_mask_irq+0x10 (__ipipe_ack_level_irq+0x54)
:|   #func               -84858+   1.268  __ipipe_mach_acktimer+0x10 (__ipipe_ack_timerirq+0x28)
:|   #func               -84856+   1.298  __ipipe_end_level_irq+0x10 (__ipipe_ack_timerirq+0x38)
:|   #func               -84855+   1.358  mxc_unmask_irq+0x10 (__ipipe_end_level_irq+0x28)
:|   #func               -84854+   1.552  __ipipe_dispatch_wired+0x10 (__ipipe_handle_irq+0xa8)
:|   #func               -84852+   1.238  __ipipe_dispatch_wired_nocheck+0x10 (__ipipe_dispatch_wired+0x84)
:|  #*func               -84851+   1.507  xnintr_clock_handler+0x10 (__ipipe_dispatch_wired_nocheck+0x68)
:|  #*func               -84849+   2.208  xntimer_tick_aperiodic+0x14 (xnintr_clock_handler+0x44)
:|  #*func               -84847+   2.074  xntimer_next_local_shot+0x10 (xntimer_tick_aperiodic+0x258)
:|  #*event   tick@-84784-84845+   1.164  xntimer_next_local_shot+0xcc (xntimer_tick_aperiodic+0x258)
:|  #*func               -84844+   2.268  __ipipe_mach_set_dec+0x10 (xntimer_next_local_shot+0x110)
:|   #func               -84842+   1.552  __ipipe_walk_pipeline+0x10 (__ipipe_dispatch_wired_nocheck+0xac)
:|   #end     0xffffffff -84840+   1.835  __ipipe_grab_irq+0x74 (__irq_svc+0x68)
:    #func               -84838+   1.522  vma_prio_tree_remove+0x10 (__remove_shared_vm_struct+0x120)
:    #func               -84837+   1.268  __ipipe_unstall_root+0x10 (__remove_shared_vm_struct+0x124)
:|   #begin   0x80000000 -84836+   1.567  __ipipe_unstall_root+0x34 (__remove_shared_vm_struct+0x124)
:|   +end     0x80000000 -84834+   1.313  __ipipe_unstall_root+0x98 (__remove_shared_vm_struct+0x124)
:    +func               -84833+   1.432  ipipe_check_context+0x10 (__remove_shared_vm_struct+0x12c)
:    +func               -84831+   1.597  ipipe_check_context+0x10 (unlink_file_vma+0x60)
:    +func               -84830+   1.537  anon_vma_unlink+0x10 (free_pgtables+0x50)
:    +func               -84828+   1.910  unlink_file_vma+0x10 (free_pgtables+0x58)
:|   +func               -84826+   1.223  __ipipe_grab_irq+0x10 (__irq_svc+0x68)
:|   +begin   0xffffffff -84825+   1.522  __ipipe_grab_irq+0x5c (__irq_svc+0x68)
:|   +func               -84823+   1.641  __ipipe_handle_irq+0x14 (__ipipe_grab_irq+0x68)
:|   +func               -84822+   1.208  __ipipe_ack_timerirq+0x10 (__ipipe_handle_irq+0x9c)
:|   +func               -84821+   1.164  __ipipe_ack_level_irq+0x10 (__ipipe_ack_timerirq+0x24)
:|   +func               -84819+   1.373  mxc_mask_irq+0x10 (__ipipe_ack_level_irq+0x3c)
:|   +func               -84818+   1.328  mxc_mask_irq+0x10 (__ipipe_ack_level_irq+0x54)
:|   +func               -84817+   1.313  __ipipe_mach_acktimer+0x10 (__ipipe_ack_timerirq+0x28)
:|   +func               -84815+   1.149  __ipipe_end_level_irq+0x10 (__ipipe_ack_timerirq+0x38)
:|   +func               -84814+   1.358  mxc_unmask_irq+0x10 (__ipipe_end_level_irq+0x28)
:|   +func               -84813+   1.492  __ipipe_dispatch_wired+0x10 (__ipipe_handle_irq+0xa8)
:|   +func               -84811+   1.298  __ipipe_dispatch_wired_nocheck+0x10 (__ipipe_dispatch_wired+0x84)
:|  # func               -84810+   1.373  xnintr_clock_handler+0x10 (__ipipe_dispatch_wired_nocheck+0x68)
:|  # func               -84809+   2.686  xntimer_tick_aperiodic+0x14 (xnintr_clock_handler+0x44)
:|  # func               -84806+   1.955  xntimer_next_local_shot+0x10 (xntimer_tick_aperiodic+0x258)
:|  # event   tick@-84783-84804+   1.567  xntimer_next_local_shot+0xcc (xntimer_tick_aperiodic+0x258)
:|  # func               -84803+   2.253  __ipipe_mach_set_dec+0x10 (xntimer_next_local_shot+0x110)
:|   +func               -84800+   1.805  __ipipe_walk_pipeline+0x10 (__ipipe_dispatch_wired_nocheck+0xac)
:|   +end     0xffffffff -84798+   1.940  __ipipe_grab_irq+0x74 (__irq_svc+0x68)
:    +func               -84797+   1.432  ipipe_check_context+0x10 (unlink_file_vma+0x3c)
:    +func               -84795+   1.343  __remove_shared_vm_struct+0x10 (unlink_file_vma+0x58)
:|   +begin   0x80000001 -84794+   1.507  __remove_shared_vm_struct+0xa4 (unlink_file_vma+0x58)
:|   #end     0x80000001 -84792+   1.402  __remove_shared_vm_struct+0xc4 (unlink_file_vma+0x58)
:    #func               -84791+   1.343  ipipe_check_context+0x10 (__remove_shared_vm_struct+0xd0)
:    #func               -84790+   1.238  vma_prio_tree_remove+0x10 (__remove_shared_vm_struct+0x120)
:    #func               -84788+   1.417  __ipipe_unstall_root+0x10 (__remove_shared_vm_struct+0x124)
:|   #begin   0x80000000 -84787+   1.507  __ipipe_unstall_root+0x34 (__remove_shared_vm_struct+0x124)
:|   +end     0x80000000 -84785+   1.925  __ipipe_unstall_root+0x98 (__remove_shared_vm_struct+0x124)
:|   +func               -84783+   1.656  __ipipe_grab_irq+0x10 (__irq_svc+0x68)
:|   +begin   0xffffffff -84782+   1.522  __ipipe_grab_irq+0x5c (__irq_svc+0x68)
:|   +func               -84780+   1.522  __ipipe_handle_irq+0x14 (__ipipe_grab_irq+0x68)
:|   +func               -84779+   1.567  __ipipe_ack_timerirq+0x10 (__ipipe_handle_irq+0x9c)
:|   +func               -84777+   1.208  __ipipe_ack_level_irq+0x10 (__ipipe_ack_timerirq+0x24)
:|   +func               -84776+   1.373  mxc_mask_irq+0x10 (__ipipe_ack_level_irq+0x3c)
:|   +func               -84775+   1.447  mxc_mask_irq+0x10 (__ipipe_ack_level_irq+0x54)
:|   +func               -84773+   1.313  __ipipe_mach_acktimer+0x10 (__ipipe_ack_timerirq+0x28)
:|   +func               -84772+   1.164  __ipipe_end_level_irq+0x10 (__ipipe_ack_timerirq+0x38)
:|   +func               -84771+   1.402  mxc_unmask_irq+0x10 (__ipipe_end_level_irq+0x28)
:|   +func               -84769+   1.402  __ipipe_dispatch_wired+0x10 (__ipipe_handle_irq+0xa8)
:|   +func               -84768+   1.298  __ipipe_dispatch_wired_nocheck+0x10 (__ipipe_dispatch_wired+0x84)
:|  # func               -84767+   1.388  xnintr_clock_handler+0x10 (__ipipe_dispatch_wired_nocheck+0x68)
:|  # func               -84765+   4.358  xntimer_tick_aperiodic+0x14 (xnintr_clock_handler+0x44)
:|  # func               -84761+   2.179  xnthread_timeout_handler+0x10 (xntimer_tick_aperiodic+0xa8)
:|  # func               -84759+   3.447  xnpod_resume_thread+0x10 (xnthread_timeout_handler+0x34)
:|  # [ 1575] -<?>-    1 -84755+   5.343  xnpod_resume_thread+0x6c (xnthread_timeout_handler+0x34)
:|  # func               -84750+   1.537  xntimer_next_local_shot+0x10 (xntimer_tick_aperiodic+0x258)
:|  # event   tick@-83749-84748+   1.462  xntimer_next_local_shot+0xcc (xntimer_tick_aperiodic+0x258)
:|  # func               -84747+   2.835  __ipipe_mach_set_dec+0x10 (xntimer_next_local_shot+0x110)
:|  # func               -84744+   3.044  __xnpod_schedule+0x14 (xnintr_clock_handler+0xcc)
:|  # [ 1577] -<?>-   -1 -84741+   2.761  __xnpod_schedule+0x98 (xnintr_clock_handler+0xcc)
:|  # func               -84738+   7.507  xnsched_pick_next+0x10 (__xnpod_schedule+0x10c)
:|  # func               -84731+   2.522  ipipe_unstall_pipeline_head+0x10 (__xnpod_schedule+0x2f8)
:|  + end     0x80000000 -84728+   2.373  ipipe_unstall_pipeline_head+0x8c (__xnpod_schedule+0x2f8)
:|  + begin   0x80000001 -84726+   2.358  __xnpod_schedule+0x398 (xnintr_clock_handler+0xcc)
:|  + end     0x80000001 -84723!  55.000  __xnpod_schedule+0x3b8 (xnintr_clock_handler+0xcc)
:   + func               -84668+   7.716  xnsched_finish_unlocked_switch+0x10 (__xnpod_schedule+0x4e0)
:|  + begin   0x80000000 -84661+   7.970  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x4e0)
:|  # [ 1575] -<?>-    1 -84653+   7.522  __xnpod_schedule+0x504 (xnpod_suspend_thread+0x278)
:|  # func               -84645+   3.313  __ipipe_restore_pipeline_head+0x10 (xnpod_suspend_thread+0x2c8)
:|  + end     0x80000000 -84642+   6.805  __ipipe_restore_pipeline_head+0xdc (xnpod_suspend_thread+0x2c8)
:|  + begin   0x80000001 -84635+   4.522  __ipipe_dispatch_event+0x158 (__ipipe_syscall_root+0x88)
:|  + end     0x80000001 -84631! 84595.567  __ipipe_dispatch_event+0x22c (__ipipe_syscall_root+0x88)
:   + func                 -35+   3.567  __ipipe_syscall_root+0x10 (vector_swi+0x74)
:   + func                 -31+   1.417  __ipipe_dispatch_event+0x14 (__ipipe_syscall_root+0x88)
:|  + begin   0x80000001   -30+   4.447  __ipipe_dispatch_event+0x40 (__ipipe_syscall_root+0x88)
:|  + end     0x80000001   -26+   1.970  __ipipe_dispatch_event+0xfc (__ipipe_syscall_root+0x88)
:   + func                 -24+   5.507  hisyscall_event+0x14 (__ipipe_dispatch_event+0x120)
:   + func                 -18+   2.268  xnshadow_sys_trace+0x10 (hisyscall_event+0x168)
:   + func                 -16+   1.358  ipipe_trace_frozen_reset+0x10 (xnshadow_sys_trace+0xa0)
:   + func                 -14+   1.925  __ipipe_global_path_lock+0x10 (ipipe_trace_frozen_reset+0x18)
:   + func                 -13+   1.388  __ipipe_spin_lock_irqsave+0x10 (__ipipe_global_path_lock+0x1c)
:|  + begin   0x80000001   -11+   6.805  __ipipe_spin_lock_irqsave+0x34 (__ipipe_global_path_lock+0x1c)
:|  # func                  -4+   2.283  __ipipe_spin_unlock_irqcomplete+0x10 (__ipipe_global_path_unlock+0x6c)
:|  + end     0x80000001    -2+   2.552  __ipipe_spin_unlock_irqcomplete+0x50 (__ipipe_global_path_unlock+0x6c)
<   + freeze  0x00000000     0    2.791  xnshadow_sys_trace+0xac (hisyscall_event+0x168)
 |  + begin   0x80000001     2    1.895  __ipipe_dispatch_event+0x158 (__ipipe_syscall_root+0x88)
 |  + end     0x80000001     4  84585.373  __ipipe_dispatch_event+0x22c (__ipipe_syscall_root+0x88)
    + func               84590    1.746  __ipipe_syscall_root+0x10 (vector_swi+0x74)
    + func               84591    1.268  __ipipe_dispatch_event+0x14 (__ipipe_syscall_root+0x88)
 |  + begin   0x80000001 84593    1.940  __ipipe_dispatch_event+0x40 (__ipipe_syscall_root+0x88)
 |  + end     0x80000001 84595    1.179  __ipipe_dispatch_event+0xfc (__ipipe_syscall_root+0x88)
    + func               84596    3.223  hisyscall_event+0x14 (__ipipe_dispatch_event+0x120)
    + func               84599    4.582  __rt_task_sleep+0x14 (hisyscall_event+0x168)
    + func               84604    2.835  rt_task_sleep+0x14 (__rt_task_sleep+0x68)
    + func               84606    0.000  xnpod_suspend_thread+0x14 (rt_task_sleep+0x80)

[-- Attachment #3: testpreempt.c --]
[-- Type: text/plain, Size: 1670 bytes --]

#include <stdio.h>
#include <stdint.h>
#include <fcntl.h>
#include <sys/ioctl.h>
#include <string.h>

#include <stdlib.h>
#include <stdio.h>
#include <sys/mman.h>	/* for MCL_CURRENT and MCL_FUTURE */
#include <rtdm/rtdm.h>
#include <native/task.h>
#include <nucleus/trace.h>

#define GPIO6_ON 		*Gpio2ValAddr |= 1 << 6
#define GPIO6_OFF		*Gpio2ValAddr &= ~(1 << 6);

static RT_TASK rt_task_desc;
static RT_TASK tsk2ms;

	//dati per la gestione memoria mappata
static unsigned long * Gpio2ValAddr = NULL;

volatile int cnt2ms = 0;
volatile int cntmain = 0;
volatile int x;

void funct2ms( void * params )
{
	for(;;)
	{
		GPIO6_ON;
		rt_task_sleep( 2000000 );
		++ cnt2ms;
		GPIO6_OFF;
	}
}

int main(int argc, char *argv[])
{
	int count = 0;
	int traceOn = 0;
	int fd, ret;

	// no memory-swapping for this programm
	ret = mlockall(MCL_CURRENT | MCL_FUTURE);
	if( ret )
	{
		perror("ERROR : mlockall has failled");
		exit(1);
	}


	fd = open( "/dev/mem", O_RDWR | O_SYNC );
	printf( "FD=%d", fd );
	fflush( stdout );

	Gpio2ValAddr = (unsigned long  *)mmap(  NULL, 0x1000, PROT_READ | PROT_WRITE,  MAP_SHARED, fd, 0x53FD0000 );

	ret = rt_task_shadow(&rt_task_desc, NULL, 1, 0);
	if( ret != 0 )
	{
		fprintf(stderr, "ERROR : rt_task_shadow: %s\n", strerror(-ret));
		exit( 1 );
	}

	rt_task_create( &tsk2ms, "task2ms",0, 99, 0 );
	rt_task_start( &tsk2ms, funct2ms, NULL );


	for(;;)
	{
		for( x=0; x < 1000000; x++ );
		for( x=0; x < 1000000; x++ );
		xntrace_user_freeze(0, 0);
		for( x=0; x < 1000000; x++ );
		for( x=0; x < 1000000; x++ );
		rt_task_sleep( 10000000 );
	}

	return 0;
}