Attention is currently required from: Bora Guvendik, Furquan Shaikh, Selma Bensaid, Tim Wawrzynczak, Angel Pons, Julius Werner, Aaron Durbin. Subrata Banik has posted comments on this change. ( https://review.coreboot.org/c/coreboot/+/51445 )
Change subject: timestamp: Add new helper functions ......................................................................
Patch Set 8:
(1 comment)
Commit Message:
https://review.coreboot.org/c/coreboot/+/51445/comment/032076ad_6c28fe35 PS3, Line 7: Add helper fucntions
Thanks Angel and Julius for your suggestion. I believe we all are in same page but we are using different notation to explain our understanding.
Let me put the question straight here:
if you take a look into below table, the timestamp ids are in serialized order where
944: CSE sent boot stall done to PMC is the first activity for CSE RO post coming out from reset. Followed by 945, 946 and finally 947 where CSE receives CPU reset ack from PMC and we are moving towards CPU coming out from resetYes, makes sense.
now if we subtract the CSE timestamp from base or `0` and the cbmem does its sorting, it breaks the pre-cpu reset order (as you can see below, 947 becoming the least negative number).
If I understand you correctly, does "least negative number" mean the same as "negative number with the smallest absolute value"? For example, the "least negative number" among { -6, -3, -4 } would be -3, right? Or am I misunderstanding you?
"negative number with the largest absolute value" i meant like in above example: `(-1,074,000)` "947:CSE received 'CPU Reset Done Ack sent' from PMC" is the least entry for cbmem table.
If my interpretation is correct, I don't see what the problem is. 947 is the last event that happened before the "1st timestamp", so it should be the "least negative number". AIUI, the result should be something like this:
944:CSE sent 'Boot Stall Done' to PMC -1,074,000 (18,483,711,496,695,957) 945:CSE started to handle ICC configuration -308,000 (18,483,711,496,697,957) 946:CSE sent 'Host BIOS Prep Done' to PMC -303,000 (18,483,711,495,936,957) 947:CSE received 'CPU Reset Done Ack sent' from PMC -296,000 0:1st timestamp 0
Here is the data that we have extracted from CSE and as per that data. 944: CSE sent 'Boot Stall Done' to PMC takes 296ms 945: CSE started to handle ICC configuration takes ~7ms 946: CSE sent 'Host BIOS Prep Done' to PMC takes ~5ms 947: CSE received 'CPU Reset Done Ack sent' from PMC takes ~766ms
hence, if we put those in order with assumption that while power-on the 1st time stamp is 0 then all above data appear as per below order:
0:1st timestamp 0 944:CSE sent 'Boot Stall Done' to PMC 296,000 945:CSE started to handle ICC configuration 303,000 (7,000) 946:CSE sent 'Host BIOS Prep Done' to PMC 308,000 (5,000) 947:CSE received 'CPU Reset Done Ack sent' from PMC 1,074,000 (766,000)
Now, after 1sec (1,074ms/1,074,000ns) post reset, CPU would come out from the reset. Consider timestamp id 11 as "Start of Bootblock" is first time stamp that comes coreboot bootblock takes ~27sec then now the entire table should look as below:
0:1st timestamp 0 944:CSE sent 'Boot Stall Done' to PMC 296,000 945:CSE started to handle ICC configuration 303,000 (7,000) 946:CSE sent 'Host BIOS Prep Done' to PMC 308,000 (5,000) 947:CSE received 'CPU Reset Done Ack sent' from PMC 1,074,000 (766,000) 11:start of bootblock 1,101,606 (27,606)
Do you agree with this ?
Having negative number is the calculation would look only perfect as @Bora has mentioned below, he need to perform an additional qsort to move "timestamp id: 947" elapse value into order rather appearing at the first entry which is not correct as per the CSE reset flow.
Hmmm, but timestamps currently use unsigned integers. I guess that's why the numbers in parentheses are so large, they underflow.
This is what my concern was about. I believe subtract is the final solution for simplicity but followed by sorting makes it weird as below.
0:1st timestamp 0 947:CSE received 'CPU Reset Done Ack sent' from PMC 1,074,000 946:CSE sent 'Host BIOS Prep Done' to PMC 308,000 (18,483,711,495,936,957) 945:CSE started to handle ICC configuration 303,000 (18,483,711,496,697,957) 944:CSE sent 'Boot Stall Done' to PMC 296,000 (18,483,711,496,695,957)
Yes, I agree this ordering looks very weird.