[Xenomai] First call to rt_timer_tsc() causes an unexpected switch to secondary mode.

[ZIV-Alberto Ozalla Cantabrana <alberto.ozalla@cgglobal.com>]

Dear colleagues,

I face an unexpected switch to secondary mode after the very first call to rt_timer_tsc() into a real-time task created by Xenomai.
This unexpected switch  only arises if it is the very first call to rt_timer_tsc().
Calling rt_timer_tsc() before creating the task, solves the unexpected switch to secondary mode.
I can not figure where the problem is.
Help will be welcomed.

Thanks in advance.
Alberto Ozalla


Simplest possible self-contained test case:

RT_TASK Test_Task_descriptor;

void Test_Task(void *arg)
{
    // Arguments: &task (NULL=self), start time, period (here: 1,001 ms)
    rt_task_set_periodic(NULL, TM_NOW, 1001000);

    while(1) {

        // Wait for the next periodic release point.
        rt_task_wait_period(NULL);

        rt_timer_tsc();    // Very first call causes an unexpected switch to secondary mode! - Removing this call works OK.
    }
}

main()
{
    ...
        // rt_timer_tsc();  // Calling rt_timer_tsc() before creating the task, solves the unexpected switch to secondary mode.

        // Real-time function creation.
        if (int err = rt_task_create(&Test_Task_descriptor, "Test_Task", 0, 90, 0)) {
            log(CU_LOG_ERR, "Error creating Test_Task (%d)", err);
            return FALSE;
        }

        // Real-time function started.
        if(rt_task_start(&Test_Task_descriptor, &Test_Task, NULL)) {
            log(CU_LOG_ERR, "Error starting Test_Task");
            return FALSE;
        }
    ...
}

Additional information:


  *   Xenomai version:

/proc/xenomai # cat version
2.6.3

  *   Configuration knobs passed to the configure script, used in building the Xenomai libraries:

