2023-03-15 And now for something entirely different…
Wayne Meretsky told us via email that the Oregon Software PASCAL compiler for the IOP programs, and after a number of not very productive searches, we finally found that one of the founders of Oregon Software had put almost exactly the most interesting parts of the compiler up on github:
Some good clues about the peephole-optimizations can be found here:
2023-03-10 No emulating after bedtime
Every so often, in late evening sessions, we would persistently run into this error:
PASCAL error #4 at location 000218D0 Last called from location 000220C8 Last called from location 0002251C Last called from location 00023296
And being late at night, the obvious thing was to go to bed and look at it with fresher eyes later … where it then fails to happen.
We finally dived into the disassembled PASCAL code of
LOADER.M200 and found the bug, which was, of course, painfully obvious in the tracefile, if we had not been so sleepy:
Calendar([14 03 08 03 16 13 11]) Calendar([14 03 08 03 16 13 12]) Calendar([14 03 08 03 16 13 13]) Calendar([14 03 08 03 16 14 57]) Calendar([14 03 08 03 17 47 21]) Calendar([14 03 08 03 24 18 28])
These are the timestamps read from the RTC chip by kernel system-call 0x13, and the fields are:
Year-1 (binary) Month (BCD) Day (BCD) Weekday Hour (BCD) Minute (BCD) Second (BCD)
The RTC emulation had a bug relating to the values 0x18, 0x24 and 24.
This is now fixed, and we implemented the missing midnight increment of the day/wday/month fields as well.
2023-02-26 License or not
Having established that the real machine does not assert when the cluster-ID is wrong and the licenses invalid, it is obvious to ask: Does the machine boot faster if those software products are unlicensed?
A quick run this morning confirms that it is so.
An licensed boot takes 1327 seconds, an unlicensed only 1194 seconds.
It is the time
"username:" console messages,
which is a bit more than two minutes shorter.
This is good to know, but not actionable until the emulator makes it all the way to
2023-02-25 Different. Still lousy, but different
ADA_MANAGEMENT.11.50.4D DISK_CLEANER.11.1.3D PARSER.11.50.1D PRETTY_PRINTER.11.50.3D
====>> Environment Log <<==== 09:58:39 !!! EEDB Assert_Failure Unable to elaborate PRETTY_PRINTER.11.50.3D: Unhandled exception - 16#84# at PC 00169C1300007FE0 ====>> Elaborator Database <<==== Unable to elaborate PRETTY_PRINTER.11.50.3D: Unhandled exception - 16#84# at PC& 00169C1300007FE0 EEDB: %
So this run was the "megacomp4" branch where we have attempted to optimize things, so the next logical experiment is to fall back to the "main" branch, which is our ground-truth, using the "much-deleted" disk-images, and see what that does.
At least we will find out in a couple of weeks, rather than months.
We tried booting the real machine with a wrong cluster ID, and it produced the same »Product_Authorization Invalid for« messages, but did not assert, so that is also a solid indication that something is wrong still.
2023-02-24 Good Omens
A certain part of the failing runs look like this:
Elaborating subsystem: ELABORATOR_DATABASE ====>> Elaborator Database <<==== NETWORK.11.1.5D OM_MECHANISMS.11.2.0D BASIC_MANAGERS.11.3.0D
While on the real machine it looks like this:
Elaborating subsystem: ELABORATOR_DATABASE ====>> Elaborator Database <<==== NETWORK.11.1.5D OM_MECHANISMS.11.2.0D ====>> Environment Log <<==== 10:48:37 +++ Low_Level_Action.Manager Restoration_From_Archive ====>> Elaborator Database <<==== BASIC_MANAGERS.11.3.0D
And, as of this morning, so does it in emulator when running with the cluster number from PAM's machine.
2023-02-22 Second long run failed same way
After the three months long run failed in November, we started the exact same run again, to get an idea how reproducible the failure-mode is, and this morning we have the answer: It failed precisely the same way:
Kernel assert failure detected by kernel debugger stub. System shutting down. Exception: !Lrm.System.Assertion_Error, from PC = #F6413, #707
A week ago we got the exact same failure after only 16 days, using the new much-deleted disk-images, so we are very confident that this is something we will be able to track down.
#F6413 is loaded in
KK.11.5.9K.MLOAD where it is commented as "BTREE_MANAGER", which sounds like very fundamental Ada-code.
We are seven days into the run where we patched the cluster-id to match PAM's machine, not out of the "starting VM" phase yet, but getting there, in some days we will know if that solves the "Product_Authorization Invalid for […]" issue, and a couple of weeks from now, we will know if that also solves the BTREE_MANAGER assert.
In the meantime, "mega-component" optimizations continue.
2023-02-14 Patching the cluster-id
We have started a new run identical to the 16 day run which just failed, except for one detail: We have patched the cluster-id of PAM's machine into the IOC_EEPROM with the following CLI command to the emulator:
cli firmware patch IOC_EEPROM 0x7e84 0x00 0x06 0x3b 0x8b
Hopefully that fixes at least the
2023-02-14 Failing five times faster
The bad news:
The much-deleted-diskimage + megacomp4 run failed after 16 days.
The good news:
It failed precisely the same way (see below), as the three month run on the full diskimage did, back in November 2022.
The product authorization failures is undoubtedly a very strong clue, we just dont know what it means.
The code segment which fails,#F6413, is 1008659.SEG.
.MLOAD file it has the comment
-- BTREE_MANAGER and the instruction at #707 is:
0707 0257 Execute Discrete,Raise
Now we need to find out why…
DISK_CLEANER.11.1.3D PARSER.11.50.1D PRETTY_PRINTER.11.50.3D DIRECTORY.11.4.6D INPUT_OUTPUT.11.7.0D ====>> Environment Log <<==== 05:49:07 !!! Product_Authorization Invalid for Work_Orders 05:49:07 !!! Product_Authorization Invalid for Cmvc 05:49:08 !!! Product_Authorization Invalid for Rci 05:49:08 !!! Product_Authorization Invalid for Tcp/Ip 05:49:08 !!! Product_Authorization Invalid for Rpc 05:49:09 !!! Product_Authorization Invalid for Insight 05:49:09 !!! Product_Authorization Invalid for Rs6000_Aix_Ibm 05:49:09 !!! Product_Authorization Invalid for X Interface 05:49:09 !!! Product_Authorization Invalid for Cmvc.Source_Control 05:49:10 !!! Product_Authorization Invalid for Rcf 05:49:10 !!! Product_Authorization Invalid for Testmate 05:49:10 !!! Product_Authorization Invalid for Fundamental Session 05:49:11 !!! Product_Authorization Invalid for Lrm_Interface 05:49:11 !!! Product_Authorization Invalid for Telnet 05:49:11 !!! Product_Authorization Invalid for Ftp 05:49:11 !!! Product_Authorization Invalid for X_Library 05:49:12 !!! Product_Authorization Invalid for Dtia ====>> Elaborator Database <<==== COMPILER_UTILITIES.11.51.0D SEMANTICS.11.50.3D R1000_DEPENDENT.11.51.0D R1000_CHECKING.11.51.0D R1000_CODE_GEN.11.51.0D IMAGE.11.4.2D CORE_EDITOR.11.6.2D TOOLS.11.5.1D OE_MECHANISMS.11.1.2D OBJECT_EDITOR.11.6.1D MAIL.DELTA OS_COMMANDS.11.6.2D ====>> Kernel.11.5.8 <<==== Kernel: Kernel assert failure detected by kernel debugger stub. System shutting down. Exception: !Lrm.System.Assertion_Error, from PC = #F6413, #707
2023-02-07 Getting somewhere 8x faster
Thanks to the much-stuff-deleted-diskimages, we can now get to the code after the VM initialization in 9 days, instead of 72 days:
rr001 (cyan&green) is main branch and original disk-images
rr007 (purple&orange) is megacomp4 branch and reduced disk-images
2023-01-28 Belated Happy New-year!
(Apologies for the lack of updates this last month, a bacterial pneumonia stole a couple of weeks.)
We have finally found the secret to making the R1000, real or emulated, boot faster: The nightly daemon run.
PAM told us that the way to get faster boot was to "delete stuff, in particular ADA objects".
We have tried that a number of times, but to no avail: The boot time stubbornly took one hour and some minutes.
Then some random experiments made us to run so much out of disk-space, that we had to run the nightly daemon run to proceed.
That took 4+ hours, and then the next boot was 10 minutes faster - Secret sauce detected!
With the pristine disk-image it take 2076 seconds to get from
starting virtual memory system to
the virtual memory system is up
After a two week campaign of sessions of wanton destruction, each concluding with
daemon.run("daily"), we have reduced that to 284 seconds.
At the current speed, that should make the emulation of the "main" branch boot 70 days faster: 58 days instead of 128 days.
- 2022 Logbook entries - We are getting somewhere with the emulation
- 2021 Logbook entries - We discover there is no instruction set, and start simulating hardware
- 2020 Logbook entries - Covid-19 happens, and we start to create a software emulation
- 2019 Logbook entries - We fix the IOC RAM error, and Pierre-Alain Muller drops by for startup
- 2014-2018 - The project got stuck for lack of a sufficiently beefy 5V power-supply, and then phk disappeared while he built a new house.
- 2013 Logbook entries - Documentation preservation and we run into the IOC RAM error
- 2012 Logbook entries - Preservation starts and we borrow tapes from Pierre-Alain Muller
Many thanks to
- Erlo Haugen
- Grady Booch
- Grek Bek
- Pierre-Alain Muller
- Michael Druke
- Pascal Leroy