nuttx icon indicating copy to clipboard operation
nuttx copied to clipboard

[BUG] Premature exit of a process will cause the group to be released ahead of schedule.

Open husong2 opened this issue 3 weeks ago • 12 comments

Description / Steps to reproduce the issue

If there is a sleep call in a child thread, a crash will occur. The test case is as follows:

#define TIMEOUT 5		/* Timeout value of 5 seconds. */
#define INTHREAD 0		/* Control going to or is already for Thread */
#define INMAIN 1		/* Control going to or is already for Main */

static int sem1;			/* Manual semaphore */

static void *a_thread_func(void *arg)
{
	printf("a_thread_func entry \n");

	/* Indicate to main() that the thread was created. */
	sem1 = INTHREAD;

	/* Wait for main to detach change the attribute object and try and detach this thread.
	 * Wait for a timeout value of 10 seconds before timing out if the thread was not able
	 * to be detached. */
	sleep(TIMEOUT);
	printf("a_thread_func entry 2222\n");
	printf
	    ("Test FAILED: Did not detach the thread, main still waiting for it to end execution.\n");
	pthread_exit((void *)PTS_FAIL);
	return NULL;
}

int main(void)
{
	pthread_t new_th;
	pthread_attr_t new_attr;
	int ret_val;

	/* Initializing */
	sem1 = INMAIN;
	if (pthread_attr_init(&new_attr) != 0) {
		perror("Cannot initialize attribute object\n");
		return PTS_UNRESOLVED;
	}

	/* Create a new thread passing it the new attribute object */
	if (pthread_create(&new_th, &new_attr, a_thread_func, NULL) != 0) {
		perror("Error creating thread\n");
		return PTS_UNRESOLVED;
	}

	/* Wait for thread to indicate that the start routine for the thread has started. */
	while (sem1 == INMAIN)
		sleep(1);

	/* If pthread_detach fails, that means that the test fails as well. */
	ret_val = pthread_detach(new_th);

	if (ret_val != 0) {
		/* Thread is already detached. */
		if (ret_val == EINVAL) {
			printf("Test FAILED\n");
			return PTS_FAIL;
		}
		/* pthread_detach() failed for another reason. */
		else {
			printf("Error in pthread_detach(), error: %d\n",
			       ret_val);
			return PTS_UNRESOLVED;
		}
	}

	printf("Test PASSED\n");

	printf("Test PASSED 2222 \n");

	return PTS_PASS;

}

The specific logic is as follows: When the process starts to exit by calling exit(), the main thread will be removed from the group. The call chain is as follows:

#0  group_leave (tcb=tcb@entry=0x412a1470) at ../../nuttx/sched/group/group_leave.c:195
#1  0x0012a32e in nxtask_exithook (tcb=tcb@entry=0x412a1470, status=status@entry=0) at ../../nuttx/sched/task/task_exithook.c:481
#2  0x0012ad78 in _exit (status=112, status@entry=1093276784) at ../../nuttx/sched/task/exit.c:106
#3  0x001bb22c in exit (status=1093276784) at ../../nuttx/libs/libc/stdlib/lib_exit.c:126
#4  0x001b92bc in nxtask_startup (entrypt=entrypt@entry=0x412a1470, argc=<optimized out>, argv=<optimized out>) at ../../nuttx/libs/libc/sched/task_startup.c:66
#5  0x00129e14 in nxtask_start () at ../../nuttx/sched/task/task_start.c:104
#6  0x00000000 in ?? ()

Then, when the child thread executes sleep(), it will also trigger the exit process: the child thread is removed from the group and its TCB is deleted. At this point, since the TCB and the group are allocated together in memory, the memory space of the group will be deleted along with the TCB. The call chain is as follows:

#0  group_leave (tcb=tcb@entry=0x412a1a28) at ../../nuttx/sched/group/group_leave.c:195
#1  0x0012a32e in nxtask_exithook (tcb=tcb@entry=0x412a1a28, status=status@entry=0) at ../../nuttx/sched/task/task_exithook.c:481
#2  0x001209b0 in nx_pthread_exit (exit_value=exit_value@entry=0xffffffff) at ../../nuttx/sched/pthread/pthread_exit.c:123
#3  0x00116726 in pthread_exit (exit_value=exit_value@entry=0xffffffff) at ../../nuttx/libs/libc/pthread/pthread_exit.c:71
#4  0x00111084 in leave_cancellation_point () at ../../nuttx/libs/libc/sched/task_cancelpt.c:200
#5  0x00134238 in clock_nanosleep (clockid=clockid@entry=0, flags=flags@entry=0, rqtp=rqtp@entry=0x412a2ec8, rmtp=rmtp@entry=0x412a2ed8)
    at ../../nuttx/sched/signal/sig_nanosleep.c:208
#6  0x004256c0 in sleep (seconds=seconds@entry=5) at ../../nuttx/libs/libc/unistd/lib_sleep.c:112
#7  0x00211d0e in a_thread_func (arg=<error reading variable: value has been optimized out>)
    at ../../apps/testing/ltp/ltp/testcases/open_posix_testsuite/conformance/interfaces/pthread_attr_init/2-1.c:46
#8  0x004089e0 in pthread_startup (entry=<optimized out>, arg=<optimized out>) at ../../nuttx/libs/libc/pthread/pthread_create.c:61
#9  0x00445baa in pthread_start () at ../../nuttx/sched/pthread/pthread_create.c:147
#10 0x00000000 in ?? ()
#0  umm_delayfree (mem=mem@entry=0x4129fa28) at ../../nuttx/mm/umm_heap/umm_free.c:69
#1  0x00122c7e in nxsched_release_tcb (tcb=tcb@entry=0x4129fa28, ttype=1)
    at ../../nuttx/sched/sched/sched_releasetcb.c:213
#2  0x001d3a70 in nxtask_exit () at ../../nuttx/sched/task/task_exit.c:128
#3  0x0013b568 in up_exit (status=status@entry=0) at ../../nuttx/arch/arm/src/common/arm_exit.c:59
#4  0x00120808 in nx_pthread_exit (exit_value=exit_value@entry=0xffffffff)
    at ../../nuttx/sched/pthread/pthread_exit.c:131
#5  0x00116636 in pthread_exit (exit_value=exit_value@entry=0xffffffff)
    at ../../nuttx/libs/libc/pthread/pthread_exit.c:71
#6  0x00110f94 in leave_cancellation_point () at ../../nuttx/libs/libc/sched/task_cancelpt.c:204
#7  0x001340c0 in clock_nanosleep (clockid=clockid@entry=0, flags=flags@entry=0, rqtp=rqtp@entry=0x412a0ec8,
    rmtp=rmtp@entry=0x412a0ed8) at ../../nuttx/sched/signal/sig_nanosleep.c:208
#8  0x00424ef0 in sleep (seconds=seconds@entry=5) at ../../nuttx/libs/libc/unistd/lib_sleep.c:112
#9  0x0021153e in a_thread_func (arg=<error reading variable: value has been optimized out>)
    at ../../apps/testing/ltp/ltp/testcases/open_posix_testsuite/conformance/interfaces/pthread_attr_init/2-1.c:46
#10 0x00408210 in pthread_startup (entry=<optimized out>, arg=<optimized out>)
    at ../../nuttx/libs/libc/pthread/pthread_create.c:61
