The notification tutorial solution seems to have a race condition

Every once in a while we're getting a failure in the CI simulation run. Since it's simulation, we can exclude hardware glitches and since it is working most of the time it's likely that there is a race condition somewhere that gets triggered rarely.

Example log output:

2023-03-27T10:30:10.0851519Z simulate: qemu-system-x86_64  -cpu Nehalem,-vme,+pdpe1gb,-xsave,-xsaveopt,-xsavec,-fsgsbase,-invpcid,+syscall,+lm,enforce -nographic -serial mon:stdio -m size=512M  -kernel images/kernel-x86_64-pc99 -initrd images/capdl-loader-image-x86_64-pc99 �c�[?7l�[2J�[0mSeaBIOS (version 1.14.0-2)
2023-03-27T10:30:10.0852108Z 
2023-03-27T10:30:10.0852114Z 
2023-03-27T10:30:10.0852120Z 
2023-03-27T10:30:10.0852416Z iPXE (http://ipxe.org) 00:03.0 CA00 PCI2.10 PnP PMM+1FF8F360+1FECF360 CA00
2023-03-27T10:30:10.0852666Z 
2023-03-27T10:30:10.0852886Z Press Ctrl-B to configure iPXE (PCI 00:03.0)...
2023-03-27T10:30:10.0853085Z 
2023-03-27T10:30:10.0853095Z 
2023-03-27T10:30:10.0853101Z 
2023-03-27T10:30:10.0853106Z 
2023-03-27T10:30:10.0853268Z Booting from ROM..Boot config: debug_port = 0x3f8
2023-03-27T10:30:10.0853423Z 
2023-03-27T10:30:10.0853560Z Boot config: disable_iommu = false
2023-03-27T10:30:10.0853766Z 
2023-03-27T10:30:10.0853892Z Detected 1 boot module(s):
2023-03-27T10:30:10.0854079Z 
2023-03-27T10:30:10.0854406Z   module #0: start=0xa14000 end=0xbac6d0 size=0x1986d0 name='images/capdl-loader-image-x86_64-pc99'
2023-03-27T10:30:10.0854661Z 
2023-03-27T10:30:10.0854759Z Parsing GRUB physical memory map
2023-03-27T10:30:10.0854948Z 
2023-03-27T10:30:10.0855106Z 	Physical Memory Region from 0 size 9fc00 type 1
2023-03-27T10:30:10.0855301Z 
2023-03-27T10:30:10.0855490Z 	Physical Memory Region from 9fc00 size 400 type 2
2023-03-27T10:30:10.0855694Z 
2023-03-27T10:30:10.0855871Z 	Physical Memory Region from f0000 size 10000 type 2
2023-03-27T10:30:10.0856066Z 
2023-03-27T10:30:10.0856193Z 	Physical Memory Region from 100000 size 1fee0000 type 1
2023-03-27T10:30:10.0856390Z 
2023-03-27T10:30:10.0856614Z Adding physical memory region 0x100000-0x1ffe0000
2023-03-27T10:30:10.0856814Z 
2023-03-27T10:30:10.0856977Z 	Physical Memory Region from 1ffe0000 size 20000 type 2
2023-03-27T10:30:10.0857200Z 
2023-03-27T10:30:10.0857379Z 	Physical Memory Region from fffc0000 size 40000 type 2
2023-03-27T10:30:10.0857527Z 
2023-03-27T10:30:10.0857672Z Multiboot gave us no video information
2023-03-27T10:30:10.0857862Z 
2023-03-27T10:30:10.0857990Z ACPI: RSDP paddr=0xf5b20
2023-03-27T10:30:10.0858159Z 
2023-03-27T10:30:10.0858284Z ACPI: RSDP vaddr=0xf5b20
2023-03-27T10:30:10.0858452Z 
2023-03-27T10:30:10.0858537Z ACPI: RSDT paddr=0x1ffe1550
2023-03-27T10:30:10.0858735Z 
2023-03-27T10:30:10.0858875Z ACPI: RSDT vaddr=0x1ffe1550
2023-03-27T10:30:10.0859044Z 
2023-03-27T10:30:10.0859236Z Kernel loaded to: start=0x100000 end=0xa13000 size=0x913000 entry=0x1002ea
2023-03-27T10:30:10.0859449Z 
2023-03-27T10:30:10.0859569Z ACPI: RSDT paddr=0x1ffe1550
2023-03-27T10:30:10.0859827Z 
2023-03-27T10:30:10.0859906Z ACPI: RSDT vaddr=0x1ffe1550
2023-03-27T10:30:10.0860082Z 
2023-03-27T10:30:10.0860234Z ACPI: FADT paddr=0x1ffe1404
2023-03-27T10:30:10.0860401Z 
2023-03-27T10:30:10.0860519Z ACPI: FADT vaddr=0x1ffe1404
2023-03-27T10:30:10.0860680Z 
2023-03-27T10:30:10.0860800Z ACPI: FADT flags=0x80a5
2023-03-27T10:30:10.0860921Z 
2023-03-27T10:30:10.0861043Z ACPI: MADT paddr=0x1ffe1478
2023-03-27T10:30:10.0861200Z 
2023-03-27T10:30:10.0861334Z ACPI: MADT vaddr=0x1ffe1478
2023-03-27T10:30:10.0861526Z 
2023-03-27T10:30:10.0861657Z ACPI: MADT apic_addr=0xfee00000
2023-03-27T10:30:10.0861837Z 
2023-03-27T10:30:10.0861911Z ACPI: MADT flags=0x1
2023-03-27T10:30:10.0862070Z 
2023-03-27T10:30:10.0862193Z ACPI: MADT_APIC apic_id=0x0
2023-03-27T10:30:10.0862359Z 
2023-03-27T10:30:10.0862548Z ACPI: MADT_IOAPIC ioapic_id=0 ioapic_addr=0xfec00000 gsib=0
2023-03-27T10:30:10.0862755Z 
2023-03-27T10:30:10.0862929Z ACPI: MADT_ISO bus=0 source=0 gsi=2 flags=0x0
2023-03-27T10:30:10.0863073Z 
2023-03-27T10:30:10.0863313Z ACPI: MADT_ISO bus=0 source=5 gsi=5 flags=0xd
2023-03-27T10:30:10.0863582Z 
2023-03-27T10:30:10.0863731Z ACPI: MADT_ISO bus=0 source=9 gsi=9 flags=0xd
2023-03-27T10:30:10.0863925Z 
2023-03-27T10:30:10.0864077Z ACPI: MADT_ISO bus=0 source=10 gsi=10 flags=0xd
2023-03-27T10:30:10.0864279Z 
2023-03-27T10:30:10.0864384Z ACPI: MADT_ISO bus=0 source=11 gsi=11 flags=0xd
2023-03-27T10:30:10.0864580Z 
2023-03-27T10:30:10.0864730Z ACPI: 1 CPU(s) detected
2023-03-27T10:30:10.0864895Z 
2023-03-27T10:30:10.0865116Z ELF-loading userland images from boot modules:
2023-03-27T10:30:10.0865319Z 
2023-03-27T10:30:10.0865522Z size=0x30c000 v_entry=0x408477 v_start=0x400000 v_end=0x70c000 p_start=0xbad000 p_end=0xeb9000
2023-03-27T10:30:10.0865760Z 
2023-03-27T10:30:10.0865924Z Moving loaded userland images to final location: from=0xbad000 to=0xa13000 size=0x30c000
2023-03-27T10:30:10.0866267Z 
2023-03-27T10:30:10.0866399Z Starting node #0 with APIC ID 0
2023-03-27T10:30:10.0866609Z 
2023-03-27T10:30:10.0866749Z Mapping kernel window is done
2023-03-27T10:30:10.0866927Z 
2023-03-27T10:30:10.0867064Z available phys memory regions: 1
2023-03-27T10:30:10.0867200Z 
2023-03-27T10:30:10.0867327Z   [100000..1ffe0000]
2023-03-27T10:30:10.0867480Z 
2023-03-27T10:30:10.0867624Z reserved virt address space regions: 1
2023-03-27T10:30:10.0867822Z 
2023-03-27T10:30:10.0867992Z   [ffffff8000100000..ffffff8000d1f000]
2023-03-27T10:30:10.0868173Z 
2023-03-27T10:30:10.0868332Z Booting all finished, dropped to user space
2023-03-27T10:30:10.0868481Z 
2023-03-27T10:30:10.0868611Z Waiting for producer
2023-03-27T10:30:10.0868776Z 
2023-03-27T10:30:10.0868887Z 2: produce
2023-03-27T10:30:10.0869034Z 
2023-03-27T10:30:10.0869139Z 1: produce
2023-03-27T10:30:10.0869308Z 
2023-03-27T10:30:10.0869376Z Got badge: 2
2023-03-27T10:30:10.0869527Z 
2023-03-27T10:30:10.0869638Z Got badge: 1
2023-03-27T10:30:10.0869799Z 
2023-03-27T10:30:10.0869902Z 2: produce
2023-03-27T10:30:10.0870044Z 
2023-03-27T10:30:10.0870103Z 1: produce
2023-03-27T10:30:10.0870249Z 
2023-03-27T10:30:10.0870352Z Got badge: 2
2023-03-27T10:30:10.0870526Z 
2023-03-27T10:30:10.0870633Z Got badge: 1
2023-03-27T10:30:10.0870790Z 
2023-03-27T10:30:10.0870899Z 2: produce
2023-03-27T10:30:10.0870997Z 
2023-03-27T10:30:10.0871099Z 1: produce
2023-03-27T10:30:10.0871237Z 
2023-03-27T10:30:10.0871342Z Got badge: 2
2023-03-27T10:30:10.0871488Z 
2023-03-27T10:30:10.0871616Z Got badge: 1
2023-03-27T10:30:10.0871759Z 
2023-03-27T10:30:10.0871820Z 2: produce
2023-03-27T10:30:10.0871970Z 
2023-03-27T10:30:10.0872070Z 1: produce
2023-03-27T10:30:10.0872211Z 
2023-03-27T10:30:10.0872318Z Got badge: 2
2023-03-27T10:30:10.0872462Z 
2023-03-27T10:30:10.0872567Z Got badge: 1
2023-03-27T10:30:10.0872667Z 
2023-03-27T10:30:10.0872793Z 2: produce
2023-03-27T10:30:10.0872944Z 
2023-03-27T10:30:10.0873052Z 1: produce
2023-03-27T10:30:10.0873191Z 
2023-03-27T10:30:10.0873297Z Got badge: 2
2023-03-27T10:30:10.0873397Z 
2023-03-27T10:30:10.0873504Z Got badge: 1
2023-03-27T10:30:10.0873648Z 
2023-03-27T10:30:10.0873849Z Succes2: produce
2023-03-27T10:30:10.0874048Z 
2023-03-27T10:30:10.0874150Z 1: produce
2023-03-27T10:30:10.0874291Z 
2023-03-27T10:30:10.0874349Z s!
2023-03-27T10:30:10.0874485Z 
2023-03-27T10:30:10.0874640Z Caught cap fault in send phase at address 0
2023-03-27T10:30:10.0874832Z 
2023-03-27T10:30:10.0874951Z while trying to handle:
2023-03-27T10:30:10.0875126Z 
2023-03-27T10:30:10.0875305Z vm fault on data at address 0 with status 0x4
2023-03-27T10:30:10.0875453Z 
2023-03-27T10:30:10.0875623Z in thread 0xffffff80083a4400 "tcb_consumer" at address 0
2023-03-27T10:30:10.0875827Z 
2023-03-27T10:30:10.0875935Z With stack:
2023-03-27T10:30:10.0876088Z 
2023-03-27T10:30:10.0876198Z 0x41bee8: 0x407f8e
2023-03-27T10:30:10.0876351Z 
2023-03-27T10:30:10.0876418Z 0x41bef0: 0x419000
2023-03-27T10:30:10.0876584Z 
2023-03-27T10:30:10.0876714Z 0x41bef8: 0x0
2023-03-27T10:30:10.0876865Z 
2023-03-27T10:30:10.0876974Z 0x41bf00: 0x41bf40
2023-03-27T10:30:10.0877120Z 
2023-03-27T10:30:10.0877228Z 0x41bf08: 0x407bdf
2023-03-27T10:30:10.0877331Z 
2023-03-27T10:30:10.0877436Z 0x41bf10: 0x0
2023-03-27T10:30:10.0877591Z 
2023-03-27T10:30:10.0877701Z 0x41bf18: 0x41bfd8
2023-03-27T10:30:10.0877866Z 
2023-03-27T10:30:10.0877978Z 0x41bf20: 0x41bfd0
2023-03-27T10:30:10.0878128Z 
2023-03-27T10:30:10.0878190Z 0x41bf28: 0x41bfb8
2023-03-27T10:30:10.0878339Z 
2023-03-27T10:30:10.0878443Z 0x41bf30: 0x2
2023-03-27T10:30:10.0878587Z 
2023-03-27T10:30:10.0878704Z 0x41bf38: 0x4019f9
2023-03-27T10:30:10.0878849Z 
2023-03-27T10:30:10.0878980Z 0x41bf40: 0x41bf90
2023-03-27T10:30:10.0879082Z 
2023-03-27T10:30:10.0879192Z 0x41bf48: 0x407b81
2023-03-27T10:30:10.0879335Z 
2023-03-27T10:30:10.0879443Z 0x41bf50: 0x0
2023-03-27T10:30:10.0879595Z 
2023-03-27T10:30:10.0879713Z 0x41bf58: 0x41bfb0
2023-03-27T10:30:10.0879862Z 
2023-03-27T10:30:10.0880013Z 0x41bf60: 0x0
2023-03-27T10:30:10.0880162Z 
2023-03-27T10:30:10.0880427Z Failure! <class 'pexpect.exceptions.TIMEOUT'>
2023-03-27T10:30:10.0880982Z   File "/github/workspace/build/../projects/sel4-tutorials/test.py", line 144, in <module>
2023-03-27T10:30:10.0881365Z     sys.exit(main())
2023-03-27T10:30:10.0881760Z   File "/github/workspace/build/../projects/sel4-tutorials/test.py", line 139, in main
2023-03-27T10:30:10.0882105Z     run_tests(tests)
2023-03-27T10:30:10.0882576Z   File "/github/workspace/build/../projects/sel4-tutorials/test.py", line 107, in run_tests
2023-03-27T10:30:10.0883055Z     run_single_test(config, app, temp_file)
2023-03-27T10:30:10.0883542Z   File "/github/workspace/build/../projects/sel4-tutorials/test.py", line 87, in run_single_test
2023-03-27T10:30:10.0883979Z     if run_single_test_iteration(build_dir, solution, temp_file):
2023-03-27T10:30:10.0884511Z   File "/github/workspace/build/../projects/sel4-tutorials/test.py", line 50, in run_single_test_iteration
2023-03-27T10:30:10.0884899Z     result = check(_out=logfile, _cwd=build_dir)
2023-03-27T10:30:10.0885356Z   File "/usr/local/lib/python3.9/dist-packages/sh.py", line 1524, in __call__
2023-03-27T10:30:10.0885779Z     return RunningCommand(cmd, call_args, stdin, stdout, stderr)
2023-03-27T10:30:10.0886230Z   File "/usr/local/lib/python3.9/dist-packages/sh.py", line 788, in __init__
2023-03-27T10:30:10.0886575Z     self.wait()
2023-03-27T10:30:10.0886975Z   File "/usr/local/lib/python3.9/dist-packages/sh.py", line 845, in wait
2023-03-27T10:30:10.0887351Z     self.handle_command_exit_code(exit_code)
2023-03-27T10:30:10.0887780Z   File "/usr/local/lib/python3.9/dist-packages/sh.py", line 869, in handle_command_exit_code
2023-03-27T10:30:10.0888148Z     raise exc
2023-03-27T10:30:10.0888438Z sh.ErrorReturnCode_2: 
2023-03-27T10:30:10.0888567Z 
2023-03-27T10:30:10.0888750Z   RAN: /github/workspace/notificationsg3wja63r_build/check
2023-03-27T10:30:10.0888964Z 
2023-03-27T10:30:10.0889071Z   STDOUT:
2023-03-27T10:30:10.0889224Z 
2023-03-27T10:30:10.0889230Z 
2023-03-27T10:30:10.0889357Z   STDERR:
2023-03-27T10:30:10.0889513Z

I was able to reproduce what looks like the same behaviour locally while working through the notifications tutorial.

Environment:

Host: WSL2 Ubuntu Jammy
Platform: pc99
GCC: 11.4.0
Tutorial: notifications

Steps I ran:

cd ~/sel4/sel4-tutorials
mkdir -p notifications_solution_build
cd notifications_solution_build
../init --tut notifications --solution
cd ../notifications_solution_build_build
ninja
./simulate

Observed behaviour:

The tutorial reaches Success!, but then tcb_consumer faults at address 0:
Success!
Caught cap fault in send phase at address 0
while trying to handle:
vm fault on data at address 0 with status 0x4
in thread ... "tcb_consumer" at address 0

I also tried modifying consumer.c so that after printing Success!, it does not return from main:
printf("Success!\n");

while (1) {
    seL4_Yield();
}

return 0;

With that change, the post-success fault disappeared in my local run.

This makes me wonder whether at least one failure mode is caused by the consumer returning from main after the success condition, rather than the producer-consumer notification logic itself failing.

I was able to reproduce a similar failure mode locally with the notifications tutorial solution.

In my local run, the solution printed Success! and then faulted in tcb_consumer at address 0 after returning from main. I tested a small change that keeps the consumer alive after printing Success! by yielding in a loop instead of returning, and that removed the post-success fault in my local reproduction.

I opened PR #124 with that change.

I’m not sure whether this covers every intermittent CI failure described here, but it appears to address at least the post-success tcb_consumer fault pattern shown in the log.

Some diagnosis on this one: the change in #124 is unrelated. The vm fault happens in the consumer thread when it ends, as usual, and always after the "Success!" print has finished. It might still be nice to just not exit to avoid confusing people with that fault, but it is unrelated to the race condition in this issue.

The producer threads do not produce any vm fault, because they can never finish their producer loops (the consumer consumes 10 in total, they have 100 produce iterations and wait on "empty" every time).

The race is between the end of the consumer loop, which wakes up one or two producers (and no longer waits for them, because the loop is over). The producers each advance to printing <n>: produce, and that print races with "Success!" in the consumer.

The CI success check is waiting for the string "Success!", so if that interleaves with producer output, it fails.

The fix is a bit annoying, I haven't come up with anything yet that does not pollute the tutorial. You can easily wait for one producer just before the "Success!" print, but in theory, 2 producers could have been woken up in the loop (and usually are, but it is not guaranteed). You could keep track of how many were woken up in a variable, but that pollutes the tutorial loop. You could add some kind of busy loop, but that's not something we should teach people to do.

I'm tempted to just wait for one consumer and leave tracking for two consumers as an additional exercise in the comment. Waiting for one consumer should usually be enough to let both of them finish printing before the consumer starts "Success!". It's still a race, but it's less likely and hopefully less annoying in CI.

Actually, I think I do have a solution that doesn't need any additional tracking. Need to try it out, though.

notifications: add final task for race-free print

Navigation Menu

Repository navigation

The notification tutorial solution seems to have a race condition #100

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

The notification tutorial solution seems to have a race condition #100

Description

Activity

praneelmalapaka commented on Jun 21, 2026

praneelmalapaka commented on Jun 21, 2026

lsf37 commented on Jul 3, 2026

lsf37 commented on Jul 3, 2026

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions