Can printf() be made SMP safe?
Dave DeGroote
Dave.DeGroote at astrobotic.com
Fri May 14 01:09:53 UTC 2021
I'm still beating my head against this so I wrote a simple RTEMS only test to narrow it down and the problem is still occurring. Sometimes it crashes, hangs, or runs fine, depending on the number of RTEMS objects created (it sometimes works with fewer objects and fails with more).
- The code starts two tasks with printf() loops.
- To start, the printf()'s do not overlap - this always works
- The code then switches to fast overlapping printf()'s where it fails (depending on the #of objects).
The compile command, code, and results are below.
Thanks for any help or insight!
Compile command (gcc version 7.2.0 (Cobham Gaisler RCC 1.3-rc7) ):
sparc-gaisler-rtems5-gcc -Wall -g -O2 -Werror -mcpu=leon3 -mfix-gr712rc -qbsp=gr712rc_smp -o smp_test smp_test.c
Results: fails with 20 semaphores:
gncsim at gncsim:~/grmon-pro-3.0.9/linux/bin64$ sudo ./grmon -ftdi -log /tmp/grmon-log.log -e "load ~/lander/flat_sat/DaveD/smp_test; run" -u
GRMON LEON debug monitor v3.0.9 64-bit pro version
Copyright (C) 2018 Cobham Gaisler - All rights reserved.
For latest updates, go to http://www.gaisler.com/
Comments or bug-reports to support at gaisler.com
JTAG chain (1): GR712RC
Device ID: 0x712
GRLIB build version: 3696
Detected system: GR712RC
Detected frequency: 80 MHz
Component Vendor
LEON3FT SPARC V8 Processor Cobham Gaisler
<... snip ...>
Timer Unit with Latches Cobham Gaisler
Use command 'info sys' to print a detailed report of attached cores
40000000 .text 191.7kB / 191.7kB [===============>] 100%
4002FED0 .rtemsroset 96B [===============>] 100%
40031F40 .data 5.6kB / 5.6kB [===============>] 100%
Total size: 197.38kB (774.38kbit/s)
Entry point 0x40000000
Image /home/gncsim/lander/flat_sat/DaveD/smp_test loaded
t1a:0 <0>
t2a:1 [0]
t1a:0 <1>
t2a:1 [1]
t1a:0 <2>
t2a:1 [2]
t2b:1 [0]
t1b:0 <0>
t2b:1 [1]
CPU 0: Unknown watchpoint hit
0x400217b4: ba100015 mov %l5, %i5 <_vfprintf_r+316>
CPU 1: IU exception (tt = 0x2B, data store error)
0x40011818: 96100001 mov %g1, %o3 <_Thread_queue_Queue_enqueue+108>
grmon3> bt cpu0
%pc %sp
#0 0x400217b4 0x4003eb60 <_vfprintf_r+0x13c>
#1 0x4001e1ec 0x4003ed38 <printf+0x2c>
#2 0x40001334 0x4003eda0 <task1+0x68>
#3 0x40010084 0x4003ee00 <_Thread_Entry_adaptor_numeric+0x8>
#4 0x4000ea8c 0x4003ee60 <_Thread_Handler+0x60>
#5 0x4000ea2c 0x4003eec0 <_Thread_Handler+0>
grmon3> bt cpu1
%pc %sp
#0 0x40011818 0x4003fae0 <_Thread_queue_Queue_enqueue+0x6c>
#1 0x40010c00 0x4003fb40 <_Thread_queue_Enqueue+0x80>
#2 0x4002ce60 0x4003fba8 <clock_nanosleep.part.4+0x134>
#3 0x4002cf34 0x4003fcd8 <nanosleep+0x10>
#4 0x400214c4 0x4003fd38 <usleep+0x48>
#5 0x400013dc 0x4003fda8 <task2+0x70>
#6 0x40010084 0x4003fe08 <_Thread_Entry_adaptor_numeric+0x8>
#7 0x4000ea8c 0x4003fe68 <_Thread_Handler+0x60>
#8 0x4000ea2c 0x4003fec8 <_Thread_Handler+0>
grmon3>
Results: works with 60 semaphores:
gncsim at gncsim:~/grmon-pro-3.0.9/linux/bin64$ sudo ./grmon -ftdi -log /tmp/grmon-log.log -e "load ~/lander/flat_sat/DaveD/smp_test; run" -u
GRMON LEON debug monitor v3.0.9 64-bit pro version
Copyright (C) 2018 Cobham Gaisler - All rights reserved.
For latest updates, go to http://www.gaisler.com/
Comments or bug-reports to support at gaisler.com
JTAG chain (1): GR712RC
Device ID: 0x712
GRLIB build version: 3696
Detected system: GR712RC
Detected frequency: 80 MHz
Component Vendor
LEON3FT SPARC V8 Processor Cobham Gaisler
<... snip ...>
Timer Unit with Latches Cobham Gaisler
Use command 'info sys' to print a detailed report of attached cores
40000000 .text 191.7kB / 191.7kB [===============>] 100%
4002FED0 .rtemsroset 96B [===============>] 100%
40031F40 .data 5.6kB / 5.6kB [===============>] 100%
Total size: 197.38kB (774.75kbit/s)
Entry point 0x40000000
Image /home/gncsim/lander/flat_sat/DaveD/smp_test loaded
t1a:0 <0>
t2a:1 [0]
t1a:0 <1>
t2a:1 [1]
t1a:0 <2>
t2a:1 [2]
t1b:0 <0>
t1b:0 <1>
t2b:1 [0]
t1b:0 <2>
t2b:1 [1]
t1b:0 <3>
t2b:1 [2]
t1b:0 <4>
t2b:1 [3]
t1b:0 <5>
t2b:1 [4]
t1b:0 <6>
t2b:1 [5]
t1b:0 <7>
t2b:1 [6]
t1b:0 <8>
............... runs to completion:
t1b:0 <298>
t2b:1 [297]
t1b:0 <299>
t2b:1 [298]
t1 done
CPU 0: Program exited normally.
CPU 1: Unknown watchpoint hit
0x4001a424: 01000000 nop
grmon3> q
Exiting GRMON
gncsim at gncsim:~/grmon-pro-3.0.9/linux/bin64$
Code:
==================
#include <rtems.h>
#define CONFIGURE_INIT
#include <bsp.h> /* for device driver prototypes */
#define CONFIGURE_APPLICATION_NEEDS_CONSOLE_DRIVER
#define CONFIGURE_APPLICATION_NEEDS_CLOCK_DRIVER
#define CONFIGURE_MAXIMUM_TASKS 8
#define CONFIGURE_MAXIMUM_SEMAPHORES 60
//#define CONFIGURE_MAXIMUM_SEMAPHORES 20
#define CONFIGURE_MAXIMUM_MESSAGE_QUEUES 20 // The value of this configuration option defines the maximum number of Classic API Message Queues that can be concurrently active.
#define CONFIGURE_MAXIMUM_FILE_DESCRIPTORS 32 // The value of this configuration option defines the maximum number of file like objects that can be concurrently open.
#define CONFIGURE_MAXIMUM_DRIVERS 32 // The value of this configuration option defines the number of device drivers.
#define CONFIGURE_MAXIMUM_PERIODS 1 //
#define CONFIGURE_RTEMS_INIT_TASKS_TABLE
#define CONFIGURE_INIT_TASK_ATTRIBUTES RTEMS_DEFAULT_ATTRIBUTES | RTEMS_FLOATING_POINT
#define CONFIGURE_EXTRA_TASK_STACKS (40 * RTEMS_MINIMUM_STACK_SIZE)
#define CONFIGURE_MICROSECONDS_PER_TICK RTEMS_MILLISECONDS_TO_MICROSECONDS(2)
#define CONFIGURE_INIT_TASK_PRIORITY 100
// Create separate schedulers for each CPU
#define CONFIGURE_MAXIMUM_PROCESSORS 2
#define CONFIGURE_MAXIMUM_PRIORITY 255
// Configuration Step 1 - Scheduler Algorithms
// - only scheduler algorithms defined here can be used
#define CONFIGURE_SCHEDULER_PRIORITY_SMP
#include <rtems/scheduler.h>
// Configuration Step 2 - Schedulers
// - Instantiate a scheduler for each CPU
RTEMS_SCHEDULER_PRIORITY_SMP(scha, CONFIGURE_MAXIMUM_PRIORITY + 1);
RTEMS_SCHEDULER_PRIORITY_SMP(schb, CONFIGURE_MAXIMUM_PRIORITY + 1);
// Configuration Step 3 - Scheduler Table
// - give each scheduler a symbolic name and assign a table index (the order in the table)
#define CONFIGURE_SCHEDULER_TABLE_ENTRIES \
RTEMS_SCHEDULER_TABLE_PRIORITY_SMP(scha, rtems_build_name('S', 'C', 'H', 'A')), \
RTEMS_SCHEDULER_TABLE_PRIORITY_SMP(schb, rtems_build_name('S', 'C', 'H', 'B'))
// Configuration Step 4 - Processor to Scheduler Assignment
// - assign cores to each scheduler instance
// - the table order is the scheduler instance & the cpu ID is the first parameter
#define CONFIGURE_SCHEDULER_ASSIGNMENTS \
RTEMS_SCHEDULER_ASSIGN(0, RTEMS_SCHEDULER_ASSIGN_PROCESSOR_MANDATORY), \
RTEMS_SCHEDULER_ASSIGN(1, RTEMS_SCHEDULER_ASSIGN_PROCESSOR_MANDATORY)
#include <rtems/confdefs.h>
#include <stdio.h>
#include <stdlib.h>
#define USLEEP_ONE_SEC 1000000
rtems_task task1(rtems_task_argument unused) {
int processorId = rtems_scheduler_get_processor();
// Slow interleaved printf's
for (int ii=0; ii<3; ii++) {
printf("t1a:%d <%d>\n", processorId, ii);
usleep(USLEEP_ONE_SEC);
}
usleep(USLEEP_ONE_SEC/2);
// Overlapping printf's
for (int ii=0; ii<300; ii++) {
printf("t1b:%d <%d>\n", processorId, ii);
usleep(1);
}
printf("t1 done\n");
exit(0);
}
rtems_task task2(rtems_task_argument unused) {
int processorId = rtems_scheduler_get_processor();
usleep(USLEEP_ONE_SEC/2);
// Slow interleaved printf's
for (int ii=0; ii<3; ii++) {
printf("t2a:%d [%d]\n", processorId, ii);
usleep(USLEEP_ONE_SEC);
}
// Overlapping printf's
for (int ii=0; ii<300; ii++) {
printf("t2b:%d [%d]\n", processorId, ii);
usleep(1);
}
printf("t2 done\n");
exit(0);
}
rtems_task Init(rtems_task_argument ignored) {
rtems_id tid1, tid2;
rtems_status_code status;
rtems_mode r_mode = RTEMS_PREEMPT | RTEMS_NO_ASR | RTEMS_NO_TIMESLICE | RTEMS_INTERRUPT_LEVEL(0);
rtems_attribute r_attributes = RTEMS_LOCAL | RTEMS_FLOATING_POINT;
status = rtems_task_create(rtems_build_name( 'T', 'S', 'K', '1'), 1, RTEMS_MINIMUM_STACK_SIZE, r_mode, r_attributes, &tid1);
if (status!=RTEMS_SUCCESSFUL) printf ("status1=%s (%x)\n", rtems_status_text(status), status);
status = rtems_task_create(rtems_build_name( 'T', 'S', 'K', '2'), 1, RTEMS_MINIMUM_STACK_SIZE, r_mode, r_attributes, &tid2);
if (status!=RTEMS_SUCCESSFUL) printf ("status2=%s (%x)\n", rtems_status_text(status), status);
// Create a scheduler for each CPU
rtems_id scheduler_a_id;
rtems_id scheduler_b_id;
status = rtems_scheduler_ident(rtems_build_name('S', 'C', 'H', 'A'), &scheduler_a_id);
if (status!=RTEMS_SUCCESSFUL) printf ("status3=%s (%x)\n", rtems_status_text(status), status);
status = rtems_scheduler_ident(rtems_build_name('S', 'C', 'H', 'B'), &scheduler_b_id);
if (status!=RTEMS_SUCCESSFUL) printf ("status4=%s (%x)\n", rtems_status_text(status), status);
// Set the scheduler for each task
status = rtems_task_set_scheduler(tid1, scheduler_a_id, 80);
if (status!=RTEMS_SUCCESSFUL) printf ("status5=%s (%x)\n", rtems_status_text(status), status);
status = rtems_task_set_scheduler(tid2, scheduler_b_id, 80);
if (status!=RTEMS_SUCCESSFUL) printf ("status6=%s (%x)\n", rtems_status_text(status), status);
// Start task 1
status = rtems_task_start(tid1, task1, 1);
if (status!=RTEMS_SUCCESSFUL) printf ("status7=%s (%x)\n", rtems_status_text(status), status);
// Start task 2
status = rtems_task_start(tid2, task2, 1);
if (status!=RTEMS_SUCCESSFUL) printf ("status8=%s (%x)\n", rtems_status_text(status), status);
// Suspend this task so subtasks keep running
rtems_task_suspend( RTEMS_SELF );
}
==================
[Astrobotic Logo] Dave DeGroote
Flight Software Engineer
Astrobotic
1016 N. Lincoln Avenue | Pittsburgh, PA 15233
office: 412.682.3282
________________________________
From: Dave DeGroote
Sent: Friday, April 30, 2021 3:07:17 PM
To: users at rtems.org
Subject: Can printf() be made SMP safe?
Hello,
I'm trying to get RTEMS running using SMP on a Leon3/gr712rc (2 cores). I have it partially running, but it crashes intermittently on printf's. Can anyone tell me if there's a way to make printf() SMP safe? printf appears to use termios which uses rtems_mutex_init() and rtems_binary_semaphore_init() which I don't think are SMP safe (but I'm also new to this so I'm not sure).
Thanks!
[Astrobotic Logo] Dave DeGroote
Flight Software Engineer
Astrobotic
1016 N. Lincoln Avenue | Pittsburgh, PA 15233
office: 412.682.3282
Disclaimer
The information contained in this communication from the sender is confidential. It is intended solely for use by the recipient and others authorized to receive it. If you are not the recipient, you are hereby notified that any disclosure, copying, distribution or taking action in relation of the contents of this information is strictly prohibited and may be unlawful.
This email has been scanned for viruses and malware, and may have been automatically archived by Mimecast Ltd, an innovator in Software as a Service (SaaS) for business. Providing a safer and more useful place for your human generated data. Specializing in; Security, archiving and compliance. To find out more visit the Mimecast website.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.rtems.org/pipermail/users/attachments/20210514/375b2560/attachment-0001.html>
More information about the users
mailing list