#11 0x004453da in pthread_start () at ../../nuttx/sched/pthread/pthread_create.c:147
#12 0x00000000 in ?? ()

Finally, the process starts to exit by calling up_exit(). The exit process still contains an operation to delete the TCB, resulting in a double free. The call chain is as follows:

#0  __assert (filename=filename@entry=0x4d1504 "../../nuttx/mm/mm_heap/mm_free.c", linenum=linenum@entry=67, msg=msg@entry=0x0) at ../../nuttx/libs/libc/assert/lib_assert.c:39
#1  0x00117e8e in add_delaylist (heap=heap@entry=0x4129e000, mem=mem@entry=0x4129f470, asan_check=false) at ../../nuttx/mm/mm_heap/mm_free.c:67
#2  0x001186e4 in mm_delayfree (heap=0x4129e000, mem=mem@entry=0x4129f470) at ../../nuttx/mm/mm_heap/mm_free.c:249
#3  0x00117c1e in umm_delayfree (mem=mem@entry=0x4129f470) at ../../nuttx/mm/umm_heap/umm_free.c:70
#4  0x00122cae in nxsched_release_tcb (tcb=tcb@entry=0x4129f470, ttype=0) at ../../nuttx/sched/sched/sched_releasetcb.c:213
#5  0x001d3aa0 in nxtask_exit () at ../../nuttx/sched/task/task_exit.c:128
#6  0x0013b598 in up_exit (status=status@entry=0) at ../../nuttx/arch/arm/src/common/arm_exit.c:59
#7  0x0012ac00 in _exit (status=112, status@entry=1093268592) at ../../nuttx/sched/task/exit.c:114
#8  0x001bb0e4 in exit (status=1093268592) at ../../nuttx/libs/libc/stdlib/lib_exit.c:126
#9  0x001b9174 in nxtask_startup (entrypt=entrypt@entry=0x4129f470, argc=<optimized out>, argv=<optimized out>) at ../../nuttx/libs/libc/sched/task_startup.c:66
#10 0x00129c74 in nxtask_start () at ../../nuttx/sched/task/task_start.c:104
#11 0x00000000 in ?? ()

On which OS does this issue occur?

[OS: Linux]

What is the version of your OS?

vela

NuttX Version

latest version

Issue Architecture

[Arch: arm64], [Arch: arm]

Issue Area

[Area: Other]

Host information

No response

Verification

  • [x] I have verified before submitting the report.

husong2 avatar Dec 02 '25 06:12 husong2

https://github.com/apache/nuttx/pull/11832#issuecomment-3591055544

husong2 avatar Dec 02 '25 06:12 husong2

@anchao do you have method to fix this issue? or let @husong2 revert your patch first.

xiaoxiang781216 avatar Dec 02 '25 06:12 xiaoxiang781216

@anchao do you have method to fix this issue? or let @husong2 revert your patch first.

Have you guys run this demo on the community code? I tested it locally and it worked fine.

nsh> hello
a_thread_func entry 
a_thread_func entry 2222
Test FAILED: Did not detach the thread, main still waiting for it to end execution.
Test PASSED
Test PASSED 2222 

Furthermore, the back reference design of the tcb group is flawless because all threads maintain a linked list reference count for tg_members, and the group's lifecycle is also maintained by this count. I suspect your issue only manifests in internal branches, right? Please check if you have changed the group logic.

anchao avatar Dec 02 '25 11:12 anchao

@anchao do you have method to fix this issue? or let @husong2 revert your patch first.

Have you guys run this demo on the community code? I tested it locally and it worked fine.

nsh> hello
a_thread_func entry 
a_thread_func entry 2222
Test FAILED: Did not detach the thread, main still waiting for it to end execution.
Test PASSED
Test PASSED 2222 

Furthermore, the back reference design of the tcb group is flawless because all threads maintain a linked list reference count for tg_members, and the group's lifecycle is also maintained by this count. I suspect your issue only manifests in internal branches, right? Please check if you have changed the group logic.

also verified on qemu arm64

Image

anchao avatar Dec 02 '25 11:12 anchao

Another point of suspicion is whether you reproduced the issue in SMP mode? If it's an internal branch, it might be related to @hujun260 previous changes from critical sections to spinlocks.

anchao avatar Dec 02 '25 11:12 anchao

arm64 smp:

Image

anchao avatar Dec 02 '25 11:12 anchao

@anchao ennnnn,You need to enable the CONFIG_CANCELLATION_POINTS macro, then compile the test case I provided to reproduce the issue. Note that I have modified the test case, so you need to re-copy it before compiling.

Image

give you a config to reference

/nuttx/boards/arm/qemu/qemu-armv8r-aarch32/configs/smp/defconfig

#
# This file is autogenerated: PLEASE DO NOT EDIT IT.
#
# You can use "make menuconfig" to make any modifications to the installed .config file.
# You can then do "make savedefconfig" to generate a new defconfig file that includes your
# modifications.
#
CONFIG_ARCH="arm"
CONFIG_ARCH_BOARD="qemu-armv8r-aarch32"
CONFIG_ARCH_BOARD_QEMU_ARMV8R_AARCH32=y
CONFIG_ARCH_CHIP="qemu"
CONFIG_ARCH_CHIP_QEMU_ARM=y
CONFIG_ARCH_CHIP_QEMU_CORTEXR52=y
CONFIG_ARCH_INTERRUPTSTACK=2048
CONFIG_ARCH_LOWVECTORS=y
CONFIG_ARM_GIC_VERSION=2
CONFIG_ARM_MPU=y
CONFIG_ARM_SEMIHOSTING_POWEROFF=y
CONFIG_ARM_THUMB=y
CONFIG_BOARDCTL_POWEROFF=y
CONFIG_BUILTIN=y
CONFIG_CANCELLATION_POINTS=y
CONFIG_DEBUG_ASSERTIONS=y
CONFIG_DEBUG_FEATURES=y
CONFIG_DEBUG_FULLOPT=y
CONFIG_DEBUG_SYMBOLS=y
CONFIG_DEFAULT_TASK_STACKSIZE=4096
CONFIG_EXAMPLES_HELLO=y
CONFIG_FLASH_SIZE=1048576
CONFIG_FS_PROCFS=y
CONFIG_FS_ROMFS=y
CONFIG_HAVE_CXX=y
CONFIG_HAVE_CXXINITIALIZE=y
CONFIG_IDLETHREAD_STACKSIZE=4096
CONFIG_INIT_ENTRYPOINT="nsh_main"
CONFIG_INTELHEX_BINARY=y
CONFIG_NSH_ARCHINIT=y
CONFIG_NSH_BUILTIN_APPS=y
CONFIG_NSH_FILEIOSIZE=512
CONFIG_NSH_READLINE=y
CONFIG_PERCPU_SECTION=y
CONFIG_PREALLOC_TIMERS=4
CONFIG_RAM_SIZE=15728640
CONFIG_RAM_START=0x40100000
CONFIG_RAW_BINARY=y
CONFIG_READLINE_CMD_HISTORY=y
CONFIG_RR_INTERVAL=200
CONFIG_SCHED_HAVE_PARENT=y
CONFIG_SCHED_HPWORK=y
CONFIG_SCHED_HPWORKPRIORITY=192
CONFIG_SMP=y
CONFIG_START_DAY=15
CONFIG_START_MONTH=2
CONFIG_START_YEAR=2025
CONFIG_SYMTAB_ORDEREDBYNAME=y
CONFIG_SYSTEM_NSH=y
CONFIG_SYSTEM_SYSTEM=y
CONFIG_TESTING_GETPRIME=y
CONFIG_TESTING_OSTEST=y
CONFIG_UART1_BASE=0x9000000
CONFIG_UART1_IRQ=33
CONFIG_UART1_PL011=y
CONFIG_UART1_SERIAL_CONSOLE=y
CONFIG_UART_PL011=y
CONFIG_USEC_PER_TICK=1000

