search

chipsalliance / caliptra-sw

Caliptra software (ROM, FMC, runtime firmware), and libraries/tools needed to build and test
Apache License 2.0
94 stars 44 forks source link

Verilator test failures: caliptra-runtime::integration_tests #851

Closed korran closed 1 year ago

korran commented 1 year ago 
50364:2023-09-20T01:45:54.8524368Z         FAIL [26955.341s] caliptra-runtime::integration_tests test_disable_attestation_cmd
52108:2023-09-20T02:35:19.0550460Z         FAIL [27705.854s] caliptra-runtime::integration_tests test_fips_cmd_api
53341:2023-09-20T03:14:50.3249292Z         FAIL [27293.130s] caliptra-runtime::integration_tests test_invoke_dpe_sign_and_certify_key_cmds
54099:2023-09-20T03:42:33.9457981Z         FAIL [27095.727s] caliptra-runtime::integration_tests test_keyvault
56727:2023-09-20T05:58:25.2853509Z         FAIL [38798.178s] caliptra-runtime::integration_tests test_fw_info
57214:2023-09-20T06:15:38.4889439Z         FAIL [19932.771s] caliptra-runtime::integration_tests test_stash_measurement
2023-09-20T06:15:38.4889439Z         FAIL [19932.771s] caliptra-runtime::integration_tests test_stash_measurement
2023-09-20T06:15:38.4889986Z 
2023-09-20T06:15:38.4890783Z --- STDOUT:              caliptra-runtime::integration_tests test_stash_measurement ---
2023-09-20T06:15:38.4891261Z 
2023-09-20T06:15:38.4891437Z running 1 test
2023-09-20T06:15:38.4895722Z       6,155 ready_for_fuses is high
2023-09-20T06:15:38.4896273Z       6,333 writing to cptra_bootfsm_go
2023-09-20T06:15:38.4896932Z test test_stash_measurement has been running for over 60 seconds
2023-09-20T06:15:38.4897533Z     195,201 UART: 
2023-09-20T06:15:38.4902426Z     195,256 UART: Running Caliptra ROM ...
2023-09-20T06:15:38.4902789Z     196,662 UART: 
2023-09-20T06:15:38.4903077Z     202,819 UART: [state] CFI Enabled
2023-09-20T06:15:38.4903441Z     205,066 UART: [state] LifecycleState = Unprovisioned
2023-09-20T06:15:38.4903787Z     207,326 UART: [state] DebugLocked = No
2023-09-20T06:15:38.4904235Z     209,296 UART: [state] Watchdog Timer is not started because the device is not locked for debugging
2023-09-20T06:15:38.4922829Z     355,872 UART: ROM Digest: BBB6BA0BFBA2F1E2103A1060EB333FF6613A1F43E352AA823F62EF22650FF80F
2023-09-20T06:15:38.4923719Z     367,112 UART: [kat] ++
2023-09-20T06:15:38.4924174Z     367,624 UART: [kat] sha1
2023-09-20T06:15:38.4924963Z     376,784 UART: [kat] SHA2-256
2023-09-20T06:15:38.4925523Z     379,656 UART: [kat] SHA2-384
2023-09-20T06:15:38.4926130Z     383,921 UART: [kat] SHA2-384-ACC
2023-09-20T06:15:38.4926750Z     386,218 UART: [kat] ECC-384
2023-09-20T06:15:38.4927341Z   3,956,572 UART: [kat] HMAC-384
2023-09-20T06:15:38.4927802Z   3,967,624 UART: [kat] LMS
2023-09-20T06:15:38.4928827Z   5,069,426 UART: [kat] --
2023-09-20T06:15:38.4929416Z   5,073,687 UART: [cold-reset] ++
2023-09-20T06:15:38.4929925Z   5,075,903 UART: [idev] ++
2023-09-20T06:15:38.4930397Z   5,076,482 UART: [idev] CDI.KEYID = 6
2023-09-20T06:15:38.4930925Z   5,077,732 UART: [idev] SUBJECT.KEYID = 7
2023-09-20T06:15:38.4931615Z   5,079,204 UART: [idev] UDS.KEYID = 0
2023-09-20T06:15:38.4932156Z   5,098,333 UART: [idev] Erasing UDS.KEYID = 0
2023-09-20T06:15:38.4933038Z   8,365,543 UART: [idev] Using Sha1 for KeyId Algorithm
2023-09-20T06:15:38.4933672Z   8,387,845 UART: [idev] --
2023-09-20T06:15:38.4934112Z   8,393,994 UART: [ldev] ++
2023-09-20T06:15:38.4934621Z   8,394,587 UART: [ldev] CDI.KEYID = 6
2023-09-20T06:15:38.4939743Z   8,395,829 UART: [ldev] SUBJECT.KEYID = 5
2023-09-20T06:15:38.4940690Z   8,397,301 UART: [ldev] AUTHORITY.KEYID = 7
2023-09-20T06:15:38.4941196Z   8,398,883 UART: [ldev] FE.KEYID = 1
2023-09-20T06:15:38.4941550Z   8,412,000 UART: [ldev] Erasing FE.KEYID = 1
2023-09-20T06:15:38.4942210Z  11,700,057 UART: [ldev] Signing Cert with AUTHORITY.KEYID = 7
2023-09-20T06:15:38.4942800Z  15,298,320 UART: [ldev] PUB.X = 504D38CA45D997901F48BA333A149A2FB2668B973AAC64D3B79ECC09A663F02ED2FABA133F5FA499677AEB7687C99B25
2023-09-20T06:15:38.4943542Z  15,314,018 UART: [ldev] PUB.Y = A5CD31125698B3322C086E4398A591946BF20A3ECEA8EB7D7C23410D49FA877E7ECFBE47BD883BD53D7DA865AC217F1D
2023-09-20T06:15:38.4944545Z  15,330,088 UART: [ldev] SIG.R = 14B5D494DF875AC7CEE9FE3E9A6168A6B64BFB01171F5ECC5216C8BB945FAF957CED1BE6C7CFBB1DDB2B7F4BFD76A492
2023-09-20T06:15:38.4945354Z  15,346,000 UART: [ldev] SIG.S = 821D8CC92F40AFF934771D7652C9BC3C59D47E5635E110A8486B76F7433B02B3C6B0FD8B1B6548B5994C481547111FC5
2023-09-20T06:15:38.4945987Z  15,367,949 UART: [ldev] --
2023-09-20T06:15:38.4946282Z  15,375,413 ready_for_fw is high
2023-09-20T06:15:38.4946626Z  15,375,415 <<< Executing mbox cmd 0x46574c44 (63908 bytes) from SoC
2023-09-20T06:15:38.4947021Z  15,375,474 UART: [fwproc] Waiting for Commands...
2023-09-20T06:15:38.4959765Z  15,411,190 UART: [fwproc] Received command 0x46574c44
2023-09-20T06:15:38.4960559Z  15,413,803 UART: [fwproc] Received Image of size 63908 bytes
2023-09-20T06:15:38.4961332Z  18,131,031 UART: [fwproc] Image verified using Vendor ECC Key Index 0
2023-09-20T06:15:38.4962176Z  18,214,988 UART: [fwproc] Loading FMC at address 0x40000000 len 12964
2023-09-20T06:15:38.4962866Z  18,296,394 UART: [fwproc] Loading Runtime at address 0x40004000 len 45060
2023-09-20T06:15:38.4963708Z  18,572,382 >>> mbox cmd response: success
2023-09-20T06:15:38.4964675Z  18,575,639 UART: [afmc] ++
2023-09-20T06:15:38.4965373Z  18,576,219 UART: [afmc] CDI.KEYID = 6
2023-09-20T06:15:38.4966175Z  18,577,469 UART: [afmc] SUBJECT.KEYID = 7
2023-09-20T06:15:38.4966936Z  18,578,927 UART: [afmc] AUTHORITY.KEYID = 5
2023-09-20T06:15:38.4967384Z  21,893,593 UART: [afmc] Signing Cert with AUTHORITY.KEYID = 5
2023-09-20T06:15:38.4967814Z  24,186,864 UART: [afmc] Erasing AUTHORITY.KEYID = 5
2023-09-20T06:15:38.4968432Z  25,495,691 UART: [afmc] PUB.X = 74A2DA8F43E3CF7B034EB91F9FEBBBEBD3F2BB8B9B15CCF6B2944AE9C548D4ACDD20742598EA46075F5EE3D570A3C884
2023-09-20T06:15:38.4969209Z  25,511,479 UART: [afmc] PUB.Y = F0B6D79EFAF624F13C60ACE8287337FA10B411125D5F76A85844E286F5E554EBD2D1B41B1DFB30A078203A651EFE8C34
2023-09-20T06:15:38.4969908Z  25,527,387 UART: [afmc] SIG.R = 8C94183EECD46495965C1F58565A801C567721535D1E46E8FBD8FE28C4361A17C85DDA0427F22D62A34CAFBA60DE91CF
2023-09-20T06:15:38.4970601Z  25,543,051 UART: [afmc] SIG.S = 57083EFAA8C09D86B408ABDEB8120F3A0A87C9C1DAD6EA4940C67CDFEED457B052E07185C310A798191C6F16BBB24B74
2023-09-20T06:15:38.4971288Z  25,570,495 UART: [afmc] --
2023-09-20T06:15:38.4971655Z  25,574,380 UART: [cold-reset] --
2023-09-20T06:15:38.4971963Z  25,589,999 UART: [fht] Storing FHT @ 0x50003400
2023-09-20T06:15:38.4972421Z  25,607,861 UART: [state] Watchdog Timer is not stopped because the device is not locked for debugging
2023-09-20T06:15:38.4972855Z  25,614,773 UART: [state] Locking Datavault
2023-09-20T06:15:38.4973565Z  25,619,819 UART: [state] Locking PCR0, PCR1 and PCR31
2023-09-20T06:15:38.4973926Z  25,621,895 UART: [state] Locking ICCM
2023-09-20T06:15:38.4974268Z  25,623,411 UART: [exit] Launching FMC @ 0x40000134
2023-09-20T06:15:38.4974570Z  25,632,220 UART: 
2023-09-20T06:15:38.4974842Z  25,632,254 UART: Running Caliptra FMC ...
2023-09-20T06:15:38.4975129Z  25,633,097 UART: 
2023-09-20T06:15:38.4975416Z  25,636,088 UART: [alias rt] Extend RT PCRs
2023-09-20T06:15:38.4975921Z  25,669,171 UART: [alias rt] Extend RT PCRs Done
2023-09-20T06:15:38.4976265Z  25,670,213 UART: [alias rt] Lock RT PCRs
2023-09-20T06:15:38.4976603Z  25,671,022 UART: [alias rt] Lock RT PCRs Done
2023-09-20T06:15:38.4976915Z  25,672,002 UART: [alias rt] Populate DV
2023-09-20T06:15:38.4977249Z  25,672,900 UART: [alias rt] Populate DV Done
2023-09-20T06:15:38.4977674Z  25,673,880 UART: Handoff : FMC CDI: 6
2023-09-20T06:15:38.4978080Z  25,674,648 UART: FMC Alias Private Key: 7
2023-09-20T06:15:38.4978404Z  25,676,559 UART: [alias rt] Derive CDI
2023-09-20T06:15:38.4978740Z  25,677,300 UART: [alias rt] Store in in slot 0x4
2023-09-20T06:15:38.4979062Z  25,711,040 UART: [alias rt] Derive Key Pair
2023-09-20T06:15:38.4979417Z  25,711,948 UART: [alias rt] Store priv key in slot 0x5
2023-09-20T06:15:38.4979887Z  28,951,155 UART: [alias rt] Derive Key Pair - Done
2023-09-20T06:15:38.4980249Z  28,962,164 UART: [alias rt] Signing Cert with AUTHO
2023-09-20T06:15:38.4980565Z  28,963,331 UART:             RITY.KEYID = 7
2023-09-20T06:15:38.4980920Z  31,241,454 UART: [alias rt] Erasing AUTHORITY.KEYID = 7
2023-09-20T06:15:38.4981496Z  31,242,965 UART: [alias rt] PUB.X = 936D29CD91478E8BFD8448DF77FB434E813422DFBBA0A1C4AD9E65038F57DC8EF9A599AE7B20C8FB81425C13941B7BE2
2023-09-20T06:15:38.4982217Z  31,250,408 UART: [alias rt] PUB.Y = 56D1DAB09D37E0B66C64463FD2636502A9368DE8DE9F6F8108D5936AC454E38B9A14E0A1201EB194C7ECB8F54540BC6C
2023-09-20T06:15:38.4982984Z  31,257,994 UART: [alias rt] SIG.R = 7B1DC3CBAE95BAAD3E5125F0DF699AFACC8902F69EDF6F91CE3C9496C87D70C58C45F8D048B6E7FACB92E962C925EF85
2023-09-20T06:15:38.4983766Z  31,265,416 UART: [alias rt] SIG.S = B8F6D886DF8F6244A01CF306E1C807D7B4F26C09EEB9C61E6242E38BA1C7A4E2624ECB6A9E254EA19C11AECEACC0E5FE
2023-09-20T06:15:38.4984237Z  32,568,977 UART: 
2023-09-20T06:15:38.4984517Z  32,569,011 UART:   ____      _ _       _               ____ _____
2023-09-20T06:15:38.4984872Z  32,570,643 UART:  / ___|__ _| (_)_ __ | |_ _ __ __ _  |  _ \_   _|
2023-09-20T06:15:38.4985375Z  32,572,309 UART: | |   / _` | | | '_ \| __| '__/ _` | | |_) || |
2023-09-20T06:15:38.4985787Z  32,573,908 UART: | |__| (_| | | | |_) | |_| | | (_| | |  _ < | |
2023-09-20T06:15:38.4986115Z  32,575,507 UART:  \____\__,_|_|_| .__/ \__|_|  \__,_| |_| \_\|_|
2023-09-20T06:15:38.4986422Z  32,577,106 UART:                |_|
2023-09-20T06:15:38.4986687Z  32,577,748 UART: 
2023-09-20T06:15:38.4987006Z  32,674,348 UART: Caliptra RT listening for mailbox commands...
2023-09-20T06:15:38.4987414Z  32,675,908 <<< Executing mbox cmd 0x4d454153 (108 bytes) from SoC
2023-09-20T06:15:38.4987800Z  32,681,270 UART: [rt] Received command=0x4d454153, len=108
2023-09-20T06:15:38.4988135Z  32,689,968 >>> mbox cmd response data (12 bytes)
2023-09-20T06:15:38.4988473Z test test_stash_measurement ... FAILED
2023-09-20T06:15:38.4988673Z 
2023-09-20T06:15:38.4988768Z failures:
2023-09-20T06:15:38.4988917Z 
2023-09-20T06:15:38.4989009Z failures:
2023-09-20T06:15:38.4989246Z     test_stash_measurement
2023-09-20T06:15:38.4989424Z 
2023-09-20T06:15:38.4989693Z test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 18 filtered out; finished in 19932.75s
2023-09-20T06:15:38.4989996Z 
2023-09-20T06:15:38.4990003Z 
2023-09-20T06:15:38.4990524Z --- STDERR:              caliptra-runtime::integration_tests test_stash_measurement ---
2023-09-20T06:15:38.4996100Z thread 'test_stash_measurement' panicked at 'assertion failed: `(left == right)`
2023-09-20T06:15:38.4996619Z   left: `4097`,
2023-09-20T06:15:38.4996995Z  right: `0`', runtime/tests/integration_tests.rs:264:5
nquarton commented 1 year ago

Is anyone looking into this issue yet? If not, I can start

jhand2 commented 1 year ago

@nquarton No I don't think anyone has started on this one. Thanks!

jhand2 commented 1 year ago

Actually, let's split this up into multiple issues so that we can parallelize the work.

I opened https://github.com/chipsalliance/caliptra-sw/issues/882 and assigned to Zach to handle the stuff related to DPE. @nquarton would you want to take the other tests?

nquarton commented 1 year ago

Actually, let's split this up into multiple issues so that we can parallelize the work.

I opened #882 and assigned to Zach to handle the stuff related to DPE. @nquarton would you want to take the other tests?

  • test_keyvault
  • test_fw_info
  • test_fips_cmd_api

I may not be able to get to these other issues for a week or two due to some other priorities. If no one else can get to them earlier, I could take a look at that point.

nquarton commented 1 year ago

For the stash measurement issue (and possibly some others) the problem is verilator (and it looks like the FPGA) use a hardcoded PAUSER of 0xFFFF_FFFF. DPE expects a PAUSER of 0x1 from what's provided in the image header. This causes the DPE code to report a failure.

However PAUSER values other than 0xFFFF_FFFF are blocked by the RTL. Only 0xFFFF_FFFF is valid by default (which I'm guessing is an invalid PAUSER? or is this a HW vulnerability?). To allow others, we need to set MBOX_VALID_PAUSER and MBOX_PAUSER_LOCK. I am adding this flow to the hw-model initialization.

We also need to add support to configure the PAUSER used on the bus in all 3 models (it's not configurable in the emulator either).

Ideally, the emulator should be covering this RTL behavior of VALID_PAUSER and PAUSER lock at some point as well.

nquarton commented 1 year ago

Sorry Jordan, I misunderstood what you were asking at first. I started looking at the stash measurement failure since that was the one that was in the log. I missed the top part that listed all the other failures at first. If any other DPE failures are for locality/pauser, then the fix I can make should correct those as well.

But still the same answer for the others. Exactly when I can get to them will depend on some other tasks. But I'll put it on my list and I can get to it if no one else gets a chance to.

jhand2 commented 1 year ago

Thanks Nick! No problem, we can look into the other failures and open separate issues.

To allow others, we need to set MBOX_VALID_PAUSER and MBOX_PAUSER_LOCK. I am adding this flow to the hw-model initialization.

We also need to add support to configure the PAUSER used on the bus in all 3 models (it's not configurable in the emulator either).

So once you've updated the hw model to set those registers, would you expect this to work for Verilator/FPGA, and then the next step would be to implement use of those registers in the emulator?

cc @zhalvorsen as FYI for why some of the tests are failing.

I think some of the other failures are because the FPGA only supports 8 KeyVaultSlots. I think we use 10 today. We should look into

  1. Can DPE use fewer KV slots?
  2. If not, can we increase the FPGA to support 16? (FPGA bitstream is really close on space, so we should avoid this if we can)
nquarton commented 1 year ago

So once you've updated the hw model to set those registers, would you expect this to work for Verilator/FPGA, and then the next step would be to implement use of those registers in the emulator?

Yep, I pushed a "partial" fix (https://github.com/chipsalliance/caliptra-sw/pull/893) that will change the hardcoded value for PAUSER for verilator and FPGA to 0x1. It also adds a configuration option for the HW-model to init the necessary MBOX_VALID_PAUSER reg with a default of 1 and set LOCK as well. This for sure fixes the stash measurement test on verilator. I haven't had a chance to try the other broken tests or try on FPGA.

The full solution would just add the ability to configure the PAUSER value the 3 models use. Though this could be a separate PR technically since that's really a new feature anyway.

nquarton commented 1 year ago

Just an update that fix should be complete now. The emulator still doesn't support the VALID_PAUSER check but it also doesn't actually seem to emulate pauser on the bus itself so I think that's an enhancement for a later time. Both VALID_PAUSER and the pauser value we want "soc" to use are configurable now though (and apply to both verilator and FPGA).

zhalvorsen commented 1 year ago

With #970 added we can now all the caliptra-runtime::integration_tests more easily on the FPGA. caliptra-runtime::runtime_integration_tests integration_tests::test_update is now the only test failing.

ubuntu@zynqmp:~/caliptra-sw$ CPTRA_UIO_NUM=4 cargo nextest run --no-fail-fast --features=fpga_realtime --release -E 'package(caliptra-runtime)'
    Finished release [optimized] target(s) in 1.57s
    Starting 23 tests across 68 binaries
        PASS [  40.528s] caliptra-runtime::runtime_integration_tests error_handling::test_wdt_timeout
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests ecdsa::ecdsa_cmd_run_wycheproof
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests hmac::hmac_cmd_run_wycheproof
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_boot
        PASS [  64.583s] caliptra-runtime::runtime_integration_tests ecdsa::ecdsa_cmd_run_wycheproof
        PASS [  73.007s] caliptra-runtime::runtime_integration_tests hmac::hmac_cmd_run_wycheproof
        PASS [  81.143s] caliptra-runtime::runtime_integration_tests integration_tests::test_boot
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_certs
        PASS [  71.445s] caliptra-runtime::runtime_integration_tests integration_tests::test_certs
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_disable_attestation_cmd
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_ecdsa_verify_cmd
        PASS [  69.842s] caliptra-runtime::runtime_integration_tests integration_tests::test_disable_attestation_cmd
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_error_cleared
        PASS [  78.127s] caliptra-runtime::runtime_integration_tests integration_tests::test_ecdsa_verify_cmd
        PASS [  87.493s] caliptra-runtime::runtime_integration_tests integration_tests::test_error_cleared
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_fips_cmd_api
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_fw_info
        PASS [  87.533s] caliptra-runtime::runtime_integration_tests integration_tests::test_fips_cmd_api
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_fw_version
        PASS [  90.422s] caliptra-runtime::runtime_integration_tests integration_tests::test_fw_info
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_idev_id_cert
        PASS [  94.166s] caliptra-runtime::runtime_integration_tests integration_tests::test_fw_version
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_idev_id_info
        PASS [  94.228s] caliptra-runtime::runtime_integration_tests integration_tests::test_idev_id_cert
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_invoke_dpe_get_certificate_chain_cmd
        PASS [  93.339s] caliptra-runtime::runtime_integration_tests integration_tests::test_idev_id_info
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_invoke_dpe_get_profile_cmd
        PASS [  84.675s] caliptra-runtime::runtime_integration_tests integration_tests::test_invoke_dpe_get_certificate_chain_cmd
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_invoke_dpe_sign_and_certify_key_cmds
        PASS [  94.239s] caliptra-runtime::runtime_integration_tests integration_tests::test_invoke_dpe_get_profile_cmd
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_pauser_privilege_level_dpe_context_thresholds
        PASS [  93.917s] caliptra-runtime::runtime_integration_tests integration_tests::test_invoke_dpe_sign_and_certify_key_cmds
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_rt_cert_with_custom_dates
        PASS [  93.420s] caliptra-runtime::runtime_integration_tests integration_tests::test_pauser_privilege_level_dpe_context_thresholds
        PASS [  86.615s] caliptra-runtime::runtime_integration_tests integration_tests::test_rt_cert_with_custom_dates
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_standard
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_stash_measurement
        PASS [  86.659s] caliptra-runtime::runtime_integration_tests integration_tests::test_standard
        PASS [  86.096s] caliptra-runtime::runtime_integration_tests integration_tests::test_stash_measurement
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_unimplemented_cmds
        SLOW [> 60.000s] caliptra-runtime::runtime_integration_tests integration_tests::test_update
        PASS [  43.064s] caliptra-runtime::runtime_integration_tests test_panic_missing::test_panic_missing
        PASS [ 101.508s] caliptra-runtime::runtime_integration_tests integration_tests::test_unimplemented_cmds
        FAIL [ 107.993s] caliptra-runtime::runtime_integration_tests integration_tests::test_update

--- STDOUT:              caliptra-runtime::runtime_integration_tests integration_tests::test_update ---

running 1 test
test integration_tests::test_update has been running for over 60 seconds
          0 new_unbooted
          1 ready_for_fuses is high
          1 writing to cptra_bootfsm_go
         10 UART: 
         10 UART: Running Caliptra ROM ...
         11 UART: 
         11 UART: [state] CFI Enabled
         11 UART: [state] LifecycleState = Unprovisioned
         11 UART: [state] DebugLocked = No
         11 UART: [state] Watchdog Timer is not started because the device is not locked for debugging
         18 UART: ROM Digest: 1BB96CC8A1EAC40029BE7A2605928E2AD11ECF884FA882CE70AA59B0EE9417C1
         19 UART: [kat] ++
         19 UART: [kat] sha1
         19 UART: [kat] SHA2-256
         19 UART: [kat] SHA2-384
         19 UART: [kat] SHA2-384-ACC
         20 UART: [kat] ECC-384
        134 UART: [kat] HMAC-384
        134 UART: [kat] LMS
        185 UART: [kat] --
        186 UART: [cold-reset] ++
        186 UART: [fht] Storing FHT @ 0x50003400
        186 UART: [idev] ++
        186 UART: [idev] CDI.KEYID = 6
        186 UART: [idev] SUBJECT.KEYID = 7
        186 UART: [idev] UDS.KEYID = 0
        187 ready_for_fw is high
        187 <<< Executing mbox cmd 0x46574c44 (74004 bytes) from SoC
        192 UART: [idev] Erasing UDS.KEYID = 0
        355 UART: [idev] Using Sha1 for KeyId Algorithm
        356 UART: [idev] --
        356 UART: [ldev] ++
        356 UART: [ldev] CDI.KEYID = 6
        356 UART: [ldev] SUBJECT.KEYID = 5
        357 UART: [ldev] AUTHORITY.KEYID = 7
        357 UART: [ldev] FE.KEYID = 1
        357 UART: [ldev] Erasing FE.KEYID = 1
        521 UART: [ldev] Signing Cert with AUTHORITY.KEYID = 7
        636 UART: [ldev] PUB.X = 504D38CA45D997901F48BA333A149A2FB2668B973AAC64D3B79ECC09A663F02ED2FABA133F5FA499677AEB7687C99B25
        637 UART: [ldev] PUB.Y = A5CD31125698B3322C086E4398A591946BF20A3ECEA8EB7D7C23410D49FA877E7ECFBE47BD883BD53D7DA865AC217F1D
        638 UART: [ldev] SIG.R = F6A916F77E5B3B771E6C4E82926720B3E88C379D5634F7B02603253A3BFD2E5409A81AE94634387494009E5718A79FCA
        639 UART: [ldev] SIG.S = 605C11001E0624CA454FF5EF88D19D2919BB78E7B52A39E37573251E0212953D0327441F638BD2F2FAE80828B4FF4544
        640 UART: [ldev] --
        640 UART: [fwproc] Waiting for Commands...
        640 UART: [fwproc] Received command 0x46574c44
        640 UART: [fwproc] Received Image of size 74004 bytes
        816 UART: [fwproc] Image verified using Vendor ECC Key Index 0
        820 UART: [fwproc] Loading FMC at address 0x40000000 len 13020
        823 UART: [fwproc] Loading Runtime at address 0x40004000 len 55100
        833 >>> mbox cmd response: success
      1,172 <<< Executing mbox cmd 0x46574c44 (74004 bytes) from SoC
      1,177 UART: [afmc] ++
      1,177 UART: [afmc] CDI.KEYID = 6
      1,177 UART: [afmc] SUBJECT.KEYID = 7
      1,177 UART: [afmc] AUTHORITY.KEYID = 5
      1,177 UART: ROM Fatal Error: 0x00100001
      1,177 >>> mbox cmd response: failed
test integration_tests::test_update ... FAILED

failures:

failures:
    integration_tests::test_update

test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 22 filtered out; finished in 107.98s

--- STDERR:              caliptra-runtime::runtime_integration_tests integration_tests::test_update ---
warning: unknown feature specified for `-Ctarget-feature`: `unaligned-scalar-mem`
  |
  = note: it is still passed through to the codegen backend
  = help: consider filing a feature request

warning: unknown feature specified for `-Ctarget-feature`: `unaligned-scalar-mem`
  |
  = note: it is still passed through to the codegen backend
  = help: consider filing a feature request

warning: unknown feature specified for `-Ctarget-feature`: `unaligned-scalar-mem`
  |
  = note: it is still passed through to the codegen backend
  = help: consider filing a feature request

thread 'integration_tests::test_update' panicked at 'called `Result::unwrap()` on an `Err` value: MailboxCmdFailed(1048577)', runtime/tests/runtime_integration_tests/integration_tests.rs:78:10
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

------------
     Summary [ 504.465s] 23 tests run: 22 passed (20 slow), 1 failed, 0 skipped
        FAIL [ 107.993s] caliptra-runtime::runtime_integration_tests integration_tests::test_update
error: test run failed
zhalvorsen commented 1 year ago

test_update fixed with #972

jhand2 commented 1 year ago

Closing this issue since there are no failures on the latest FPGA run on Nightly Release: https://github.com/chipsalliance/caliptra-sw/actions/runs/6596754708/job/17923180848