:~/pro/npcp/output/beagleboneblack-npcptest/build/xenomai-2.6.git_09072014$ grep configure config.status
# Generated by configure.
# Compiler output produced by configure, useful for debugging
# configure, is in config.log if it exists.
configured by ./configure, generated by GNU Autoconf 2.69,
ac_configure_extra_args=
  ac_configure_extra_args="$ac_configure_extra_args --silent"
  set X /bin/bash './configure'  '--prefix=/home/aozalla/pro/npcp/output/beagleboneblack-npcptest/stage' '--build=x86_64-pc-linux-gnu' '--host=arm-linux-uclibcgnueabihf' '--target=arm-linux-uclibcgnueabihf' '--disable-rpath' '--disable-shared' '--enable-static' '--disable-devel' '--disable-ipv6' '--disable-libipq' '--with-kernel=/home/aozalla/pro/npcp/output/beagleboneblack-npcptest/build/linux-3.14.9' 'build_alias=x86_64-pc-linux-gnu' 'host_alias=arm-linux-uclibcgnueabihf' 'target_alias=arm-linux-uclibcgnueabihf' 'CC=/home/aozalla/pro/npcp/output/beagleboneblack-npcptest/stage/bin/arm-linux-uclibcgnueabihf-gcc' 'CFLAGS=-Os -pipe -D_REENTRANT -fomit-frame-pointer -march=armv7-a -mtune=cortex-a8  -mfpu=vfpv3-d16 -finline-functions -finline-limit=50 -ffast-math -include /home/aozalla/pro/npcp/toolchain/include/builtin_redefines.h   -DMAX_PCI_SLOTS=8 -fPIC -DPIC -DNO_LARGEFILE_SOURCE -U_LARGEFILE_SOURCE -U_LARGE_FILES -U_FILE_OFFSET_BITS' 'LDFLAGS=' 'CPP=/home/aozalla/pro/npcp/output/beagleboneblack-npcptest/stage/bin/arm-linux-uclibcgnueabihf-cpp' $ac_configure_extra_args --no-create --no-recursion
    # on some systems where configure will not decide to define it.
    # Let's still pretend it is `configure' which instantiates (i.e., don't
    configure_input='Generated from '`
    `' by configure.'
      configure_input="$ac_file.  $configure_input"
    case $configure_input in #(
       ac_sed_conf_input=`$as_echo "$configure_input" |
    *) ac_sed_conf_input=$configure_input;;
s|@configure_input@|$ac_sed_conf_input|;t t
      $as_echo "/* $configure_input  */" \
    $as_echo "/* $configure_input  */" \
# Libtool was configured on host `(hostname || uname -n) 2>/dev/null | sed 1q`:



  *   Booting logs:

U-Boot SPL 2013.04-dirty (Jul 10 2013 - 14:02:53)
musb-hdrc: ConfigData=0xde (UTMI-8, dyn FIFOs, HB-ISO Rx, HB-ISO Tx, SoftConn)
musb-hdrc: MHDRC RTL version 2.0
musb-hdrc: setup fifo_mode 4
musb-hdrc: 28/31 max ep, 16384/16384 memory
USB Peripheral mode controller at 47401000 using PIO, IRQ 0
musb-hdrc: ConfigData=0xde (UTMI-8, dyn FIFOs, HB-ISO Rx, HB-ISO Tx, SoftConn)
musb-hdrc: MHDRC RTL version 2.0
musb-hdrc: setup fifo_mode 4
musb-hdrc: 28/31 max ep, 16384/16384 memory
USB Host mode controller at 47401800 using PIO, IRQ 0
OMAP SD/MMC: 0
mmc_send_cmd : timeout: No status update
reading u-boot.img
reading u-boot.img


U-Boot 2013.04-dirty (Jul 10 2013 - 14:02:53)

I2C:   ready
DRAM:  512 MiB
WARNING: Caches not enabled
NAND:  No NAND device found!!!
0 MiB
MMC:   OMAP SD/MMC: 0, OMAP SD/MMC: 1
*** Warning - readenv() failed, using default environment

musb-hdrc: ConfigData=0xde (UTMI-8, dyn FIFOs, HB-ISO Rx, HB-ISO Tx, SoftConn)
musb-hdrc: MHDRC RTL version 2.0
musb-hdrc: setup fifo_mode 4
musb-hdrc: 28/31 max ep, 16384/16384 memory
USB Peripheral mode controller at 47401000 using PIO, IRQ 0
musb-hdrc: ConfigData=0xde (UTMI-8, dyn FIFOs, HB-ISO Rx, HB-ISO Tx, SoftConn)
musb-hdrc: MHDRC RTL version 2.0
musb-hdrc: setup fifo_mode 4
musb-hdrc: 28/31 max ep, 16384/16384 memory
USB Host mode controller at 47401800 using PIO, IRQ 0
Net:   <ethaddr> not set. Validating first E-fuse MAC
cpsw, usb_ether
Hit any key to stop autoboot:  0
gpio: pin 53 (gpio 53) value is 1
Card did not respond to voltage select!
mmc0(part 0) is current device
Card did not respond to voltage select!
No micro SD card found, setting mmcdev to 1
mmc_send_cmd : timeout: No status update
mmc1(part 0) is current device
mmc_send_cmd : timeout: No status update
gpio: pin 54 (gpio 54) value is 1
SD/MMC found on device 1
reading uEnv.txt
26 bytes read in 3 ms (7.8 KiB/s)
Loaded environment from uEnv.txt
Importing environment from mmc ...
gpio: pin 55 (gpio 55) value is 1
2544928 bytes read in 371 ms (6.5 MiB/s)
gpio: pin 56 (gpio 56) value is 1
31371 bytes read in 50 ms (612.3 KiB/s)
Booting from mmc ...
## Booting kernel from Legacy Image at 80007fc0 ...
   Image Name:   Linux-3.14.9
   Image Type:   ARM Linux Kernel Image (uncompressed)
   Data Size:    2544864 Bytes = 2.4 MiB
   Load Address: 80008000
   Entry Point:  80008000
   Verifying Checksum ... OK
## Flattened Device Tree blob at 80f80000
   Booting using the fdt blob at 0x80f80000
   XIP Kernel Image ... OK
OK
   Using Device Tree in place at 80f80000, end 80f8aa8a

Starting kernel ...

[    0.280790] omap_init_mbox: hwmod doesn't have valid attrs
[    1.110098] musb-hdrc musb-hdrc.0.auto: Failed to request rx1.
[    1.116533] musb-hdrc musb-hdrc.0.auto: musb_init_controller failed with status -517
[    1.129661] musb-hdrc musb-hdrc.1.auto: Failed to request rx1.
[    1.136052] musb-hdrc musb-hdrc.1.auto: musb_init_controller failed with status -517
[    1.273438] cpu cpu0: cpu0 regulator not ready, retry
starting pid 1361, tty '/dev/ttyO0': '/etc/rcS'

2000/01/06,18:01:27  kern.notice kernel: klogd started: BusyBox v1.22.1 ()
2000/01/06,18:01:27  kern.info kernel: [    0.000000] Booting Linux on physical CPU 0x0
2000/01/06,18:01:27  kern.info kernel: [    0.000000] Initializing cgroup subsys cpuset
2000/01/06,18:01:27  kern.info kernel: [    0.000000] Initializing cgroup subsys cpu
2000/01/06,18:01:27  kern.info kernel: [    0.000000] Initializing cgroup subsys cpuacct
2000/01/06,18:01:27  kern.notice kernel: [    0.000000] Linux version 3.14.9 (gcc version 4.7.3 (GCC) ) #1 SMP 201<6>Jan  6 18:01:27 kernel: [    0.000000] CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7), cr=10c5387d
2000/01/06,18:01:27  kern.info kernel: [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
2000/01/06,18:01:27  kern.info kernel: [    0.000000] Machine model: TI AM335x BeagleBone
2000/01/06,18:01:27  kern.info kernel: [    0.000000] cma: CMA: reserved 16 MiB at 9e800000
2000/01/06,18:01:27  kern.info kernel: [    0.000000] Memory policy: Data cache writeback
2000/01/06,18:01:27  kern.debug kernel: [    0.000000] On node 0 totalpages: 130816
2000/01/06,18:01:27  kern.debug kernel: [    0.000000]   Normal zone: 1024 pages used for memmap
2000/01/06,18:01:27  kern.debug kernel: [    0.000000]   Normal zone: 0 pages reserved
2000/01/06,18:01:27  kern.debug kernel: [    0.000000]   Normal zone: 130816 pages, LIFO batch:31
2000/01/06,18:01:27  kern.info kernel: [    0.000000] CPU: All CPU(s) started in SVC mode.
2000/01/06,18:01:27  kern.info kernel: [    0.000000] please try 'cgroup_disable=memory' option if you don't want memory cgroups
2000/01/06,18:01:27  kern.notice kernel: [    0.000000] Memory: 492048K/523264K available (4919K kernel code, 450K rwdata, 1832K rodata, 467K init, 1418K bss, 31216K reserved, 0K highmem)
2000/01/06,18:01:27  kern.notice kernel: [    0.000000] Virtual kernel memory layout:
2000/01/06,18:01:27  kern.notice kernel: [    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
2000/01/06,18:01:27  kern.notice kernel: [    0.000000]     fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
2000/01/06,18:01:27  kern.notice kernel: [    0.000000]     vmalloc : 0xe0800000 - 0xff000000   ( 488 MB)
2000/01/06,18:01:27  kern.notice kernel: [    0.000000]     lowmem  : 0xc0000000 - 0xe0000000   ( 512 MB)
2000/01/06,18:01:27  kern.notice kernel: [    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
2000/01/06,18:01:27  kern.notice kernel: [    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
2000/01/06,18:01:27  kern.info kernel: [    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
2000/01/06,18:01:27  kern.info kernel: [    0.000000] NR_IRQS:16 nr_irqs:16 16
2000/01/06,18:01:27  kern.info kernel: [    0.000000] IRQ: Found an INTC at 0xfa200000 (revision 5.0) with 128 interrupts
2000/01/06,18:01:27  kern.info kernel: [    0.000000] Total of 128 interrupts on 1 active controller
2000/01/06,18:01:27  kern.info kernel: [    0.000000] OMAP clockevent source: timer2 at 24000000 Hz
2000/01/06,18:01:27  kern.info kernel: [    0.000017] sched_clock: 32 bits at 24MHz, resolution 41ns, wraps every 178956969942ns
2000/01/06,18:01:27  kern.info kernel: [    0.000044] I-pipe, 24.000 MHz clocksource
2000/01/06,18:01:27  kern.info kernel: [    0.000075] OMAP clocksource: timer1 at 24000000 Hz
2000/01/06,18:01:27  kern.info kernel: [    0.132442] CPU: Testing write buffer coherency: ok
2000/01/06,18:01:27  kern.info kernel: [    0.132991] CPU0: thread -1, cpu 0, socket -1, mpidr 0
2000/01/06,18:01:27  kern.info kernel: [    0.133072] Setting up static identity map for 0x804a4920 - 0x804a4978
2000/01/06,18:01:27  kern.info kernel: [    0.134831] Brought up 1 CPUs
2000/01/06,18:01:27  kern.info kernel: [    0.134852] SMP: Total of 1 processors activated.
2000/01/06,18:01:27  kern.info kernel: [    0.134864] CPU: All CPU(s) started in SVC mode.
2000/01/06,18:01:27  kern.info kernel: [    0.366597] pps_core: LinuxPPS API ver. 1 registered
2000/01/06,18:01:27  kern.info kernel: [    0.366616] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it><mailto:giometti@linux.it>
2000/01/06,18:01:27  kern.info kernel: [    0.366887] PTP clock support registered
2000/01/06,18:01:27  kern.info kernel: [    0.372800] Switched to clocksource ipipe_tsc
2000/01/06,18:01:27  kern.info kernel: [    0.442248] NET: Registered protocol family 2
2000/01/06,18:01:28  kern.info kernel: [    0.443539] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
2000/01/06,18:01:28  kern.info kernel: [    0.447153] hw perfevents: enabled with ARMv7 Cortex-A8 PMU driver, 5 counters available
2000/01/06,18:01:28  kern.info kernel: [    0.452330] futex hash table entries: 256 (order: 2, 16384 bytes)
2000/01/06,18:01:28  kern.info kernel: [    0.708933] I-pipe: head domain Xenomai registered.
2000/01/06,18:01:28  kern.info kernel: [    0.708983] Xenomai: hal/arm started.
2000/01/06,18:01:28  kern.info kernel: [    0.710767] Xenomai: scheduling class idle registered.
2000/01/06,18:01:28  kern.info kernel: [    0.710794] Xenomai: scheduling class rt registered.
2000/01/06,18:01:28  kern.info kernel: [    0.727536] Xenomai: real-time nucleus v2.6.3 (Lies and Truths) loaded.
2000/01/06,18:01:28  kern.info kernel: [    0.767422] io scheduler noop registered
2000/01/06,18:01:28  kern.info kernel: [    0.767439] io scheduler deadline registered
2000/01/06,18:01:28  kern.info kernel: [    0.768054] io scheduler cfq registered (default)


Thanks in advance.

Alberto Ozalla


CG DISCLAIMER: This email contains confidential information. It is intended exclusively for the addressees. If you are not an addressee, you must not store, transmit or disclose its contents. Instead please notify the sender immediately; and permanently delete this e-mail from your computer systems. We have taken reasonable precautions to ensure that no viruses are present. However, you must check this email and the attachments, for viruses. We accept no liability whatsoever, for any detriment caused by any transmitted virus.