husong2 avatar Dec 03 '25 08:12 husong2

@anchao do you have method to fix this issue? or let @husong2 revert your patch first.

Have you guys run this demo on the community code? I tested it locally and it worked fine.

nsh> hello
a_thread_func entry 
a_thread_func entry 2222
Test FAILED: Did not detach the thread, main still waiting for it to end execution.
Test PASSED
Test PASSED 2222 

Furthermore, the back reference design of the tcb group is flawless because all threads maintain a linked list reference count for tg_members, and the group's lifecycle is also maintained by this count. I suspect your issue only manifests in internal branches, right? Please check if you have changed the group logic.

The test case contains main thread and a detached thread, here is the sequence which trigger used after free:

  1. main thread enter exit process
  2. main thread remove self from task group
  3. main thread cancel test thread
  4. test thread remove self from task group
  5. task group is freed affer step 4 since all threads in the group exit
  6. main thread run again and crash immediately since it's tcb(group) is freed at step 4

This problem isn't related to SMP directly.

xiaoxiang781216 avatar Dec 03 '25 09:12 xiaoxiang781216

The test case contains main thread and a detached thread, here is the sequence which trigger used after free:

  1. main thread enter exit process
  2. main thread remove self from task group
  3. main thread cancel test thread
  4. test thread remove self from task group
  5. task group is freed affer step 4 since all threads in the group exit
  6. main thread run again and crash immediately since it's tcb(group) is freed at step 4

This problem isn't related to SMP directly.

enable CONFIG_CANCELLATION_POINTS and works fine again:

Image

@husong2

I couldn't find this configuration in the community code: /nuttx/boards/arm/qemu/qemu-armv8r-aarch32/configs/smp/defconfig

I reiterate, please reproduce the issue using the community code, not Xiaomi's internal branches.

anchao avatar Dec 03 '25 12:12 anchao

The test case contains main thread and a detached thread, here is the sequence which trigger used after free:

  1. main thread enter exit process
  2. main thread remove self from task group
  3. main thread cancel test thread
  4. test thread remove self from task group
  5. task group is freed affer step 4 since all threads in the group exit
  6. main thread run again and crash immediately since it's tcb(group) is freed at step 4

This problem isn't related to SMP directly.

This process won't be triggered because the group is bound to the main thread, and its lifecycle is controlled by tg_members. You need to further examine the implementation details of nxsched_release_tcb() and group_leave(). The group is not immediately released when the main process exits:

Image

anchao avatar Dec 03 '25 12:12 anchao

@anchao hi, here are two patches that can reproduce the problem mentioned above. https://github.com/apache/nuttx/compare/master...wangzhi16:nuttx:master https://github.com/apache/nuttx-apps/compare/master...wangzhi16:nuttx-apps:dev

Since this is an intermittent issue, blocking during the free process will free up the CPU. Therefore, we use usleep to create a scenario that is guaranteed to occur.

Image

thread_parent thread_child detach() group_leave() nxsig_cleanup() free()------------>block group_leave() check no member in group, release thread_parent. exit() release_tcb()------->double free!!!

wangzhi16 avatar Dec 12 '25 08:12 wangzhi16

thread_parent ---------------------------------thread_child detach() group_leave() nxsig_cleanup() free()---->block! ---------------------------------------------------group_leave() ---------------------------------------------------check no member in group, release thread_parent. ---------------------------------------------------exit() release_tcb()--->double free!!!

wangzhi16 avatar Dec 12 '25 08:12 wangzhi16

@anchao Please see this reproduce testcase. If you don't have any questions about the issue, we will revert the following PR: https://github.com/apache/nuttx/pull/11832

GUIDINGLI avatar Dec 16 '25 13:12 GUIDINGLI

@anchao Please see this reproduce testcase. If you don't have any questions about the issue, we will revert the following PR: #11832

@GUIDINGLI Hi again, work fine after apply :

https://github.com/apache/nuttx/compare/master...wangzhi16:nuttx:master https://github.com/apache/nuttx-apps/compare/master...wangzhi16:nuttx-apps:dev

archer@archerc:~/code/nuttx/n4/nuttx$ ./nuttx 
NuttShell (NSH) NuttX-10.4.0
nsh> hello
Test PASSED
nsh>

could we reproduce this issue on upstream?

patch diff:

archer@archerc:~/code/nuttx/n4/apps$ git diff .
diff --git a/examples/hello/hello_main.c b/examples/hello/hello_main.c
index fd194a623..1f368861e 100644
--- a/examples/hello/hello_main.c
+++ b/examples/hello/hello_main.c
@@ -26,6 +26,36 @@
 #include <nuttx/config.h>
 #include <stdio.h>
+#include <sys/wait.h>
+
+#define TIMEOUT 5              /* Timeout value of 5 seconds. */
+#define INTHREAD 0             /* Control going to or is already for Thread */
+#define INMAIN 1               /* Control going to or is already for Main */
+
+#define PTS_PASS 0
+#define PTS_FAIL 1
+#define PTS_UNRESOLVED 2
+#define PTS_UNSUPPORTED 4
+#define PTS_UNTESTED 5
+
+static int sem1;                       /* Manual semaphore */
+
+static void *a_thread_func(void *arg)
+{
+
+       /* Indicate to main() that the thread was created. */
+       sem1 = INTHREAD;
+
+       /* Wait for main to detach change the attribute object and try and detach this thread.
+        * Wait for a timeout value of 10 seconds before timing out if the thread was not able
+        * to be detached. */
+       sleep(TIMEOUT);
+
+       printf
+           ("Test FAILED: Did not detach the thread, main still waiting for it to end execution.\n");
+       pthread_exit((void *)PTS_FAIL);
+       return NULL;
+}
 /****************************************************************************
  * Public Functions
@@ -37,6 +67,44 @@
 int main(int argc, FAR char *argv[])
 {
-  printf("Hello, World!!\n");
-  return 0;
+       pthread_t new_th;
+       pthread_attr_t new_attr;
+       int ret_val;
+
+       /* Initializing */
+       sem1 = INMAIN;
+       if (pthread_attr_init(&new_attr) != 0) {
+               perror("Cannot initialize attribute object\n");
+               return PTS_UNRESOLVED;
+       }
+
+       /* Create a new thread passing it the new attribute object */
+       if (pthread_create(&new_th, &new_attr, a_thread_func, NULL) != 0) {
+               perror("Error creating thread\n");
+               return PTS_UNRESOLVED;
+       }
+
+       /* Wait for thread to indicate that the start routine for the thread has started. */
+       while (sem1 == INMAIN)
+               sleep(1);
+
+       /* If pthread_detach fails, that means that the test fails as well. */
+       ret_val = pthread_detach(new_th);
+
+       if (ret_val != 0) {
+               /* Thread is already detached. */
+               if (ret_val == EINVAL) {
+                       printf("Test FAILED\n");
+                       return PTS_FAIL;
+               }
+               /* pthread_detach() failed for another reason. */
+               else {
+                       printf("Error in pthread_detach(), error: %d\n",
+                              ret_val);
+                       return PTS_UNRESOLVED;
+               }
+       }
+
+       printf("Test PASSED\n");
+       return PTS_PASS;
 }
