The notification tutorial solution seems to have a race condition

[lsf37]

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