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 failure: test_fmcalias_derivation::test_pcr_log_across_update_reset #786

Closed korran closed 1 year ago

korran commented 1 year ago 
      6,338 <<< Executing mbox cmd 0x46574c44 (60612 bytes) from SoC
test test_pcr_log_across_update_reset has been running for over 60 seconds
    195,164 UART: 
    195,202 UART: Running Caliptra ROM ...
    196,178 UART: 
    205,444 UART: [state] CFI Enabled
    207,152 UART: [state] LifecycleState = Unprovisioned
    208,741 UART: [state] DebugLocked = No
    210,137 UART: [state] Watchdog Timer is not started because the device is not locked for debugging
    357,161 UART: ROM Digest: 11BC274A06B0086E7A15BE8553A83D8F7643D7BD1E82B02C05166D41C5E3A896
    367,411 UART: [kat] ++
    367,791 UART: [kat] sha1
    377,057 UART: [kat] SHA2-256
    379,713 UART: [kat] SHA2-384
    383,410 UART: [kat] SHA2-384-ACC
    385,449 UART: [kat] ECC-384
  3,954,255 UART: [kat] HMAC-384
  3,963,914 UART: [kat] LMS
  5,034,994 UART: [kat] --
  5,038,077 UART: [cold-reset] ++
  5,039,798 UART: [idev] ++
  5,040,218 UART: [idev] CDI.KEYID = 6
  5,041,094 UART: [idev] SUBJECT.KEYID = 7
  5,042,134 UART: [idev] UDS.KEYID = 0
  5,054,872 UART: [idev] Erasing UDS.KEYID = 0
  8,317,846 UART: [idev] Using Sha1 for KeyId Algorithm
  8,338,950 UART: [idev] --
  8,342,279 UART: [ldev] ++
  8,342,685 UART: [ldev] CDI.KEYID = 6
  8,343,577 UART: [ldev] SUBJECT.KEYID = 5
  8,344,619 UART: [ldev] AUTHORITY.KEYID = 7
  8,345,737 UART: [ldev] FE.KEYID = 1
  8,356,139 UART: [ldev] Erasing FE.KEYID = 1
 11,636,329 UART: [ldev] Signing Cert with AUTHORITY.KEYID = 7
 15,226,878 UART: [ldev] PUB.X = 504D38CA45D997901F48BA333A149A2FB2668B973AAC64D3B79ECC09A663F02ED2FABA133F5FA499677AEB7687C99B25
 15,241,224 UART: [ldev] PUB.Y = A5CD31125698B3322C086E4398A591946BF20A3ECEA8EB7D7C23410D49FA877E7ECFBE47BD883BD53D7DA865AC217F1D
 15,255,906 UART: [ldev] SIG.R = 14B5D494DF875AC7CEE9FE3E9A6168A6B64BFB01171F5ECC5216C8BB945FAF957CED1BE6C7CFBB1DDB2B7F4BFD76A492
 15,270,390 UART: [ldev] SIG.S = 821D8CC92F40AFF934771D7652C9BC3C59D47E5635E110A8486B76F7433B02B3C6B0FD8B1B6548B5994C481547111FC5
 15,291,023 UART: [ldev] --
 15,298,009 UART: [afmc] Waiting for Commands...
 15,305,576 UART: 
 15,305,652 UART: [afmc] Received Image of size 60612 bytes
 17,989,198 UART: [afmc] Image verified using Vendor ECC Key Index 1
 18,144,177 UART: [afmc] Loading FMC at address 0x40000000 len 9964
 18,181,693 UART: [afmc] Loading Runtime at address 0x40004000 len 44764
 18,342,976 >>> mbox cmd response: success
 18,347,393 UART: [afmc] ++
 18,347,814 UART: [afmc] CDI.KEYID = 6
 18,348,689 UART: [afmc] SUBJECT.KEYID = 7
 18,349,729 UART: [afmc] AUTHORITY.KEYID = 5
 21,657,800 UART: [afmc] Signing Cert with AUTHORITY.KEYID = 5
 23,948,896 UART: [afmc] Erasing AUTHORITY.KEYID = 5
 25,253,900 UART: [afmc] PUB.X = 67266E58C08993FAA9AEAB115213495BE049EC4430351B2F7E6F67B1CDB330E558A932B701115FA1B98A78C3255BB26E
 25,268,244 UART: [afmc] PUB.Y = 1B0A0A843E94325EF2F51DBDDEADB313A9446A51FEEDF73EC3D153EFDDBD33E86968C3DEF1483A546A26E382D33E976B
 25,282,978 UART: [afmc] SIG.R = B8E4219A8132EBDA684858F01C4DDD808C8DC79071D2395379C827D2CD7B5951B01AE91025928A464FBEEDCA0033ECF2
 25,297,286 UART: [afmc] SIG.S = 1CBDE2A2DFDA22A6B07E770C2D652B06D500CA4ADE5FB09B98EBB6BAE5B1B24D4C962477F055FDE477DBFA3AC6F073DB
 25,322,171 UART: [afmc] --
 25,327,211 <<< Executing mbox cmd 0x10000000 (0 bytes) from SoC
 25,327,255 UART: [cold-reset] --
 25,334,625 UART: [fht] Storing FHT @ 0x50003000
 25,340,046 UART: [state] Watchdog Timer is not stopped because the device is not locked for debugging
 25,346,518 UART: [state] Locking Datavault
 25,351,960 UART: [state] Locking PCR0, PCR1 and PCR31
 25,353,406 UART: [state] Locking ICCM
 25,355,675 UART: [exit] Launching FMC @ 0x40000000
 25,363,859 UART: 
 25,363,889 UART: Running Caliptra FMC ...
 25,364,645 UART: 
 25,364,865 UART: [fmc] Received command: 0x10000000
 25,370,285 >>> mbox cmd response data (616 bytes)
 25,370,637 <<< Executing mbox cmd 0x10000006 (0 bytes) from SoC
 25,370,694 UART: [fmc] Received command: 0x10000006
 25,391,899 >>> mbox cmd response data (1536 bytes)
 25,392,763 <<< Executing mbox cmd 0x10000004 (0 bytes) from SoC
 25,392,823 UART: [fmc] Received command: 0x10000004
 25,393,911 >>> mbox cmd response: success
 25,394,256 UART: 
 25,394,294 UART: Running Caliptra ROM ...
 25,395,270 UART: 
 25,396,179 UART: [state] CFI Enabled
 25,397,873 UART: [state] LifecycleState = Unprovisioned
 25,399,462 UART: [state] DebugLocked = No
 25,401,797 UART: [state] Watchdog Timer is not started because the device is not locked for debugging
 25,549,577 UART: ROM Digest: 11BC274A06B0086E7A15BE8553A83D8F7643D7BD1E82B02C05166D41C5E3A896
 25,559,855 UART: [kat] ++
 25,560,235 UART: [kat] sha1
 25,569,491 UART: [kat] SHA2-256
 25,572,147 UART: [kat] SHA2-384
 25,575,830 UART: [kat] SHA2-384-ACC
 25,577,865 UART: [kat] ECC-384
 29,146,549 UART: [kat] HMAC-384
 29,156,185 UART: [kat] LMS
 30,227,279 UART: [kat] --
 30,230,269 UART: [update-reset] ++
 30,230,956 <<< Executing mbox cmd 0x46574c44 (60612 bytes) from SoC
 30,231,032 UART: Failed To Get Mailbox Transaction
 30,233,714 UART: ROM Non-Fatal Error: 0x01040004
 30,236,418 UART: [state] Watchdog Timer is not stopped because the device is not locked for debugging
 30,241,210 UART: [state] Locking Datavault
 30,243,673 UART: [state] Locking PCR0, PCR1 and PCR31
 30,245,119 UART: [state] Locking ICCM
 30,247,906 UART: [exit] Launching FMC @ 0x40000000
 30,256,188 UART: 
 30,256,218 UART: Running Caliptra FMC ...
 30,256,977 UART: 
 30,264,430 UART: [fmc] Received command: 0x46574C44
 30,265,572 UART: [fmc] Received command: 0x46574C44
 30,266,684 UART: [fmc] Received command: 0x46574C44
 30,267,792 UART: [fmc] Received command: 0x46574C44
 30,268,899 UART: [fmc] Received command: 0x46574C44
 30,270,005 UART: [fmc] Received command: 0x46574C44
 30,271,110 UART: [fmc] Received command: 0x46574C44
 30,272,215 UART: [fmc] Received command: 0x46574C44
 30,273,321 UART: [fmc] Received command: 0x46574C44
 30,274,426 UART: [fmc] Received command: 0x46574C44
 30,275,531 UART: [fmc] Received command: 0x46574C44
 30,276,636 UART: [fmc] Received command: 0x46574C44
 30,277,742 UART: [fmc] Received command: 0x46574C44
 30,278,847 UART: [fmc] Received command: 0x46574C44
<snip> repeating last line for 100M clock cycles
korran commented 1 year ago

Passed in most recent nightly verilator run. Fixed by #792 

19431:2023-09-19T09:41:18.3491671Z         PASS [31625.669s] caliptra-rom::test_fmcalias_derivation test_pcr_log_across_update_reset