archer@archerc:~/code/nuttx/n4/nuttx$ git diff .
diff --git a/sched/signal/sig_cleanup.c b/sched/signal/sig_cleanup.c
index 9bb8d9a733..3eef7bb94c 100644
--- a/sched/signal/sig_cleanup.c
+++ b/sched/signal/sig_cleanup.c
@@ -61,6 +61,10 @@ void nxsig_cleanup(FAR struct tcb_s *stcb)
       nxsig_release_pendingsigaction(sigq);
     }
+  /* Using sleep to simulate the blocking that free might encounter. */
+
+  usleep(1);
+
   /* Misc. signal-related clean-up */
   sigfillset(&stcb->sigprocmask);

anchao avatar Dec 16 '25 15:12 anchao

@anchao hi, I reproduce this issue on upstream. I guess you might not have CONFIG_SCHED_HAVE_PARENT or CONFIG_CANCELLATION_POINTS enabled.

Configuration that needs to be opened:

CONFIG_SCHED_HAVE_PARENT=y
CONFIG_CANCELLATION_POINTS=y

test on sim: build: tools/configure.sh sim:nsh; make -j16 result: Image

test on qemu-armv7a: build: tools/configure.sh qemu-armv7a:nsh; make -j16 result: Image

The crash mentioned above was caused by the execution flow described below.

thread_parent ------------------------------------thread_child
detach()
group_leave()
nxsig_cleanup()
free()---->block!
---------------------------------------------------group_leave()
---------------------------------------------------check no member in group, release thread_parent.
---------------------------------------------------exit()
release_tcb()--->double free!!!

please check again when you have time, thanks! @anchao

wangzhi16 avatar Dec 17 '25 01:12 wangzhi16

@wangzhi16 Thanks. I can reproduce this issue, and I will fix it today.

anchao avatar Dec 18 '25 14:12 anchao

@wangzhi16 @GUIDINGLI @husong2 @xiaoxiang781216

I have a fix based on PR #17545 that I've tested locally and can resolve your current case and simplify group lifecycle management. Please check this change:

https://github.com/apache/nuttx/pull/17545

https://github.com/anchao/nuttx/commit/68ce1b83280a721fc275ac94a299007d01aa6bc2

here is test log:

$ ./nuttx 

NuttShell (NSH) NuttX-10.4.0
nsh> 
nsh> 
nsh> hello
Test PASSED
nsh> hello
Test PASSED
nsh> 
nsh> 
nsh> 
nsh> 
nsh> free
      total       used       free    maxused    maxfree  nused  nfree name
   67108864    1787624   65321240    1923912   65321096     66      2 Umem
nsh> ostest
stdio_test: write fd=1
stdio_test: Standard I/O Check: printf
stdio_test: write fd=2
ostest_main: putenv(Variable1=BadValue3)
ostest_main: setenv(Variable1, GoodValue1, TRUE)
ostest_main: setenv(Variable2, BadValue1, FALSE)
ostest_main: setenv(Variable2, GoodValue2, TRUE)
ostest_main: setenv(Variable3, GoodValue3, FALSE)
ostest_main: setenv(Variable3, BadValue2, FALSE)
show_variable: Variable=Variable1 has value=GoodValue1
show_variable: Variable=Variable2 has value=GoodValue2
show_variable: Variable=Variable3 has value=GoodValue3
ostest_main: Started user_main at PID=9

user_main: Begin argument test
user_main: Started with argc=5
user_main: argv[0]="ostest"
user_main: argv[1]="Arg1"
user_main: argv[2]="Arg2"
user_main: argv[3]="Arg3"
user_main: argv[4]="Arg4"

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         1        1
mxordblk  3e289b0  3e289b0
uordblks   1d7650   1d7650
fordblks  3e289b0  3e289b0

user_main: getopt() test
getopt():  Simple test
getopt():  Invalid argument
getopt():  Missing optional argument
getopt_long():  Simple test
getopt_long():  No short options
getopt_long():  Argument for --option=argument
getopt_long():  Invalid long option
getopt_long():  Mixed long and short options
getopt_long():  Invalid short option
getopt_long():  Missing optional arguments
getopt_long_only():  Mixed long and short options
getopt_long_only():  Single hyphen long options

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         1        1
mxordblk  3e289b0  3e289b0
uordblks   1d7650   1d7650
fordblks  3e289b0  3e289b0

user_main: libc tests

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         1        1
mxordblk  3e289b0  3e289b0
uordblks   1d7650   1d7650
fordblks  3e289b0  3e289b0
show_variable: Variable=Variable1 has value=GoodValue1
show_variable: Variable=Variable2 has value=GoodValue2
show_variable: Variable=Variable3 has value=GoodValue3
show_variable: Variable=Variable1 has no value
show_variable: Variable=Variable2 has value=GoodValue2
show_variable: Variable=Variable3 has value=GoodValue3

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         1        2
mxordblk  3e289b0  3e289b0
uordblks   1d7650   1d7630
fordblks  3e289b0  3e289d0
show_variable: Variable=Variable1 has no value
show_variable: Variable=Variable2 has no value
show_variable: Variable=Variable3 has no value

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         2        2
mxordblk  3e289b0  3e289b0
uordblks   1d7630   1d7558
fordblks  3e289d0  3e28aa8

user_main: setvbuf test
setvbuf_test: Test NO buffering
setvbuf_test: Using NO buffering
setvbuf_test: Test default FULL buffering
setvbuf_test: Using default FULL buffering
setvbuf_test: Test FULL buffering, buffer size 64
setvbuf_test: Using FULL buffering, buffer size 64
setvbuf_test: Test FULL buffering, pre-allocated buffer
setvbuf_test: Using FULL buffering, pre-allocated buffer
setvbuf_test: Test LINE buffering, buffer size 64
setvbuf_test: Using LINE buffering, buffer size 64
setvbuf_test: Test FULL buffering, pre-allocated buffer
setvbuf_test: Using FULL buffering, pre-allocated buffer

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         2        2
mxordblk  3e289b0  3e289b0
uordblks   1d7558   1d7558
fordblks  3e28aa8  3e28aa8

user_main: /dev/null test
dev_null: Read 0 bytes from /dev/null
dev_null: Wrote 1024 bytes to /dev/null

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         2        2
mxordblk  3e289b0  3e289b0
uordblks   1d7558   1d7558
fordblks  3e28aa8  3e28aa8

user_main: task_restart test

