Discussion:
[Rtai] Issue with RTAI 5.0/5.1 on CentOS 7
Emmanuel Pacaud
2018-07-06 08:43:50 UTC
Permalink
Hi,

I have installed rtai 5.1 and a patched vanilla linux kernel 4.4.43 on
a CentOS 7 distribution. Compilation and installation went fine after a
few tries in order to understand what kernel options are needed by
CentOS to boot correctly.

But when I run the testsuite, I get some kernel oops, likely when the
userspace API is used.

In fact, as soon rtai_sched module is installed, linux complains:

insmod rtai_hal.ko

[62619.200082] I-pipe: head domain RTAI registered.
[62619.200176] RTAI[hal]: mounted. ISOL_CPUS_MASK: e.
[62619.200210] SYSINFO - # CPUs: 4, TIMER NAME: 'lapic', TIMER IRQ:
4354, TIMER FREQ: 93641996, CLOCK NAME: 'tsc', CLOCK FREQ: 2996554000,
CPU FREQ: 2996554000, LINUX TIMER IRQ: 4354.
[62619.200314]
REMARK: RTAI WILL NOT ACCESS USER SPACE ON STACKS ARGS ITS WAY.

insmod rtai_sched.ko

[62733.070351] RTAI[malloc]: global heap size = 2097152 bytes, <BSD>.
[62733.070478] , kstacks pool size = 524288 bytes.
[62733.070655] RTAI[sched]: hard timer type/freq = lapic/93641996(Hz);
timing: ONESHOT; linear timed lists.
[62733.070860] RTAI[sched]: Linux timer freq = 250 (Hz), TimeBase freq
= 2996554000 hz.
[62733.070968] RTAI[sched]: timer setup = 74 ns, resched latency = 0 ns.
[62733.071664] ------------[ cut here ]------------
[62733.071765] Kernel BUG at ffffffff810a4b90 [verbose debug info
unavailable]
[62733.071872] invalid opcode: 0000 [#9] SMP
[62733.072114] Modules linked in: rtai_sched(O+) rtai_hal(O)
ebtable_nat ebtable_broute bridge stp llc ip6table_mangle ip6table_raw
iptable_mangle iptable_raw ebtable_filter ebtables ip6table_filter
ip6_tables iptable_filter ipmi_devintf dcdbas pcspkr sg ipmi_si
ipmi_msghandler shpchp ip_tables x_tables xfs libcrc32c crc32c_generic
sr_mod sd_mod ahci libahci tg3 libphy igb i2c_algo_bit i2c_core hwmon
ptp pps_core libata megaraid_sas scsi_mod dm_mirror dm_region_hash
dm_log dm_mod ipv6 [last unloaded: rtai_hal]
[62733.076051] CPU: 0 PID: 30482 Comm: calibrate Tainted: G D O
4.4.43-hal-6-rtai-5.0 #14
[62733.076183] Hardware name: Dell Inc. PowerEdge T630/0W9WXC, BIOS
1.0.4 08/29/2014
[62733.076290] task: ffff880468732f00 ti: ffff88046a2bc000 task.ti:
ffff88046a2bc000
[62733.076398] RIP: 0010:[<ffffffff810a4b90>] [<ffffffff810a4b90>]
__audit_syscall_entry+0x2f/0xdc
[62733.076603] RSP: 0018:ffff88046a2bfed8 EFLAGS: 00010202
[62733.076705] RAX: ffff880468732f00 RBX: ffff88046af34800 RCX:
0000000000000000
[62733.076812] RDX: 0000000000000000 RSI: 0000000000000000 RDI:
00000000000000e7
[62733.076919] RBP: ffff88046a2bfee8 R08: ffffffffffffff70 R09:
ffff880468732f00
[62733.077026] R10: ffffffffffffff70 R11: 0000000000000246 R12:
00007f9ce0308838
[62733.077133] R13: 00007f9ce030de80 R14: 0000000000000000 R15:
0000000000000000
[62733.077241] FS: 00007f9ce0958740(0000) GS:ffff88047fc00000(0000)
knlGS:0000000000000000
[62733.077350] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[62733.077453] CR2: 00007f9ce000b8d0 CR3: 0000000469d11000 CR4:
00000000001406f0
[62733.077560] I-pipe domain Linux
[62733.077657] Stack:
[62733.077751] ffff88046a2bff58 00007f9ce0308838 0000000000000000
ffffffff810012a0
[62733.078145] 0000000000000000 0000000000010246 0000000000000014
0000000000000000
[62733.078539] 0000000000000000 ffffffff81033f74 0000000000000200
0000000000000000
[62733.078933] Call Trace:
[62733.079030] [<ffffffff810012a0>] ?
syscall_trace_enter_phase1+0xe3/0xec
[62733.079137] [<ffffffff81033f74>] ? do_page_fault+0x4e/0x7e
[62733.079240] [<ffffffff813c5f87>] ? tracesys+0xd/0x44
[62733.079342] Code: 0c 25 c0 ac 00 00 48 89 e5 41 54 53 49 8b 99 70 05
00 00 48 85 db 0f 84 b7 00 00 00 83 7b 04 00 75 09 83 bb 40 02 00 00 00
74 02 <0f> 0b 83 3d 83 30 6b 00 00 0f 84 99 00 00 00 49 8b 41 08 44 8b
[62733.084167] RIP [<ffffffff810a4b90>] __audit_syscall_entry+0x2f/0xdc
[62733.084344] RSP <ffff88046a2bfed8>
[62733.084461] ---[ end trace f782b5ddf448fd9a ]---
[62733.085369] USERMODE CHECK: ERROR.
[62733.085467] USERMODE CHECK PROVIDED (ns): KernelLatency -1,
UserLatency -1.
[62733.398278] KERNEL SPACE LATENCY ENDED AT CYCLE: 3121, LATENCY =
1822, VARIANCE = 13840/10004569, GAIN = 345847/1000000000, LEAST = 1620.
[62733.501148] AFTER KERNEL CALIBRATION (WITH RTAI TASK, ns):
KernelLatency 608, UserLatency -1 (CALIBRATION: PERIOD 10000 (ns), TIME
415573612 (ns)).
[62733.501690] ------------[ cut here ]------------
[62733.501791] Kernel BUG at ffffffff810a4b90 [verbose debug info
unavailable]
[62733.501939] invalid opcode: 0000 [#10] SMP
[62733.502181] Modules linked in: rtai_sched(O+) rtai_hal(O)
ebtable_nat ebtable_broute bridge stp llc ip6table_mangle ip6table_raw
iptable_mangle iptable_raw ebtable_filter ebtables ip6table_filter
ip6_tables iptable_filter ipmi_devintf dcdbas pcspkr sg ipmi_si
ipmi_msghandler shpchp ip_tables x_tables xfs libcrc32c crc32c_generic
sr_mod sd_mod ahci libahci tg3 libphy igb i2c_algo_bit i2c_core hwmon
ptp pps_core libata megaraid_sas scsi_mod dm_mirror dm_region_hash
dm_log dm_mod ipv6 [last unloaded: rtai_hal]
[62733.506078] CPU: 0 PID: 30483 Comm: calibrate Tainted: G D O
4.4.43-hal-6-rtai-5.0 #14
[62733.506210] Hardware name: Dell Inc. PowerEdge T630/0W9WXC, BIOS
1.0.4 08/29/2014
[62733.506318] task: ffff880468732f00 ti: ffff88046a2bc000 task.ti:
ffff88046a2bc000
[62733.506425] RIP: 0010:[<ffffffff810a4b90>] [<ffffffff810a4b90>]
__audit_syscall_entry+0x2f/0xdc
[62733.506630] RSP: 0018:ffff88046a2bfed8 EFLAGS: 00010202
[62733.506732] RAX: ffff880468732f00 RBX: ffff88046af36800 RCX:
0000000000021000
[62733.506839] RDX: 0000000000000000 RSI: 0000000000000000 RDI:
000000000000000c
[62733.506946] RBP: ffff88046a2bfee8 R08: 0000000000021000 R09:
ffff880468732f00
[62733.507053] R10: 0000000000021000 R11: 0000000000003246 R12:
00007f1d1231a4e0
[62733.507160] R13: 0000000000000000 R14: 0000000000000fff R15:
00007f1d12317760
[62733.507267] FS: 00007f1d12963740(0000) GS:ffff88047fc00000(0000)
knlGS:0000000000000000
[62733.507376] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[62733.507480] CR2: 00007f1d12034a70 CR3: 0000000469d11000 CR4:
00000000001406f0
[62733.507587] I-pipe domain Linux
[62733.507683] Stack:
[62733.507777] ffff88046a2bff58 00007f1d1231a4e0 0000000000000000
ffffffff810012a0
[62733.508171] 0000000000003082 ffff880468733780 0000000000000000
0000000000400b10
[62733.508564] 00007fff657aeee0 0000000000000000 0000000000000000
ffff88046a2bff58
[62733.508958] Call Trace:
[62733.509054] [<ffffffff810012a0>] ?
syscall_trace_enter_phase1+0xe3/0xec
[62733.509165] [<ffffffffa0861c7a>] ?
lxrt_intercept_syscall+0x81/0x172 [rtai_sched]
[62733.509273] [<ffffffff813c5f87>] ? tracesys+0xd/0x44
[62733.509375] Code: 0c 25 c0 ac 00 00 48 89 e5 41 54 53 49 8b 99 70 05
00 00 48 85 db 0f 84 b7 00 00 00 83 7b 04 00 75 09 83 bb 40 02 00 00 00
74 02 <0f> 0b 83 3d 83 30 6b 00 00 0f 84 99 00 00 00 49 8b 41 08 44 8b
[62733.519504] RIP [<ffffffff810a4b90>] __audit_syscall_entry+0x2f/0xdc
[62733.519681] RSP <ffff88046a2bfed8>
[62733.519785] ---[ end trace f782b5ddf448fd9b ]---
[62733.519891] LXRT releases PID 30483 (ID: calibrate).
[62733.521116] USERMODE USER SPACE CALIBRATION: ERROR.
[62733.521224] AFTER USER CALIBRATION (ns): KernelLatency 608,
UserLatency 0 (CALIBRATION: PERIOD 10000 (ns), TIME 19932389 (ns)).
[62733.521363] FINAL CALIBRATION SUMMARY (ns): KernelLatency 608,
UserLatency 0.

Any idea of what is going wrong ?

I have also tried rtai 5.0 + linux 4.4.43, with the same result. In
fact, with this version, but running Scientific Linux 6, RTAI works
fine. The difference in the kernel configuration between Scinetific
Linux 6 and CentOS 7 is a few options needed by systemd
(CONFIG_FHANDLE, CONFIG_CGROUPS...)

Here are the test suite results:

[***@lappc-f586 testsuite]# cd kern/
[***@lappc-f586 kern]# cd latency/
[***@lappc-f586 latency]# ./run
*
*
* Type ^C to stop this application.
*
*
RTAI Testsuite - KERNEL space latency test (output data in nanoseconds)

*** latency verification tool with RTAI own real time kernel tasks ***
*** period = 100000 (ns), avrgtime = 1 (s) ***

RTH| lat min| ovl min| lat avg| lat max| ovl max|
overruns
RTD| -9| -9| 21| 1434| 1434|
0
RTD| -9| -9| 25| 6247| 6247|
0
RTD| -9| -9| 24| 1265| 6247|
0
RTD| -9| -9| 24| 1833| 6247|
0
RTD| -9| -9| 24| 1686| 6247|
0
RTD| -9| -9| 25| 1691| 6247|
0
^CRTD| -9| -9| 25| 1691| 6247|
0
[***@lappc-f586 latency]# cd ../
latency/ preempt/ switches/
[***@lappc-f586 latency]# cd ../preempt/
[***@lappc-f586 preempt]# ./run
*
*
* Type ^C to stop this application.
*
*
RTAI Testsuite - UP preempt (all data in nanoseconds)
RTH| lat min| lat avg| lat max| jit fast| jit slow
RTD| -3| 16| 952| 1516| 1646
RTD| -3| 16| 1040| 1516| 1646
RTD| -3| 17| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 17| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 17| 1074| 1516| 1646
^CRTD| -3| 17| 1074| 1516| 1646
[***@lappc-f586 preempt]# cd ../
latency/ preempt/ switches/
[***@lappc-f586 preempt]# cd ../switches/
[***@lappc-f586 switches]# ./run
*
*
* Type ^C to stop this application.
*
*
Jul 6 04:42:23 lappc-f586 kernel: #012#012CPU USE SUMMARY
Jul 6 04:42:23 lappc-f586 kernel: # 0 -> 16171
Jul 6 04:42:23 lappc-f586 kernel: # 1 -> 0
Jul 6 04:42:23 lappc-f586 kernel: # 2 -> 0
Jul 6 04:42:23 lappc-f586 kernel: # 3 -> 0
Jul 6 04:42:23 lappc-f586 kernel: END OF CPU USE SUMMARY
Jul 6 04:42:30 lappc-f586 kernel: #012Wait for it ...
Jul 6 04:42:30 lappc-f586 kernel: #012#012FOR 10 TASKS: TIME 5 (ms),
SUSP/RES SWITCHES 40000, SWITCH TIME (INCLUDING FULL FP SUPPORT) 143
(ns)
Jul 6 04:42:30 lappc-f586 kernel: #012FOR 10 TASKS: TIME 5 (ms), SEM
SIG/WAIT SWITCHES 40000, SWITCH TIME (INCLUDING FULL FP SUPPORT) 144
(ns)
Jul 6 04:42:30 lappc-f586 kernel: #012FOR 10 TASKS: TIME 7 (ms),
RPC/RCV-RET SWITCHES 40000, SWITCH TIME (INCLUDING FULL FP SUPPORT) 175
(ns)
^C[***@lappc-f586 switches]# cd ../../user/latency/
[***@lappc-f586 latency]# ./run
*
*
* Type ^C to stop this application.
*
*
/opt/rtai/linux-4.4.43-x86_64-hal-6-rtai-5.0/realtime/bin/rtai-load :
ligne 185 : 31014 Erreur de segmentation $suflag $*
/opt/rtai/linux-4.4.43-x86_64-hal-6-rtai-5.0/realtime/bin/rtai-load :
ligne 185 : 31041 Erreur de segmentation $suflag $*
[***@lappc-f586 latency]# cd ../preempt/
[***@lappc-f586 preempt]# ./run
*
*
* Type ^C to stop this application.
*
*
/opt/rtai/linux-4.4.43-x86_64-hal-6-rtai-5.0/realtime/bin/rtai-load :
ligne 185 : 31167 Erreur de segmentation $suflag $*
/opt/rtai/linux-4.4.43-x86_64-hal-6-rtai-5.0/realtime/bin/rtai-load :
ligne 185 : 31194 Erreur de segmentation $suflag $*
[***@lappc-f586 preempt]# cd ../
latency/ preempt/ switches/
[***@lappc-f586 preempt]# cd ../switches/
[***@lappc-f586 switches]# ./run
*
*
* Type ^C to stop this application.
*
*


Wait for it ...
/opt/rtai/linux-4.4.43-x86_64-hal-6-rtai-5.0/realtime/bin/rtai-load :
ligne 185 : 31318 Erreur de segmentation $suflag $*
[***@lappc-f586 switches]#


Cheers,

Emmanuel.
Paolo Mantegazza
2018-07-06 13:11:01 UTC
Permalink
It is an issue at user space calibration. Having seen it run on a significant number of installations, back to a 2 CPUs PIII, Debian 5.3, I've difficulties in thinking to what is happening on your machine. Have you cared of all the things told in README.CONF_RMRKS.
Meanwhile, there is a quick way out: insmod rtai_sched.ko user_latency=1000.
Paolo
______________________________________
From: Rtai [rtai-***@rtai.org] on behalf of Emmanuel Pacaud [***@lapp.in2p3.fr]
Sent: Friday, July 6, 2018 10:43 AM
To: ***@rtai.org
Subject: [Rtai] Issue with RTAI 5.0/5.1 on CentOS 7

Hi,

I have installed rtai 5.1 and a patched vanilla linux kernel 4.4.43 on a CentOS 7 distribution. Compilation and installation went fine after a few tries in order to understand what kernel options are needed by CentOS to boot correctly.

But when I run the testsuite, I get some kernel oops, likely when the userspace API is used.

In fact, as soon rtai_sched module is installed, linux complains:

insmod rtai_hal.ko

[62619.200082] I-pipe: head domain RTAI registered.
[62619.200176] RTAI[hal]: mounted. ISOL_CPUS_MASK: e.
[62619.200210] SYSINFO - # CPUs: 4, TIMER NAME: 'lapic', TIMER IRQ: 4354, TIMER FREQ: 93641996, CLOCK NAME: 'tsc', CLOCK FREQ: 2996554000, CPU FREQ: 2996554000, LINUX TIMER IRQ: 4354.
[62619.200314]
REMARK: RTAI WILL NOT ACCESS USER SPACE ON STAC! KS ARGS ITS WAY.

insmod rtai_sched.ko

[62733.070351] RTAI[malloc]: global heap size = 2097152 bytes, <BSD>.
[62733.070478] , kstacks pool size = 524288 bytes.
[62733.070655] RTAI[sched]: hard timer type/freq = lapic/93641996(Hz); timing: ONESHOT; linear timed lists.
[62733.070860] RTAI[sched]: Linux timer freq = 250 (Hz), TimeBase freq = 2996554000 hz.
[62733.070968] RTAI[sched]: timer setup = 74 ns, resched latency = 0 ns.
[62733.071664] ------------[ cut here ]------------
[62733.071765] Kernel BUG at ffffffff810a4b90 [verbose debug info unavailable]
[62733.071872] invalid opcode: 0000 [#9] SMP
[62733.072114] Modules linked in: rtai_sched(O+) rtai_hal(O) ebtable_nat ebtable_broute bridge stp llc ip6table_mangle ip6table_raw iptable_mangle iptable_raw ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ipmi_d! evintf dcdbas pcspkr sg ipmi_si ipmi_msghandler shpchp ip_tables x_tables xfs libcrc32c crc32c_generic sr_mod sd_mod ahci libahci tg3 libphy igb i2c_algo_bit i2c_core hwmon ptp pps_core libata megaraid_sas scsi_mod dm_mirror dm_region_hash dm_log dm_mod ipv6 [last unloaded: rtai_hal]
[62733.076051] CPU: 0 PID: 30482 Comm: calibrate Tainted: G D O 4.4.43-hal-6-rtai-5.0 #14
[62733.076183] Hardware name: Dell Inc. PowerEdge T630/0W9WXC, BIOS 1.0.4 08/29/2014
[62733.076290] task: ffff880468732f00 ti: ffff88046a2bc000 task.ti: ffff88046a2bc000
[62733.076398] RIP: 0010:[<ffffffff810a4b90>] [<ffffffff810a4b90>] __audit_syscall_entry+0x2f/0xdc
[62733.076603] RSP: 0018:ffff88046a2bfed8 EFLAGS: 00010202
[62733.076705] RAX: ffff880468732f00 RBX: ffff88046af34800 RCX: 0000000000000000
[62733.076812] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000000 00000e7
[62733.076919] RBP: ffff88046a2bfee8 R08: ff! ffffffffffff70 R09: ffff880468732f00
[62733.077026] R10: ffffffffffffff70 R11: 0000000000000246 R12: 00007f9ce0308838
[62733.077133] R13: 00007f9ce030de80 R14: 0000000000000000 R15: 0000000000000000
[62733.077241] FS: 00007f9ce0958740(0000) GS:ffff88047fc00000(0000) knlGS:0000000000000000
[62733.077350] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[62733.077453] CR2: 00007f9ce000b8d0 CR3: 0000000469d11000 CR4: 00000000001406f0
[62733.077560] I-pipe domain Linux
[62733.077657] Stack:
[62733.077751] ffff88046a2bff58 00007f9ce0308838 0000000000000000 ffffffff810012a0
[62733.078145] 0000000000000000 0000000000010246 0000000000000014 0000000000000000
[62733.078539] 0000000000000000 ffffffff81033f74 0000000000000200 0000000000000000
[62733.078933] Call Trace:
[62733.079030] [<ffffffff810012a0>] ? syscall_trace_enter_! phase1+0xe3/0xec
[62733.079137] [<ffffffff81033f74>] ? do_page_fault+0x4e/0x7e
[62733.079240] [<ffffffff813c5f87>] ? tracesys+0xd/0x44
[62733.079342] Code: 0c 25 c0 ac 00 00 48 89 e5 41 54 53 49 8b 99 70 05 00 00 48 85 db 0f 84 b7 00 00 00 83 7b 04 00 75 09 83 bb 40 02 00 00 00 74 02 <0f> 0b 83 3d 83 30 6b 00 00 0f 84 99 00 00 00 49 8b 41 08 44 8b
[62733.084167] RIP [<ffffffff810a4b90>] __audit_syscall_entry+0x2f/0xdc
[62733.084344] RSP <ffff88046a2bfed8>
[62733.084461] ---[ end trace f782b5ddf448fd9a ]---
[62733.085369] USERMODE CHECK: ERROR.
[62733.085467] USERMODE CHECK PROVIDED (ns): KernelLatency -1, UserLatency -1.
[62733.398278] KERNEL SPACE LATENCY ENDED AT CYCLE: 3121, LATENCY = 1822, VARIANCE = 13840/10004569, GAIN = 345847/1000000000, LEAST = 1620.
[62733.501148] AFTER KERNEL CALIBRATION (WITH RTAI TASK, ns): Kerne lLatency 608, UserLatency -1 (CALIBRATION: PERIOD 10000 (ns), ! TIME 415573612 (ns)).
[62733.501690] ------------[ cut here ]------------
[62733.501791] Kernel BUG at ffffffff810a4b90 [verbose debug info unavailable]
[62733.501939] invalid opcode: 0000 [#10] SMP
[62733.502181] Modules linked in: rtai_sched(O+) rtai_hal(O) ebtable_nat ebtable_broute bridge stp llc ip6table_mangle ip6table_raw iptable_mangle iptable_raw ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter ipmi_devintf dcdbas pcspkr sg ipmi_si ipmi_msghandler shpchp ip_tables x_tables xfs libcrc32c crc32c_generic sr_mod sd_mod ahci libahci tg3 libphy igb i2c_algo_bit i2c_core hwmon ptp pps_core libata megaraid_sas scsi_mod dm_mirror dm_region_hash dm_log dm_mod ipv6 [last unloaded: rtai_hal]
[62733.506078] CPU: 0 PID: 30483 Comm: calibrate Tainted: G D O 4.4.43-hal-6-rtai-5.0 #14
[62733.506210] Hardware name: Dell Inc. PowerEdge T630/0W9WXC, BIOS 1.0! .4 08/29/2014
[62733.506318] task: ffff880468732f00 ti: ffff88046a2bc000 task.ti: ffff88046a2bc000
[62733.506425] RIP: 0010:[<ffffffff810a4b90>] [<ffffffff810a4b90>] __audit_syscall_entry+0x2f/0xdc
[62733.506630] RSP: 0018:ffff88046a2bfed8 EFLAGS: 00010202
[62733.506732] RAX: ffff880468732f00 RBX: ffff88046af36800 RCX: 0000000000021000
[62733.506839] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000000000000c
[62733.506946] RBP: ffff88046a2bfee8 R08: 0000000000021000 R09: ffff880468732f00
[62733.507053] R10: 0000000000021000 R11: 0000000000003246 R12: 00007f1d1231a4e0
[62733.507160] R13: 0000000000000000 R14: 0000000000000fff R15: 00007f1d12317760
[62733.507267] FS: 00007f1d12963740(0000) GS:ffff88047fc00000(0000) knlGS:0000000000000000
[62733.507376] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[62733.507480] CR2: 00007f1d12034a 70 CR3: 0000000469d11000 CR4: 00000000001406f0
[6273! 3.507587] I-pipe domain Linux
[62733.507683] Stack:
[62733.507777] ffff88046a2bff58 00007f1d1231a4e0 0000000000000000 ffffffff810012a0
[62733.508171] 0000000000003082 ffff880468733780 0000000000000000 0000000000400b10
[62733.508564] 00007fff657aeee0 0000000000000000 0000000000000000 ffff88046a2bff58
[62733.508958] Call Trace:
[62733.509054] [<ffffffff810012a0>] ? syscall_trace_enter_phase1+0xe3/0xec
[62733.509165] [<ffffffffa0861c7a>] ? lxrt_intercept_syscall+0x81/0x172 [rtai_sched]
[62733.509273] [<ffffffff813c5f87>] ? tracesys+0xd/0x44
[62733.509375] Code: 0c 25 c0 ac 00 00 48 89 e5 41 54 53 49 8b 99 70 05 00 00 48 85 db 0f 84 b7 00 00 00 83 7b 04 00 75 09 83 bb 40 02 00 00 00 74 02 <0f> 0b 83 3d 83 30 6b 00 00 0f 84 99 00 00 00 49 8b 41 08 44 8b
[62733.519504] RIP [<ffffffff810a4b90>] __audit_sys! call_entry+0x2f/0xdc
[62733.519681] RSP <ffff88046a2bfed8>
[62733.519785] ---[ end trace f782b5ddf448fd9b ]---
[62733.519891] LXRT releases PID 30483 (ID: calibrate).
[62733.521116] USERMODE USER SPACE CALIBRATION: ERROR.
[62733.521224] AFTER USER CALIBRATION (ns): KernelLatency 608, UserLatency 0 (CALIBRATION: PERIOD 10000 (ns), TIME 19932389 (ns)).
[62733.521363] FINAL CALIBRATION SUMMARY (ns): KernelLatency 608, UserLatency 0.

Any idea of what is going wrong ?

I have also tried rtai 5.0 + linux 4.4.43, with the same result. In fact, with this version, but running Scientific Linux 6, RTAI works fine. The difference in the kernel configuration between Scinetific Linux 6 and CentOS 7 is a few options needed by systemd (CONFIG_FHANDLE, CONFIG_CGROUPS...)

Here are the test suite results:

[***@lappc-f586 testsuite]# cd kern/
[***@lappc-f586 kern]# cd late! ncy/
[***@lappc-f586 latency]# ./run
*
*
* Type ^C to stop this application.
*
*
RTAI Testsuite - KERNEL space latency test (output data in nanoseconds)

*** latency verification tool with RTAI own real time kernel tasks ***
*** period = 100000 (ns), avrgtime = 1 (s) ***

RTH| lat min| ovl min| lat avg| lat max| ovl max| overruns
RTD| -9| -9| 21| 1434| 1434| 0
RTD| -9| -9| 25| 6247| 6247| 0
RTD| ! -9| -9| 24| 1265| 6247| 0
RTD| -9| -9| 24| 1833| 6247| 0
RTD| -9| -9| 24| 1686| 6247| 0
RTD| -9| -9| 25| 1691| 6247| 0
^CRTD| -9| -9| 25| 1691| 6247| 0
[***@lappc-f586 latency]# cd ../
latency/ &nbs! p;preempt/ switches/
[***@lappc-f586 latency]# cd ../preempt/
[***@lappc-f586 preempt]# ./run
*
*
* Type ^C to stop this application.
*
*
RTAI Testsuite - UP preempt (all data in nanoseconds)
RTH| lat min| lat avg| lat max| jit fast| jit slow
RTD| -3| 16| 952| 1516| 1646
RTD| -3| 16| 1040| 1516| 1646
RTD| -3| 17| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 17| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| ; 16| 10! 74| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 17| 1074| 1516| 1646
^CRTD| -3| 17| 1074| 1516| 1646
[***@lappc-f586 preempt]# cd ../
latency/ preempt/ switches/
[***@lappc-f586 preempt]# cd ../switches/
[***@lappc-f586 switches]# ./run
*
*
* Type ^C to stop this application.
*
*
Jul 6 04:42:23 lappc-f586 kernel: #012#012CPU USE SUMMARY
Jul 6 04:42:23 lappc-f586 kernel: # 0 -> 16171
Jul 6 04:42:23 lappc-f586 kernel: # 1 -> 0
Jul 6 04:42:23 lappc-f586 kernel: # 2 -> 0
Jul 6 04:42:23 lappc-f586 kernel: # 3 -> 0
Jul 6 04:42:23 lappc-f586 kernel: END OF CPU USE SUMMARY
Jul 6 04:42:30 lappc-f586 kernel: #012Wait for it ...
Jul 6 04:42:30 lappc-f586 kernel: #012#012FOR 10 TASKS: TIME 5 (ms), SUSP/RES SWITCHES 40000, SWITCH TIME (INCLUDING FULL FP SUPPORT) 143 (ns)
Jul 6 04:42:30 lappc-f586 kernel: #012FOR 10 TASKS: TIME 5 (ms), SEM SIG/WAIT SWITCHES 40000, SWITCH TIME (INCLUDING FULL FP SUPPORT) 144 (ns)
Jul 6 04:42:30 lappc-f586 kernel: #012FOR 10 TASKS: TIME 7 (ms), RPC/RCV-RET SWITCHES 40000, SWITCH TIME (INCLUDING FULL! FP SUPPORT) 175 (ns)
^C[***@lappc-f586 switches]# cd ../../user/latency/
[***@lappc-f586 latency]# ./run
*
*
* Type ^C to stop this application.
*
*
/opt/rtai/linux-4.4.43-x86_64-hal-6-rtai-5.0/realtime/bin/rtai-load : ligne 185 : 31014 Erreur de segmentation $suflag $*
/opt/rtai/linux-4.4.43-x86_64-hal-6-rtai-5.0/realtime/bin/rtai-load : ligne 185 : 31041 Erreur de segmentation $suflag $*
[***@lappc-f586 latency]# cd ../preempt/
[***@lappc-f586 preempt]# ./run
*
*
* Type ^C to stop this application.
*
*
/opt/rtai/linux-4.4.43-x86_64-hal-6-rtai-5.0/realtime/bin/rtai-load : ligne 185 : 31167 Erreur de segmentation $suflag $*
/opt/rtai/linux-4.4.43-x86_64-hal-6-rtai-5.0/realtime/bin/rtai-load : ligne 185 : 31194 Erreur de segmentation $suflag $*
[ro! ***@lappc-f586 preempt]# cd ../
latency/ preempt/ switches/
[***@lappc-f586 preempt]# cd ../switches/
[***@lappc-f586 switches]# ./run
*
*
* Type ^C to stop this application.
*
*


Wait for it ...
/opt/rtai/linux-4.4.43-x86_64-hal-6-rtai-5.0/realtime/bin/rtai-load : ligne 185 : 31318 Erreur de segmentation $suflag $*
[***@lappc-f586 switches]#


Cheers,

Emmanuel.
Emmanuel Pacaud
2018-07-09 14:37:55 UTC
Permalink
Hi,

It turns out the problem was the CONFIG_AUDITSYSCALL linux kernel
compilation parameter (General setup->Enable system-call auditing
support), which is listed in README.CONF_RMRKS and should be disabled.

What was puzzling in my case is the same kernel with the same
compilation options on the same type of machine and with AUDITSYCALL
enabled was working with Scientific Linux 6, but not with CentOS 7.
This is most probably due to the fact CentOS is runnning a daemon that
makes use of this kernel feature.

Thanks Paolo for your help.

Cheers,

Emmanuel.


Le ven. 6 juil. 2018 à 15:11, Paolo Mantegazza
Post by Paolo Mantegazza
It is an issue at user space calibration. Having seen it run on a
significant number of installations, back to a 2 CPUs PIII, Debian
5.3, I've difficulties in thinking to what is happening on your
machine. Have you cared of all the things told in README.CONF_RMRKS.
Meanwhile, there is a quick way out: insmod rtai_sched.ko
user_latency=1000.
Paolo
______________________________________
Sent: Friday, July 6, 2018 10:43 AM
Subject: [Rtai] Issue with RTAI 5.0/5.1 on CentOS 7
Hi,
I have installed rtai 5.1 and a patched vanilla linux kernel 4.4.43
on a CentOS 7 distribution. Compilation and installation went fine
after a few tries in order to understand what kernel options are
needed by CentOS to boot correctly.
But when I run the testsuite, I get some kernel oops, likely when the
userspace API is used.
insmod rtai_hal.ko
[62619.200082] I-pipe: head domain RTAI registered.
[62619.200176] RTAI[hal]: mounted. ISOL_CPUS_MASK: e.
2996554000, CPU FREQ: 2996554000, LINUX TIMER IRQ: 4354.
[62619.200314]
REMARK: RTAI WILL NOT ACCESS USER SPACE ON STAC! KS ARGS ITS WAY.
insmod rtai_sched.ko
[62733.070351] RTAI[malloc]: global heap size = 2097152 bytes, <BSD>.
[62733.070478] , kstacks pool size = 524288 bytes.
[62733.070655] RTAI[sched]: hard timer type/freq =
lapic/93641996(Hz); timing: ONESHOT; linear timed lists.
[62733.070860] RTAI[sched]: Linux timer freq = 250 (Hz), TimeBase freq = 2996554000 hz.
[62733.070968] RTAI[sched]: timer setup = 74 ns, resched latency = 0 ns.
[62733.071664] ------------[ cut here ]------------
[62733.071765] Kernel BUG at ffffffff810a4b90 [verbose debug info unavailable]
[62733.071872] invalid opcode: 0000 [#9] SMP
[62733.072114] Modules linked in: rtai_sched(O+) rtai_hal(O)
ebtable_nat ebtable_broute bridge stp llc ip6table_mangle
ip6table_raw iptable_mangle iptable_raw ebtable_filter ebtables
ip6table_filter ip6_tables iptable_filter ipmi_d! evintf dcdbas
pcspkr sg ipmi_si ipmi_msghandler shpchp ip_tables x_tables xfs
libcrc32c crc32c_generic sr_mod sd_mod ahci libahci tg3 libphy igb
i2c_algo_bit i2c_core hwmon ptp pps_core libata megaraid_sas scsi_mod
dm_mirror dm_region_hash dm_log dm_mod ipv6 [last unloaded: rtai_hal]
[62733.076051] CPU: 0 PID: 30482 Comm: calibrate Tainted: G D
O 4.4.43-hal-6-rtai-5.0 #14
[62733.076183] Hardware name: Dell Inc. PowerEdge T630/0W9WXC, BIOS 1.0.4 08/29/2014
[62733.076290] task: ffff880468732f00 ti: ffff88046a2bc000 task.ti: ffff88046a2bc000
[62733.076398] RIP: 0010:[<ffffffff810a4b90>] [<ffffffff810a4b90>]
__audit_syscall_entry+0x2f/0xdc
[62733.076603] RSP: 0018:ffff88046a2bfed8 EFLAGS: 00010202
[62733.076705] RAX: ffff880468732f00 RBX: ffff88046af34800 RCX: 0000000000000000
[62733.076812] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000000 00000e7
[62733.076919] RBP: ffff88046a2bfee8 R08: ff! ffffffffffff70 R09: ffff880468732f00
[62733.077026] R10: ffffffffffffff70 R11: 0000000000000246 R12: 00007f9ce0308838
[62733.077133] R13: 00007f9ce030de80 R14: 0000000000000000 R15: 0000000000000000
[62733.077241] FS: 00007f9ce0958740(0000) GS:ffff88047fc00000(0000) knlGS:0000000000000000
[62733.077350] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[62733.077453] CR2: 00007f9ce000b8d0 CR3: 0000000469d11000 CR4: 00000000001406f0
[62733.077560] I-pipe domain Linux
[62733.077751] ffff88046a2bff58 00007f9ce0308838 0000000000000000 ffffffff810012a0
[62733.078145] 0000000000000000 0000000000010246 0000000000000014 0000000000000000
[62733.078539] 0000000000000000 ffffffff81033f74 0000000000000200 0000000000000000
[62733.079030] [<ffffffff810012a0>] ? syscall_trace_enter_!
phase1+0xe3/0xec
[62733.079137] [<ffffffff81033f74>] ? do_page_fault+0x4e/0x7e
[62733.079240] [<ffffffff813c5f87>] ? tracesys+0xd/0x44
[62733.079342] Code: 0c 25 c0 ac 00 00 48 89 e5 41 54 53 49 8b 99 70
05 00 00 48 85 db 0f 84 b7 00 00 00 83 7b 04 00 75 09 83 bb 40 02 00
00 00 74 02 <0f> 0b 83 3d 83 30 6b 00 00 0f 84 99 00 00 00 49 8b 41
08 44 8b
[62733.084167] RIP [<ffffffff810a4b90>]
__audit_syscall_entry+0x2f/0xdc
[62733.084344] RSP <ffff88046a2bfed8>
[62733.084461] ---[ end trace f782b5ddf448fd9a ]---
[62733.085369] USERMODE CHECK: ERROR.
[62733.085467] USERMODE CHECK PROVIDED (ns): KernelLatency -1,
UserLatency -1.
[62733.398278] KERNEL SPACE LATENCY ENDED AT CYCLE: 3121, LATENCY =
1822, VARIANCE = 13840/10004569, GAIN = 345847/1000000000, LEAST = 1620.
[62733.501148] AFTER KERNEL CALIBRATION (WITH RTAI TASK, ns): Kerne
lLatency 608, UserLatency -1 (CALIBRATION: PERIOD 10000 (ns), ! TIME
415573612 (ns)).
[62733.501690] ------------[ cut here ]------------
[62733.501791] Kernel BUG at ffffffff810a4b90 [verbose debug info unavailable]
[62733.501939] invalid opcode: 0000 [#10] SMP
[62733.502181] Modules linked in: rtai_sched(O+) rtai_hal(O)
ebtable_nat ebtable_broute bridge stp llc ip6table_mangle
ip6table_raw iptable_mangle iptable_raw ebtable_filter ebtables
ip6table_filter ip6_tables iptable_filter ipmi_devintf dcdbas pcspkr
sg ipmi_si ipmi_msghandler shpchp ip_tables x_tables xfs libcrc32c
crc32c_generic sr_mod sd_mod ahci libahci tg3 libphy igb i2c_algo_bit
i2c_core hwmon ptp pps_core libata megaraid_sas scsi_mod dm_mirror
dm_region_hash dm_log dm_mod ipv6 [last unloaded: rtai_hal]
[62733.506078] CPU: 0 PID: 30483 Comm: calibrate Tainted: G D
O 4.4.43-hal-6-rtai-5.0 #14
[62733.506210] Hardware name: Dell Inc. PowerEdge T630/0W9WXC, BIOS 1.0! .4 08/29/2014
[62733.506318] task: ffff880468732f00 ti: ffff88046a2bc000 task.ti: ffff88046a2bc000
[62733.506425] RIP: 0010:[<ffffffff810a4b90>] [<ffffffff810a4b90>]
__audit_syscall_entry+0x2f/0xdc
[62733.506630] RSP: 0018:ffff88046a2bfed8 EFLAGS: 00010202
[62733.506732] RAX: ffff880468732f00 RBX: ffff88046af36800 RCX: 0000000000021000
[62733.506839] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000000000000c
[62733.506946] RBP: ffff88046a2bfee8 R08: 0000000000021000 R09: ffff880468732f00
[62733.507053] R10: 0000000000021000 R11: 0000000000003246 R12: 00007f1d1231a4e0
[62733.507160] R13: 0000000000000000 R14: 0000000000000fff R15: 00007f1d12317760
[62733.507267] FS: 00007f1d12963740(0000) GS:ffff88047fc00000(0000) knlGS:0000000000000000
[62733.507376] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[62733.507480] CR2: 00007f1d12034a 70 CR3: 0000000469d11000 CR4: 00000000001406f0
[6273! 3.507587] I-pipe domain Linux
[62733.507777] ffff88046a2bff58 00007f1d1231a4e0 0000000000000000 ffffffff810012a0
[62733.508171] 0000000000003082 ffff880468733780 0000000000000000 0000000000400b10
[62733.508564] 00007fff657aeee0 0000000000000000 0000000000000000 ffff88046a2bff58
[62733.509054] [<ffffffff810012a0>] ?
syscall_trace_enter_phase1+0xe3/0xec
[62733.509165] [<ffffffffa0861c7a>] ?
lxrt_intercept_syscall+0x81/0x172 [rtai_sched]
[62733.509273] [<ffffffff813c5f87>] ? tracesys+0xd/0x44
[62733.509375] Code: 0c 25 c0 ac 00 00 48 89 e5 41 54 53 49 8b 99 70
05 00 00 48 85 db 0f 84 b7 00 00 00 83 7b 04 00 75 09 83 bb 40 02 00
00 00 74 02 <0f> 0b 83 3d 83 30 6b 00 00 0f 84 99 00 00 00 49 8b 41
08 44 8b
[62733.519504] RIP [<ffffffff810a4b90>] __audit_sys!
call_entry+0x2f/0xdc
[62733.519681] RSP <ffff88046a2bfed8>
[62733.519785] ---[ end trace f782b5ddf448fd9b ]---
[62733.519891] LXRT releases PID 30483 (ID: calibrate).
[62733.521116] USERMODE USER SPACE CALIBRATION: ERROR.
[62733.521224] AFTER USER CALIBRATION (ns): KernelLatency 608,
UserLatency 0 (CALIBRATION: PERIOD 10000 (ns), TIME 19932389 (ns)).
[62733.521363] FINAL CALIBRATION SUMMARY (ns): KernelLatency 608, UserLatency 0.
Any idea of what is going wrong ?
I have also tried rtai 5.0 + linux 4.4.43, with the same result. In
fact, with this version, but running Scientific Linux 6, RTAI works
fine. The difference in the kernel configuration between Scinetific
Linux 6 and CentOS 7 is a few options needed by systemd
(CONFIG_FHANDLE, CONFIG_CGROUPS...)
*
*
* Type ^C to stop this application.
*
*
RTAI Testsuite - KERNEL space latency test (output data in
nanoseconds)
*** latency verification tool with RTAI own real time kernel tasks ***
*** period = 100000 (ns), avrgtime = 1 (s) ***
RTH| lat min| ovl min| lat avg| lat max| ovl max|
overruns
RTD| -9| -9| 21| 1434| 1434|
0
RTD| -9| -9| 25| 6247| 6247|
0
RTD| ! -9| -9| 24| 1265| 6247|
0
RTD| -9| -9| 24| 1833| 6247|
0
RTD| -9| -9| 24| 1686| 6247|
0
RTD| -9| -9| 25| 1691| 6247|
0
^CRTD| -9| -9| 25| 1691| 6247|
0
latency/ &nbs! p;preempt/ switches/
*
*
* Type ^C to stop this application.
*
*
RTAI Testsuite - UP preempt (all data in nanoseconds)
RTH| lat min| lat avg| lat max| jit fast| jit slow
RTD| -3| 16| 952| 1516| 1646
RTD| -3| 16| 1040| 1516| 1646
RTD| -3| 17| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 17| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| ; 16| 10! 74| 1516|
1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 16| 1074| 1516| 1646
RTD| -3| 17| 1074| 1516| 1646
^CRTD| -3| 17| 1074| 1516| 1646
latency/ preempt/ switches/
*
*
* Type ^C to stop this application.
*
*
Jul 6 04:42:23 lappc-f586 kernel: #012#012CPU USE SUMMARY
Jul 6 04:42:23 lappc-f586 kernel: # 0 -> 16171
Jul 6 04:42:23 lappc-f586 kernel: # 1 -> 0
Jul 6 04:42:23 lappc-f586 kernel: # 2 -> 0
Jul 6 04:42:23 lappc-f586 kernel: # 3 -> 0
Jul 6 04:42:23 lappc-f586 kernel: END OF CPU USE SUMMARY
Jul 6 04:42:30 lappc-f586 kernel: #012Wait for it ...
Jul 6 04:42:30 lappc-f586 kernel: #012#012FOR 10 TASKS: TIME 5 (ms),
SUSP/RES SWITCHES 40000, SWITCH TIME (INCLUDING FULL FP SUPPORT) 143
(ns)
Jul 6 04:42:30 lappc-f586 kernel: #012FOR 10 TASKS: TIME 5 (ms), SEM
SIG/WAIT SWITCHES 40000, SWITCH TIME (INCLUDING FULL FP SUPPORT) 144
(ns)
Jul 6 04:42:30 lappc-f586 kernel: #012FOR 10 TASKS: TIME 7 (ms),
RPC/RCV-RET SWITCHES 40000, SWITCH TIME (INCLUDING FULL! FP SUPPORT)
175 (ns)
*
*
* Type ^C to stop this application.
*
*
ligne 185 : 31014 Erreur de segmentation $suflag $*
ligne 185 : 31041 Erreur de segmentation $suflag $*
*
*
* Type ^C to stop this application.
*
*
ligne 185 : 31167 Erreur de segmentation $suflag $*
ligne 185 : 31194 Erreur de segmentation $suflag $*
latency/ preempt/ switches/
*
*
* Type ^C to stop this application.
*
*
Wait for it ...
ligne 185 : 31318 Erreur de segmentation $suflag $*
Cheers,
Emmanuel.
Loading...