musliner
commented
2 years ago pal-tournament.log.gz bridge.log.gz
the issue occurs in the first (pre-nov) game; later games are 6-3-1-E, ftr.
At SIFT, this is from musliner@openmind0:~/openmind/code/test/results/pal-tournament-v2-shared-6-3-1-E-no-pogoist-2021-12-30-125854-openmind0/
I have a no-novelty test run where a sapling didn’t appear after 7 NOPs after a break-block on log/tree (or actually ever, I think)
Our agent is robust to this condition, it reports novelty and replans... but I think that this may represent a sim bug, and our report would be assessed as an FP.
This appears to be somewhat reproducible (at least in my last two runs)...
Note the timestamps reveal we are currently not waiting a second after each NOP, unlike other action commands. Perhaps we need to? The reason I took those delays out is we were running out of time on some of the novelties like 6-3-1-H where you have to grow a lot of trees; if the NOPs each take a second etc, it adds up...
Logs attached in minute...
In our terms, the original plan is: (BREAK-BLOCK-PLATINUM-BLOCK LOC61_17_51) (BREAK-BLOCK-DIAMOND-ORE LOC45_17_35) (BREAK-BLOCK-LOG LOC43_17_42) (GROW-TREE-FROM-SAPLING LOC56_17_39) ...
So you'll see two break-blocks before the one on the log.
This custom grep pulls from our bridge log the commands sent to the sim and also when we first see mention of sapling in inventory...
zgrep 'command_ver|sapling' bridge.log.gz |egrep 'command_v|in-inv' |less... and here's what you get, from the third break-block onwards: 1384:[2021-12-30 13:01:23] command_verb: BREAK_BLOCK 1394:[2021-12-30 13:01:24] command_verb: SENSE_ACTOR_ACTIONS 1407:[2021-12-30 13:01:24] command_verb: SENSE_ALL 1495:[2021-12-30 13:01:24] command_verb: NOP 1505:[2021-12-30 13:01:24] command_verb: NOP 1515:[2021-12-30 13:01:24] command_verb: NOP 1525:[2021-12-30 13:01:24] command_verb: NOP 1535:[2021-12-30 13:01:24] command_verb: NOP 1545:[2021-12-30 13:01:24] command_verb: NOP 1555:[2021-12-30 13:01:24] command_verb: NOP 1565:[2021-12-30 13:01:25] command_verb: SENSE_ACTOR_ACTIONS 1578:[2021-12-30 13:01:25] command_verb: SENSE_ALL 1666:[2021-12-30 13:01:26] command_verb: SENSE_ALL 1754:[2021-12-30 13:01:26] command_verb: SENSE_ALL 1842:[2021-12-30 13:01:26] command_verb: REPORT_NOVELTY 1852:[2021-12-30 13:01:28] command_verb: TP_TO 1862:[2021-12-30 13:01:29] command_verb: SENSE_ACTOR_ACTIONS 1875:[2021-12-30 13:01:29] command_verb: SENSE_ALL 1964:[2021-12-30 13:01:29] command_verb: BREAK_BLOCK 1974:[2021-12-30 13:01:30] command_verb: SENSE_ACTOR_ACTIONS 1987:[2021-12-30 13:01:30] command_verb: SENSE_ALL 2070:[2021-12-30 13:01:30] command_verb: NOP 2080:[2021-12-30 13:01:30] command_verb: NOP 2090:[2021-12-30 13:01:30] command_verb: NOP 2100:[2021-12-30 13:01:30] command_verb: NOP 2110:[2021-12-30 13:01:30] command_verb: NOP 2120:[2021-12-30 13:01:30] command_verb: NOP 2130:[2021-12-30 13:01:30] command_verb: NOP 2140:[2021-12-30 13:01:31] command_verb: SENSE_ACTOR_ACTIONS 2153:[2021-12-30 13:01:31] command_verb: SENSE_ALL 2194:[2021-12-30 13:01:31] prsinterface[24028] send_message: Sending message to openmind: (domain-fact (in-inventory minecraft.sapling 1))that last line shows when we first see sapling in inventory.
this more verbose grep shows the break-block did succeed...
zgrep 'command_ver|command-response|sapling' bridge.log.gz |egrep 'command|in-inv' |less