Test task_restart()
restart_main: setenv(VarName, VarValue, TRUE)
restart_main: Started restart_main at PID=10
restart_main: Started with argc=4
restart_main: argv[0]="ostest"
restart_main: argv[1]="This is argument 1"
restart_main: argv[2]="Argument 2 here"
restart_main: argv[3]="Lastly, the 3rd argument"
restart_main: Variable=VarName has value=VarValue
restart_main: I am still here
restart_main: I am still here
restart_main: Started restart_main at PID=10
restart_main: Started with argc=4
restart_main: argv[0]="ostest"
restart_main: argv[1]="This is argument 1"
restart_main: argv[2]="Argument 2 here"
restart_main: argv[3]="Lastly, the 3rd argument"
restart_main: Variable=VarName has value=VarValue
restart_main: Started with argc=4
restart_main: argv[0]="ostest"
restart_main: argv[1]="This is argument 1"
restart_main: argv[2]="Argument 2 here"
restart_main: argv[3]="Lastly, the 3rd argument"
restart_main: Variable=VarName has value=VarValue
restart_main: Exiting

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         2        3
mxordblk  3e289b0  3e163c0
uordblks   1d7558   1e95b8
fordblks  3e28aa8  3e16a48

user_main: waitpid test

Test waitpid()
waitpid_start_child: Started waitpid_main at PID=11
waitpid_start_child: Started waitpid_main at PID=12
waitpid_start_child: Started waitpid_main at PID=13
waitpid_test: Waiting for PID=11 with waitpid()
waitpid_main: PID 11 Started
waitpid_main: PID 12 Started
waitpid_main: PID 13 Started
waitpid_main: PID 11 exitting with result=14
waitpid_main: PID 12 exitting with result=14
waitpid_main: PID 13 exitting with result=14
waitpid_test: PID 11 waitpid succeeded with stat_loc=0e00
waitpid_last: Waiting for PID=13 with waitpid()
waitpid_last: PASS: PID 13 waitpid failed with ECHILD.  That may be
              acceptable because child status is disabled on this thread.

Test waitid(P_PID)
waitpid_start_child: Started waitpid_main at PID=14
waitpid_start_child: Started waitpid_main at PID=15
waitpid_start_child: Started waitpid_main at PID=20
waitpid_test: Waiting for PID=14 with waitid()
waitpid_main: PID 14 Started
waitpid_main: PID 15 Started
waitpid_main: PID 20 Started
waitpid_main: PID 14 exitting with result=14
waitpid_main: PID 15 exitting with result=14
waitpid_main: PID 20 exitting with result=14
waitpid_test: waitid PID 14 succeeded with si_status=14
waitpid_last: Waiting for PID=20 with waitpid()
waitpid_last: PASS: PID 20 waitpid failed with ECHILD.  That may be
              acceptable because child status is disabled on this thread.

Test waitid(P_ALL)
waitpid_start_child: Started waitpid_main at PID=21
waitpid_start_child: Started waitpid_main at PID=22
waitpid_start_child: Started waitpid_main at PID=23
waitpid_test: Waiting for any child with waitid()
waitpid_main: PID 21 Started
waitpid_main: PID 22 Started
waitpid_main: PID 23 Started
waitpid_main: PID 21 exitting with result=14
waitpid_main: PID 22 exitting with result=14
waitpid_main: PID 23 exitting with result=14
waitpid_test: PID 21 waitid succeeded with si_status=14
waitpid_last: Waiting for PID=23 with waitpid()
waitpid_last: PASS: PID 23 waitpid failed with ECHILD.  That may be
              acceptable because child status is disabled on this thread.

Test wait()
waitpid_start_child: Started waitpid_main at PID=26
waitpid_start_child: Started waitpid_main at PID=27
waitpid_start_child: Started waitpid_main at PID=28
waitpid_test: Waiting for any child with wait()
waitpid_main: PID 26 Started
waitpid_main: PID 27 Started
waitpid_main: PID 28 Started
waitpid_main: PID 26 exitting with result=14
waitpid_main: PID 27 exitting with result=14
waitpid_main: PID 28 exitting with result=14
waitpid_test: PID 26 wait succeeded with stat_loc=0e00
waitpid_last: Waiting for PID=28 with waitpid()
waitpid_last: PASS: PID 28 waitpid failed with ECHILD.  That may be
              acceptable because child status is disabled on this thread.

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         3        5
mxordblk  3e163c0  3df1768
uordblks   1e95b8   20d5c8
fordblks  3e16a48  3df2a38

user_main: mutex test
Initializing mutex
Starting thread 1
Starting thread 2
		Thread1	Thread2
	Loops	32	32
	Errors	0	0

Testing moved mutex
Starting moved mutex thread 1
Starting moved mutex thread 2
		Thread1	Thread2
	Moved Loops	32	32
	Moved Errors	0	0

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         5        2
mxordblk  3df1768  3de62f0
uordblks   20d5c8   219c70
fordblks  3df2a38  3de6390

user_main: timed mutex test
mutex_test: Initializing mutex
mutex_test: Starting thread
pthread:  Started
pthread:  Waiting for lock or timeout
mutex_test: Unlocking
pthread:  Got the lock
pthread:  Waiting for lock or timeout
pthread:  Got the timeout.  Terminating
mutex_test: PASSED

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         2        2
mxordblk  3de62f0  3e18000
uordblks   219c70   1e7f60
fordblks  3de6390  3e180a0

user_main: cancel test
cancel_test: Test 1a: Normal Cancellation
cancel_test: Starting thread
start_thread: Initializing mutex
start_thread: Initializing cond
start_thread: Starting thread
start_thread: Yielding
sem_waiter: Taking mutex
sem_waiter: Starting wait for condition
cancel_test: Canceling thread
cancel_test: Joining
cancel_test: waiter exited with result=0xffffffffffffffff
cancel_test: PASS thread terminated with PTHREAD_CANCELED
cancel_test: Test 2: Asynchronous Cancellation
cancel_test: Starting thread
restart_thread: Destroying cond
restart_thread: Destroying mutex
restart_thread: Re-starting thread
start_thread: Initializing mutex
start_thread: Initializing cond
start_thread: Starting thread
start_thread: Yielding
asynch_waiter: Setting non-cancelable
asynch_waiter: Setting synchronous cancellation type
cancel_test: Canceling thread
cancel_test: Joining
asynch_waiter: Restoring cancelable state
asynch_waiter: Setting cancelable
cancel_test: waiter exited with result=0xffffffffffffffff
cancel_test: PASS thread terminated with PTHREAD_CANCELED
cancel_test: Test 3: Cancellation of detached thread
cancel_test: Re-starting thread
restart_thread: Destroying cond
restart_thread: Destroying mutex
restart_thread: Re-starting thread
start_thread: Initializing mutex
start_thread: Initializing cond
start_thread: Starting thread
start_thread: Yielding
sem_waiter: Taking mutex
sem_waiter: Starting wait for condition
cancel_test: Canceling thread
cancel_test: Joining
cancel_test: PASS pthread_join failed with status=ESRCH
cancel_test: Test 5: Non-cancelable threads
cancel_test: Re-starting thread (non-cancelable)
restart_thread: Destroying cond
restart_thread: Destroying mutex
restart_thread: Re-starting thread
start_thread: Initializing mutex
start_thread: Initializing cond
start_thread: Starting thread
start_thread: Yielding
sem_waiter: Taking mutex
sem_waiter: Starting wait for condition
sem_waiter: Setting non-cancelable
cancel_test: Canceling thread
cancel_test: Joining
sem_waiter: Releasing mutex
sem_waiter: Setting cancelable
cancel_test: waiter exited with result=0xffffffffffffffff
cancel_test: PASS thread terminated with PTHREAD_CANCELED
cancel_test: Test 6: Cancel message queue wait
cancel_test: Starting thread (cancelable)
restart_thread: Destroying cond
restart_thread: Destroying mutex
restart_thread: Re-starting thread
start_thread: Initializing mutex
start_thread: Initializing cond
start_thread: Starting thread
start_thread: Yielding
mqueue_waiter: Waiting to receive a message...
cancel_test: Canceling thread
cancel_test: Joining
cancel_test: waiter exited with result=0xffffffffffffffff
cancel_test: PASS thread terminated with PTHREAD_CANCELED
cancel_test: Test 7: Cancel signal wait
cancel_test: Starting thread (cancelable)
restart_thread: Destroying cond
restart_thread: Destroying mutex
restart_thread: Re-starting thread
start_thread: Initializing mutex
start_thread: Initializing cond
start_thread: Starting thread
start_thread: Yielding
sig_waiter: Waiting to receive signal...
cancel_test: Canceling thread
cancel_test: Joining
cancel_test: waiter exited with result=0xffffffffffffffff
cancel_test: PASS thread terminated with PTHREAD_CANCELED

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         2        3
mxordblk  3e18000  3e043c0
uordblks   1e7f60   1fbbc8
fordblks  3e180a0  3e04438

user_main: robust test
robust_test: Initializing mutex
robust_test: Starting thread
robust_waiter: Taking mutex
robust_waiter: Exiting with mutex
robust_test: Take the lock again
robust_test: Make the mutex consistent again.
robust_test: Take the lock again
robust_test: Joining
robust_test: waiter exited with result=0
robust_test: Test complete with nerrors=0

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         3        3
mxordblk  3e043c0  3e16570
uordblks   1fbbc8   1e9a18
fordblks  3e04438  3e165e8

user_main: semaphore test
sem_test: Initializing semaphore to 0
sem_test: Starting waiter thread 1
sem_test: Set thread 1 priority to 191
waiter_func: Thread 1 Started
waiter_func: Thread 1 initial semaphore value = 0
waiter_func: Thread 1 waiting on semaphore
sem_test: Starting waiter thread 2
sem_test: Set thread 2 priority to 128
waiter_func: Thread 2 Started
waiter_func: Thread 2 initial semaphore value = -1
waiter_func: Thread 2 waiting on semaphore
sem_test: Starting poster thread 3
sem_test: Set thread 3 priority to 64
poster_func: Thread 3 started
poster_func: Thread 3 semaphore value = -2
poster_func: Thread 3 posting semaphore
waiter_func: Thread 1 awakened
waiter_func: Thread 1 new semaphore value = -1
waiter_func: Thread 1 done
poster_func: Thread 3 new semaphore value = -1
poster_func: Thread 3 semaphore value = -1
poster_func: Thread 3 posting semaphore
waiter_func: Thread 2 awakened
waiter_func: Thread 2 new semaphore value = 0
waiter_func: Thread 2 done
poster_func: Thread 3 new semaphore value = 0
poster_func: Thread 3 done

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         3        4
mxordblk  3e16570  3df5560
uordblks   1e9a18   209578
fordblks  3e165e8  3df6a88

user_main: timed semaphore test
semtimed_test: Initializing semaphore to 0
semtimed_test: Waiting for two second timeout
semtimed_test: PASS: first test returned timeout
BEFORE: (1212278453 sec, 390682501 nsec)
AFTER:  (1212278455 sec, 400147663 nsec)
semtimed_test: Starting poster thread
semtimed_test: Set thread 1 priority to 191
semtimed_test: Starting poster thread 3
semtimed_test: Set thread 3 priority to 64
semtimed_test: Waiting for two second timeout
poster_func: Waiting for 1 second
poster_func: Posting
semtimed_test: PASS: sem_timedwait succeeded
BEFORE: (1212278455 sec, 400631500 nsec)
AFTER:  (1212278456 sec, 410215789 nsec)

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         4        4
mxordblk  3df5560  3e16570
uordblks   209578   1e8218
fordblks  3df6a88  3e17de8

user_main: condition variable test
cond_test: Initializing mutex
cond_test: Initializing cond
cond_test: Starting waiter
cond_test: Set thread 1 priority to 128
waiter_thread: Started
cond_test: Starting signaler
cond_test: Set thread 2 priority to 64
thread_signaler: Started
thread_signaler: Terminating
cond_test: signaler terminated, now cancel the waiter
cond_test: 	Waiter	Signaler
cond_test: Loops	32	32
cond_test: Errors	0	0
cond_test:
cond_test: 0 times, waiter did not have to wait for data
cond_test: 0 times, data was already available when the signaler run
cond_test: 0 times, the waiter was in an unexpected state when the signaler ran

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         4        4
mxordblk  3e16570  3e05d68
uordblks   1e8218   1f8bc8
fordblks  3e17de8  3e07438

user_main: pthread_exit() test
pthread_exit_test: Started pthread_exit_main at PID=59
pthread_exit_main 59: Starting pthread_exit_thread
pthread_exit_main 59: Sleeping for 5 seconds
pthread_exit_thread 60: Sleeping for 10 second
pthread_exit_main 59: Calling pthread_exit()
pthread_exit_thread 60: Still running...

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         4        3
mxordblk  3e05d68  3e05bc0
uordblks   1f8bc8   1fa3c8
fordblks  3e07438  3e05c38

user_main: pthread_rwlock test
pthread_rwlock: Initializing rwlock
pthread_exit_thread 60: Exiting

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         3        3
mxordblk  3e05bc0  3e05bc0
uordblks   1fa3c8   1e8240
fordblks  3e05c38  3e17dc0

user_main: pthread_rwlock_cancel test
pthread_rwlock_cancel: Starting test

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         3        3
mxordblk  3e05bc0  3e05d68
uordblks   1e8240   1f8bf0
fordblks  3e17dc0  3e07410

user_main: timed wait test
thread_waiter: Initializing mutex
timedwait_test: Initializing cond
timedwait_test: Starting waiter
timedwait_test: Set thread 2 priority to 177
thread_waiter: Taking mutex
thread_waiter: Starting 5 second wait for condition
timedwait_test: Joining
thread_waiter: pthread_cond_timedwait timed out
thread_waiter: Releasing mutex
thread_waiter: Exit with status 0x12345678
timedwait_test: waiter exited with result=0x12345678

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         3        3
mxordblk  3e05d68  3e16570
uordblks   1f8bf0   1e8240
fordblks  3e07410  3e17dc0

user_main: message queue test
mqueue_test: Starting receiver
mqueue_test: Set receiver priority to 128
receiver_thread: Starting
mqueue_test: Starting sender
mqueue_test: Set sender thread priority to 64
mqueue_test: Waiting for sender to complete
sender_thread: Starting
receiver_thread: mq_receive succeeded on msg 0
sender_thread: mq_send succeeded on msg 0
receiver_thread: mq_receive succeeded on msg 1
sender_thread: mq_send succeeded on msg 1
receiver_thread: mq_receive succeeded on msg 2
sender_thread: mq_send succeeded on msg 2
receiver_thread: mq_receive succeeded on msg 3
sender_thread: mq_send succeeded on msg 3
receiver_thread: mq_receive succeeded on msg 4
sender_thread: mq_send succeeded on msg 4
receiver_thread: mq_receive succeeded on msg 5
sender_thread: mq_send succeeded on msg 5
receiver_thread: mq_receive succeeded on msg 6
sender_thread: mq_send succeeded on msg 6
receiver_thread: mq_receive succeeded on msg 7
sender_thread: mq_send succeeded on msg 7
receiver_thread: mq_receive succeeded on msg 8
sender_thread: mq_send succeeded on msg 8
receiver_thread: mq_receive succeeded on msg 9
sender_thread: mq_send succeeded on msg 9
sender_thread: returning nerrors=0
mqueue_test: Killing receiver
receiver_thread: mq_receive interrupted!
receiver_thread: returning nerrors=0
mqueue_test: Canceling receiver
mqueue_test: receiver has already terminated

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         3        3
mxordblk  3e16570  3e04260
uordblks   1e8240   1fbbf0
fordblks  3e17dc0  3e04410

user_main: timed message queue test
timedmqueue_test: Starting sender
timedmqueue_test: Waiting for sender to complete
sender_thread: Starting
sender_thread: mq_timedsend succeeded on msg 0
sender_thread: mq_timedsend succeeded on msg 1
sender_thread: mq_timedsend succeeded on msg 2
sender_thread: mq_timedsend succeeded on msg 3
sender_thread: mq_timedsend succeeded on msg 4
sender_thread: mq_timedsend succeeded on msg 5
sender_thread: mq_timedsend succeeded on msg 6
sender_thread: mq_timedsend succeeded on msg 7
sender_thread: mq_timedsend succeeded on msg 8
sender_thread: mq_timedsend 9 timed out as expected
sender_thread: returning nerrors=0
timedmqueue_test: Starting receiver
timedmqueue_test: Waiting for receiver to complete
receiver_thread: Starting
receiver_thread: mq_timedreceive succeed on msg 0
receiver_thread: mq_timedreceive succeed on msg 1
receiver_thread: mq_timedreceive succeed on msg 2
receiver_thread: mq_timedreceive succeed on msg 3
receiver_thread: mq_timedreceive succeed on msg 4
receiver_thread: mq_timedreceive succeed on msg 5
receiver_thread: mq_timedreceive succeed on msg 6
receiver_thread: mq_timedreceive succeed on msg 7
receiver_thread: mq_timedreceive succeed on msg 8
receiver_thread: Receive 9 timed out as expected
receiver_thread: returning nerrors=0
timedmqueue_test: Test complete

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         3        3
mxordblk  3e04260  3e04220
uordblks   1fbbf0   1fbbf0
fordblks  3e04410  3e04410

user_main: sigprocmask test
sigprocmask_test: SUCCESS

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         3        3
mxordblk  3e04220  3e04220
uordblks   1fbbf0   1fbbf0
fordblks  3e04410  3e04410

user_main: signal handler test
sighand_test: Initializing semaphore to 0
sighand_test: Unmasking SIGCHLD
sighand_test: Registering SIGCHLD handler
sighand_test: Starting waiter task
sighand_test: Started waiter_main pid=78
waiter_main: Waiter started
waiter_main: Unmasking signal 32
waiter_main: Registering signal handler
waiter_main: oact.sigaction=0 oact.sa_flags=0 oact.sa_mask=0000000000000000
waiter_main: Waiting on semaphore
sighand_test: Signaling pid=78 with signo=32 sigvalue=42
waiter_main: sem_wait() successfully interrupted by signal
waiter_main: done
sighand_test: done

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         3        2
mxordblk  3e04220  3e16570
uordblks   1fbbf0   1e9a60
fordblks  3e04410  3e165a0

user_main: nested signal handler test
signest_test: Starting signal waiter task at priority 101
waiter_main: Waiter started
waiter_main: Setting signal mask
waiter_main: Registering signal handler
waiter_main: Waiting on semaphore
signest_test: Started waiter_main pid=79
signest_test: Starting interfering task at priority 102
interfere_main: Waiting on semaphore
signest_test: Started interfere_main pid=84
signest_test: Simple case:
  Total signalled 1240  Odd=620 Even=620
  Total handled   1240  Odd=620 Even=620
  Total nested    0    Odd=0   Even=0  
signest_test: With task locking
  Total signalled 2480  Odd=1240 Even=1240
  Total handled   2480  Odd=1240 Even=1240
  Total nested    0    Odd=0   Even=0  
signest_test: With intefering thread
  Total signalled 3720  Odd=1860 Even=1860
  Total handled   3720  Odd=1860 Even=1860
  Total nested    0    Odd=0   Even=0  
signest_test: done

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         2        4
mxordblk  3e16570  3e036b8
uordblks   1e9a60   1fbcd0
fordblks  3e165a0  3e04330

user_main: wdog test
wdog_test start...
wdtest_once 0 ns
wdtest_once 0 ns
wdtest_once 0 ns
wdtest_once 0 ns
wdtest_once 1 ns
wdtest_once 1 ns
wdtest_once 1 ns
wdtest_once 1 ns
wdtest_once 10 ns
wdtest_once 10 ns
wdtest_once 10 ns
wdtest_once 10 ns
wdtest_once 100 ns
wdtest_once 100 ns
wdtest_once 100 ns
wdtest_once 100 ns
wdtest_once 1000 ns
wdtest_once 1000 ns
wdtest_once 1000 ns
wdtest_once 1000 ns
wdtest_once 10000 ns
wdtest_once 10000 ns
wdtest_once 10000 ns
wdtest_once 10000 ns
wdtest_once 100000 ns
wdtest_once 100000 ns
wdtest_once 100000 ns
wdtest_once 100000 ns
wdtest_once 1000000 ns
wdtest_once 1000000 ns
wdtest_once 1000000 ns
wdtest_once 1000000 ns
wd_start with maximum delay, cancel OK, rest 1073741821
wdtest_recursive 1000000ns
wd_start with maximum delay, cancel OK, rest 1073741821
wdtest_recursive 1000000ns
wd_start with maximum delay, cancel OK, rest 1073741821
wdtest_recursive 1000000ns
wd_start with maximum delay, cancel OK, rest 1073741821
wdtest_recursive 1000000ns
recursive wdog triggered 6 times, elapsed tick 12
wdtest_recursive 10000000ns
recursive wdog triggered 6 times, elapsed tick 12
wdtest_recursive 10000000ns
recursive wdog triggered 6 times, elapsed tick 12
wdtest_recursive 10000000ns
recursive wdog triggered 6 times, elapsed tick 12
wdtest_recursive 10000000ns
recursive wdog triggered 6 times, elapsed tick 12
recursive wdog triggered 6 times, elapsed tick 12
recursive wdog triggered 6 times, elapsed tick 12
recursive wdog triggered 6 times, elapsed tick 12
wdog_test end...

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         4        6
mxordblk  3e036b8  3de26a8
uordblks   1fbcd0   209680
fordblks  3e04330  3df6980

user_main: POSIX timer test
timer_test: Initializing semaphore to 0
timer_test: Unmasking signal 32
timer_test: Registering signal handler
timer_test: oact.sigaction=0 oact.sa_flags=0 oact.sa_mask=0000000000000000
timer_test: Creating timer
timer_test: Starting timer
timer_test: Waiting on semaphore
timer_expiration: Received signal 32
timer_expiration: sival_int=42
timer_expiration: si_code=2 (SI_TIMER)
timer_expiration: ucontext=0
timer_test: sem_wait() successfully interrupted by signal
timer_test: g_nsigreceived=1
timer_test: Waiting on semaphore
timer_expiration: Received signal 32
timer_expiration: sival_int=42
timer_expiration: si_code=2 (SI_TIMER)
timer_expiration: ucontext=0
timer_test: sem_wait() successfully interrupted by signal
timer_test: g_nsigreceived=2
timer_test: Waiting on semaphore
timer_expiration: Received signal 32
timer_expiration: sival_int=42
timer_expiration: si_code=2 (SI_TIMER)
timer_expiration: ucontext=0
timer_test: sem_wait() successfully interrupted by signal
timer_test: g_nsigreceived=3
timer_test: Waiting on semaphore
timer_expiration: Received signal 32
timer_expiration: sival_int=42
timer_expiration: si_code=2 (SI_TIMER)
timer_expiration: ucontext=0
timer_test: sem_wait() successfully interrupted by signal
timer_test: g_nsigreceived=4
timer_test: Waiting on semaphore
timer_expiration: Received signal 32
timer_expiration: sival_int=42
timer_expiration: si_code=2 (SI_TIMER)
timer_expiration: ucontext=0
timer_test: sem_wait() successfully interrupted by signal
timer_test: g_nsigreceived=5
timer_test: Deleting timer
timer_test: done

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         6        6
mxordblk  3de26a8  3de26a8
uordblks   209680   209680
fordblks  3df6980  3df6980

user_main: barrier test
barrier_test: Initializing barrier
barrier_test: Thread 0 created
barrier_test: Thread 1 created
barrier_test: Thread 2 created
barrier_test: Thread 3 created
barrier_test: Thread 4 created
barrier_test: Thread 5 created
barrier_test: Thread 6 created
barrier_test: Thread 7 created
barrier_func: Thread 0 started
barrier_func: Thread 1 started
barrier_func: Thread 2 started
barrier_func: Thread 3 started
barrier_func: Thread 4 started
barrier_func: Thread 5 started
barrier_func: Thread 6 started
barrier_func: Thread 7 started
barrier_func: Thread 0 calling pthread_barrier_wait()
barrier_func: Thread 1 calling pthread_barrier_wait()
barrier_func: Thread 2 calling pthread_barrier_wait()
barrier_func: Thread 3 calling pthread_barrier_wait()
barrier_func: Thread 4 calling pthread_barrier_wait()
barrier_func: Thread 5 calling pthread_barrier_wait()
barrier_func: Thread 6 calling pthread_barrier_wait()
barrier_func: Thread 7 calling pthread_barrier_wait()
barrier_func: Thread 7, back with status=PTHREAD_BARRIER_SERIAL_THREAD (I AM SPECIAL)
barrier_func: Thread 0, back with status=0 (I am not special)
barrier_func: Thread 1, back with status=0 (I am not special)
barrier_func: Thread 2, back with status=0 (I am not special)
barrier_func: Thread 3, back with status=0 (I am not special)
barrier_func: Thread 4, back with status=0 (I am not special)
barrier_func: Thread 5, back with status=0 (I am not special)
barrier_func: Thread 6, back with status=0 (I am not special)
barrier_func: Thread 7 done
barrier_func: Thread 0 done
barrier_func: Thread 1 done
barrier_func: Thread 2 done
barrier_func: Thread 3 done
barrier_func: Thread 4 done
barrier_func: Thread 5 done
barrier_func: Thread 6 done
barrier_test: Thread 0 completed with result=0
barrier_test: Thread 1 completed with result=0
barrier_test: Thread 2 completed with result=0
barrier_test: Thread 3 completed with result=0
barrier_test: Thread 4 completed with result=0
barrier_test: Thread 5 completed with result=0
barrier_test: Thread 6 completed with result=0
barrier_test: Thread 7 completed with result=0

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         6        5
mxordblk  3de26a8  3da0688
uordblks   209680   25c6f0
fordblks  3df6980  3da3910

user_main: setjmp test
setjmp_test: Initializing jmp_buf
setjmp_test: Try jump
setjmp_test: About to jump, longjmp with ret val: 123
setjmp_test: Jump succeed
setjmp_test: Try jump
setjmp_test: About to jump, longjmp with ret val: 0
setjmp_test: Jump succeed

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         5        5
mxordblk  3da0688  3da0688
uordblks   25c6f0   25c6f0
fordblks  3da3910  3da3910

user_main: scheduler lock test
sched_lock: Starting lowpri_thread at 97
sched_lock: Set lowpri_thread priority to 97
sched_lock: Starting highpri_thread at 98
sched_lock: Set highpri_thread priority to 98
sched_lock: Waiting...
sched_lock: PASSED No pre-emption occurred while scheduler was locked.
sched_lock: Starting lowpri_thread at 97
sched_lock: Set lowpri_thread priority to 97
sched_lock: Starting highpri_thread at 98
sched_lock: Set highpri_thread priority to 98
sched_lock: Waiting...
sched_lock: PASSED No pre-emption occurred while scheduler was locked.
sched_lock: Finished

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         5        5
mxordblk  3da0688  3e036b8
uordblks   25c6f0   1f8cd0
fordblks  3da3910  3e07330

user_main: nxevent test

End of test memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         5        6
mxordblk  3e036b8  3df2eb0
uordblks   1f8cd0   1f8cd0
fordblks  3e07330  3e07330

Final memory usage:
VARIABLE  BEFORE   AFTER
======== ======== ========
arena     4000000  4000000
ordblks         1        6
mxordblk  3e289b0  3df2eb0
uordblks   1d7650   1f8cd0
fordblks  3e289b0  3e07330
user_main: Exiting
ostest_main: Exiting with status 0
stdio_test: Standard I/O Check: fprintf to stderr
nsh> free
      total       used       free    maxused    maxfree  nused  nfree name
   67108864    1788280   65320584    2476672   65103216     70      3 Umem
nsh> poweroff

archer@archer:~/code/nuttx/n8/nuttx$ git diff 
diff --git a/boards/sim/sim/sim/configs/nsh/defconfig b/boards/sim/sim/sim/configs/nsh/defconfig
index 8517209444..77350c394d 100644
--- a/boards/sim/sim/sim/configs/nsh/defconfig
+++ b/boards/sim/sim/sim/configs/nsh/defconfig
@@ -16,6 +16,7 @@ CONFIG_BOARDCTL_POWEROFF=y
 CONFIG_BOARD_LOOPSPERMSEC=0
 CONFIG_BOOT_RUNFROMEXTSRAM=y
 CONFIG_BUILTIN=y
+CONFIG_CANCELLATION_POINTS=y
 CONFIG_COVERAGE_ALL=y
 CONFIG_COVERAGE_TOOLCHAIN=y
 CONFIG_DEBUG_ASSERTIONS=y

anchao avatar Dec 18 '25 17:12 anchao

@anchao Why close this issue before your patch merged ?

GUIDINGLI avatar Dec 22 '25 02:12 GUIDINGLI

@anchao Why close this issue before your patch merged ?

Because the revert commit was merged, GitHub assumes the current issue is now closed and resolved: https://github.com/apache/nuttx/pull/17564

anchao avatar Dec 22 '25 03:12 anchao