Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix #1815, add retroactive CFE status asserts #1816

Merged

Conversation

jphickey
Copy link
Contributor

@jphickey jphickey commented Aug 13, 2021

Describe the contribution
Add a set of macros that decouple the function call from the expected status:

  • CFE_Assert_STATUS_STORE
  • CFE_Assert_STATUS_MAY_BE
  • CFE_Assert_STATUS_MUST_BE

The first will make the function call and put the status into a temporary holding area, but will not assert on any particular
result.

The others will check the value of the holding area.

Fixes #1815

Testing performed
Build and run all tests
Also Add new test cases that need this paradigm and confirm macros working as expected (will be in other PRs).

Expected behavior changes
None, new test macros only, not used yet.

System(s) tested on
Ubuntu

Additional context
These macros should be used whenever a specific status is not predictable before the call, but other checks after the call can determine if the result was OK or not.

A typical use case for a function that might return any of 3 status values (e.g. status1, status2, status3) would be something like:

CFE_Assert_STATUS_STORE(...)
if (CFE_Assert_STATUS_MAY_BE(status1))
{
... do other checks after getting status1
}
else if (CFE_Assert_STATUS_MAY_BE(status1))
{
... do other checks after getting status2
}
else
{
   CFE_Assert_STATUS_MUST_BE(status3);
... do other checks after getting status3
}

Contributor Info - All information REQUIRED for consideration of pull request
Joseph Hickey, Vantage Systems, Inc.

@jphickey jphickey added the CCB:Ready Ready for discussion at the Configuration Control Board (CCB) label Aug 13, 2021
@jphickey jphickey requested a review from skliper August 13, 2021 17:50
Copy link
Contributor

@skliper skliper left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do the globals get cleared on a unit test reset? I'd think they should be (or at least clear StoredText so it won't warn)... I'm thinking the case where something isn't implemented and we just want to skip the rest of the test, but the next store shouldn't error since it was intended to skip.

@zanzaben
Copy link
Contributor

I don't think we need to give a warning at all about overriding the store.

@jphickey jphickey marked this pull request as draft August 16, 2021 15:06
@jphickey
Copy link
Contributor Author

Just had a new idea here, which may make this cleaner. The idea is to change "WAS" to be a soft fail - that is, it asserts with the NA case type, so you can do more than one test. Then we can also have a "MUSTBE" for a hard fail. This may make testcase code more readable.

@jphickey
Copy link
Contributor Author

Fairly trivial change to the macro/code makes the use case look like this:

        CFE_UtAssert_STATUS_STORE(CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName));
        /*
         * Normally, this will return CFE_SUCCESS, until the max number of pipes is reached.
         * Confirm that the last creation attempt returned CFE_SB_MAX_PIPES_MET
         *
         * NOTE: this also mimics the same format as UtAssert_INT32_EQ so that any post-procesing
         * test log analysis tools will see this call as well.
         */
        if (!CFE_UtAssert_STATUS_WAS(CFE_SUCCESS))
        {
            CFE_UtAssert_STATUS_MUSTBE(CFE_SB_MAX_PIPES_MET);
            break;
        }

And the output log looks like this:

[ PASS] 42.057 sb_pipe_mang_test.c:75 - CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName) (0) == CFE_SUCCESS (0)
[ PASS] 42.058 sb_pipe_mang_test.c:75 - CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName) (0) == CFE_SUCCESS (0)
[  N/A] 42.059 sb_pipe_mang_test.c:75 - CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName) (-905969660) == CFE_SUCCESS (0)
[ PASS] 42.060 sb_pipe_mang_test.c:75 - CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName) (-905969660) == CFE_SB_MAX_PIPES_MET (-905969660)
[ PASS] 42.061 sb_pipe_mang_test.c:100 - NumPipes (58) < CFE_PLATFORM_SB_MAX_PIPES (64)

@zanzaben
Copy link
Contributor

I think that makes this more complicated than it really needs to be. Also having an N/A without any kind of explanation why that test is no longer applicable would just be confusing.

@zanzaben
Copy link
Contributor

If you want to do more than one test on it why not just not clear out the store after a WAS is called. I don't think it's a problem if Store just overrides everytime.

@skliper
Copy link
Contributor

skliper commented Aug 16, 2021

Not convinced breaking the assert pattern for STATUS_WAS is worth the extra complexity (introducing the concept of soft fail). The test can store the status on the stack and do whatever logic you want.

Basically it feels like adding an assert to be able to control the flow where it's not really needed... it isn't asserting anything.

@jphickey
Copy link
Contributor Author

jphickey commented Aug 16, 2021

I dunno, focusing on the test case implementation, IMO this makes the code read like a book. Plain as day - No extra local variables, no checking for things that are already checked for.

CFE_UtAssert_STATUS_STORE(CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName));
if (!CFE_UtAssert_STATUS_WAS(CFE_SUCCESS))
{
    CFE_UtAssert_STATUS_MUSTBE(CFE_SB_MAX_PIPES_MET);
    break;
}

The whole point of all this is we have plenty of cases where testing cannot boil down to not "one right value" in our test code. That's just reality... In that sense, the UtAssert "pattern" is already broken (because they are written with the notion of one right value).

So yes, this is a "new" pattern - sort of. Because we've done one-off workarounds in a number of places already (and as such, not new). It's just a matter of how it was solved in the past and how we want to solve it going forward. Do we want lots of different ways of doing this type of thing, or do we want consistent patterns in the testing? That's really the choice here.

Whether we go with this suggestion or something different, we do need to establish a some sort of recommended pattern or at least a modicum of consistency when dealing with cases where the output of a function is permitted to be one of several different values. It isn't that rare in functional test. (at least not rare enough, IMO, to say "lets not bother with that" - in coverage test, sure - there should be only one right value - but in functional test with uncontrolled preconditions - not so much).

@jphickey
Copy link
Contributor Author

jphickey commented Aug 16, 2021

My concern with the original form is that it's a little goofy to use in the test case code, typically asserting on something you just checked, in order to get the logs complete. Take the CDS use case - with the original proposal, it would go something like this:

    status = CFE_UtAssert_STATUS_STORE(CFE_ES_RegisterCDS(&CDSHandlePtr, BlockSize, Name));

    if (status == CFE_ES_CDS_ALREADY_EXISTS)
    {
        CFE_UtAssert_STATUS_WAS(CFE_ES_CDS_ALREADY_EXISTS);
        UtAssert_NA("CDS already exists. CFE_ES_RegisterCDS new allocation could not be properly tested");
    }
    else
    {
        CFE_UtAssert_STATUS_WAS(CFE_SUCCESS);
    }

The fact that we checked for CFE_ES_CDS_ALREADY_EXISTS and then asserted for the same is a little ... odd? It works, though (the goal being to record in the log file that we called CFE_ES_RegisterCDS with those parameters and got CFE_ES_CDS_ALREADY_EXISTS back).

Again, the whole impetus of this, is to get some improvement and consistency in what goes into the test log file. With test cases handling each exception like this in a one-off manner, there is no consistency in either implementation or what gets logged (making tracing more difficult - we have to go back to the source code to see what "status == CFE_SUCCESS" meant here).

The macros are intended to improve the accuracy of the log file - to more fully capture what was called and what was returned. No earth-shattering new assert capabilities, just a better log file at the end of the day.

@skliper
Copy link
Contributor

skliper commented Aug 16, 2021

I do like the STORE and WAS asserts as they relate to the logs (with WAS being a hard assert). I don't see the added value of having a soft fail w/ an NA in the log, it seems more straight forward to me to keep it focused on actual asserts. Or use a completely different prefix since it's not really an assert in the classical sense (at least not how I currently understand the proposed pattern) and I'd prefer it be very obvious and hard to get wrong... if you really want logic flow sort of messages in the log. UtBranch/UtFlow/UtPath or similar, and could have it as another stage of reporting (or just make them debug) where it's optional if you want?

@jphickey
Copy link
Contributor Author

And in the form I'm proposing today, the same CDS use case would look something like:

    CFE_UtAssert_STATUS_STORE(CFE_ES_RegisterCDS(&CDSHandlePtr, BlockSize, Name));

    if (CFE_UtAssert_STATUS_WAS(CFE_ES_CDS_ALREADY_EXISTS))
    {
        UtAssert_NA("CDS already exists. CFE_ES_RegisterCDS new allocation could not be properly tested");
    }
    else
    {
        CFE_UtAssert_STATUS_MUSTBE(CFE_SUCCESS);
    }

No extra local status or local checks, no double-checking. Reads clean, which I like - very clear what's going on here!

@skliper
Copy link
Contributor

skliper commented Aug 16, 2021

CFE_UtFlow_STATUS_CHECK(blah) and keep CFE_UtAssert_STATUS_WAS as a hard assert? STATUS_CHECK could just be debug info, or a step below the PASS/FAIL.

@jphickey
Copy link
Contributor Author

The value of "soft fail with NA" is that it's a casetype we already have, and requires absolutely no updates to the UtAssert library. Yes, it is a stretch from the original intent of NA, and we could consider using a different name, but for the proof of concept, it fit what was needed to make a check that doesn't fail the test.

The extra "N/A" line in the log is a valid concern, but I don't think its wrong to have it in there:

[ N/A] 42.059 sb_pipe_mang_test.c:75 - CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName) (-905969660) == CFE_SUCCESS (0)

It's the truth, anyway - the test case DID check for it. I concur its probably not much value to the end user, but to squelch it would require an update to UtAssert (I think) to differentiate from the cases you do want to see - so that's where IMO it's better to leave it as is. More info in logs is OK (ignore the extra), but too little is bad.

@zanzaben
Copy link
Contributor

I get it now, you are using CFE_UtAssert_STATUS_WAS as a getter that makes a record in the log. That idea is fine but I agree with skilper on the name change since this isn't a assert anymore. I also think that it should be an [info] event in the log instead of an [n/a].

@skliper
Copy link
Contributor

skliper commented Aug 16, 2021

My concern with the original form is that it's a little goofy to use in the test case code, typically asserting on something you just checked, in order to get the logs complete. Take the CDS use case - with the original proposal, it would go something like this:

Sorry, reading out of order. So I think the example you had in this case is definitely goofy, but only because you are asserting something you weren't actually originally testing for. Keep that specific test related to creating new, and the assert for already existing should be separate. You have to do it if it is new, so why try to double up the purpose of the first test?

At minimum change the prefix... I don't care all that much about reporting, NA is fine but it needs to be clear it's not a PASS/FAIL assert.

@skliper
Copy link
Contributor

skliper commented Aug 16, 2021

In other words, I see:

    status = CFE_UtAssert_STATUS_STORE(CFE_ES_RegisterCDS(&CDSHandlePtr, BlockSize, Name));

    if (status == CFE_ES_CDS_ALREADY_EXISTS)
    {
         UtAssert_NA("CDS already exists. CFE_ES_RegisterCDS new allocation could not be properly tested");
    }
    else
    {
        CFE_UtAssert_STATUS_WAS(CFE_SUCCESS);
    }

as being plenty good. Sure it doesn't put the non-assert flow info in there, but it's really obvious in the log what it did...

@jphickey
Copy link
Contributor Author

jphickey commented Aug 16, 2021

as being plenty good. Sure it doesn't put the non-assert flow info in there, but it's really obvious in the log what it did...

To a human reader, maybe ... They'll see the string "CDS already exists. CFE_ES_RegisterCDS new allocation could not be properly tested" ... one has to go back to the code and see that it was from a call to CFE_ES_RegisterCDS(), with three valid input arguments, returning CFE_ES_CDS_ALREADY_EXISTS. My point is, that latter info should really be in the log too - like we log everything else that we call and returns a value, we should log the fact that we called CFE_ES_RegisterCDS(&CDSHandlePtr, BlockSize, Name) and we got CFE_ES_CDS_ALREADY_EXISTS back, just like we log every other function call that way. It's just as valid/important to know as the CFE_SUCCESS case was. That's missing from the current code.

@jphickey
Copy link
Contributor Author

Also, I read the prefix a little differently. Per coding standards/naming conventions, all macros/constants/functions defined by a module should be prefixed with the name of that module. That's what the CFE_UtAssert_ prefix is here - they are from the cfe_assert library (probably my mistake that "ut" was initally missed/added here, could always correct that too, we could change prefix across the board to "CFE_Assert" instead of "CFE_UtAssert" - that would better adhere to convention).

The point is, that prefix is not to say that everything makes some sort of "assert" in the log - far from it, the library has plenty of helper functions that are also prefixed with _CFE_RegisterTest, CFE_Assert_LibInit, and on. Just because it starts with "CFE_Assert" does not mean it triggers an assert in the log.

@jphickey
Copy link
Contributor Author

Latest update does the following:

  • Use CFE_Assert_ prefix on new macros instead of CFE_UtAssert_
  • Use names CFE_Assert_STATUS_MAY_BE and CFE_Assert_STATUS_MUST_BE which hopefully makes the intent clearer. The former checks for a passable/acceptable result but does not fail if it does not match. The latter is more of a conventional assert, but would be the last thing used - the test implementer can use MAY_BE first to skip over the MUST_BE check.

@jphickey
Copy link
Contributor Author

The base branch does not yet include a test for create pipe max number, but that test now looks like this:

        CFE_Assert_STATUS_STORE(CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName));
        if (CFE_Assert_STATUS_MAY_BE(CFE_SB_MAX_PIPES_MET))
        {
            break;
        }

        CFE_Assert_STATUS_MUST_BE(CFE_SUCCESS);

@zanzaben
Copy link
Contributor

Heads up, this will have conflicts with #1785

@jphickey
Copy link
Contributor Author

jphickey commented Aug 17, 2021

Note, see also nasa/osal#1131 - adding a couple new case types to OSAL allows us to better capture the nuanced differences between these N/A cases. With that, we relegate these new "MAY_BE" messages to the debug level if they don't match, which cleans up the log nicely. In my own test branch (including nasa/osal#1131) the logs now look like this.

For CDS normal startup (PO):

[ INFO] es_cds_test.c:45:Testing: CFE_ES_RegisterCDS
[ PASS] 02.002 es_cds_test.c:55 - CFE_ES_RegisterCDS(&CDSHandlePtr, BlockSize, Name) (0) == CFE_SUCCESS (0)
[ PASS] 02.003 es_cds_test.c:75 - CFE_ES_RegisterCDS(&CDSHandlePtr2, BlockSize, Name) (1140850701) == CFE_ES_CDS_ALREADY_EXISTS (1140850701)
[ PASS] 02.004 es_cds_test.c:78 - CFE_ES_RegisterCDS(NULL, BlockSize, Name) (-1006632950) == CFE_ES_BAD_ARGUMENT (-1006632950)

For CDS already exists startup (PR):

[ INFO] es_cds_test.c:45:Testing: CFE_ES_RegisterCDS
[ PASS] 02.001 es_cds_test.c:55 - CFE_ES_RegisterCDS(&CDSHandlePtr, BlockSize, Name) (1140850701) == CFE_ES_CDS_ALREADY_EXISTS (1140850701)
[ SKIP] 02.002 es_cds_test.c:64 - CDS already exists. CFE_ES_RegisterCDS new allocation could not be properly tested
[ PASS] 02.003 es_cds_test.c:78 - CFE_ES_RegisterCDS(NULL, BlockSize, Name) (-1006632950) == CFE_ES_BAD_ARGUMENT (-1006632950)

And finally, the CreatePipe max test (all other "max" tests would be similar):

[ PASS] 42.116 sb_pipe_mang_test.c:75 - CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName) (0) == CFE_SUCCESS (0)
[ PASS] 42.117 sb_pipe_mang_test.c:75 - CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName) (-905969660) == CFE_SB_MAX_PIPES_MET (-905969660)
[ PASS] 42.118 sb_pipe_mang_test.c:95 - NumPipes (58) < CFE_PLATFORM_SB_MAX_PIPES (64)
[ PASS] 42.119 sb_pipe_mang_test.c:101 - CFE_SB_DeletePipe(PipeId[NumPipes]) (0) == CFE_SUCCESS (0)

@jphickey jphickey force-pushed the fix-1815-utassert-retroactive branch 2 times, most recently from 1406779 to 20b9dd9 Compare August 17, 2021 20:06
@jphickey jphickey marked this pull request as ready for review August 17, 2021 20:13
@astrogeco astrogeco removed the CCB:Ready Ready for discussion at the Configuration Control Board (CCB) label Aug 18, 2021
@astrogeco
Copy link
Contributor

CCB:2021-08-18 APPROVED

@astrogeco astrogeco added the CCB:Approved Indicates code review and approval by community CCB label Aug 18, 2021
@jphickey jphickey force-pushed the fix-1815-utassert-retroactive branch from 286c76e to fdeac78 Compare August 18, 2021 17:51
@jphickey
Copy link
Contributor Author

Latest proposal just uses a case type of "FLOW" (see latest updates in nasa/osal#1131)

Here is what a "Nominal" CDS test run looks like in the log (PO reset, CDS does not exist, default log level):

[ INFO] es_cds_test.c:46:Testing: CFE_ES_RegisterCDS
[ PASS] 04.002 es_cds_test.c:56 - CFE_ES_RegisterCDS(&CDSHandlePtr, BlockSize2, Name) (0) == CFE_SUCCESS (0) -> match
[ PASS] 04.003 es_cds_test.c:76 - CFE_ES_RegisterCDS(&CDSHandlePtr2, BlockSize2, Name) (1140850701) == CFE_ES_CDS_ALREADY_EXISTS (1140850701)
[ PASS] 04.004 es_cds_test.c:79 - CFE_ES_RegisterCDS(&CDSHandlePtr2, BlockSize, Name) (0) == CFE_SUCCESS (0)

Here is what a "Verbose" CDS test run looks like:

[ INFO] es_cds_test.c:46:Testing: CFE_ES_RegisterCDS
[ FLOW] 04.001 es_cds_test.c:56 - CFE_ES_RegisterCDS(&CDSHandlePtr, BlockSize2, Name) (0) == CFE_ES_CDS_ALREADY_EXISTS (1140850701) -> not match
[ PASS] 04.002 es_cds_test.c:56 - CFE_ES_RegisterCDS(&CDSHandlePtr, BlockSize2, Name) (0) == CFE_SUCCESS (0) -> match
[ PASS] 04.003 es_cds_test.c:76 - CFE_ES_RegisterCDS(&CDSHandlePtr2, BlockSize2, Name) (1140850701) == CFE_ES_CDS_ALREADY_EXISTS (1140850701)

And for another example, here is what the "Max Gen Counters" test case looks like in default log level:

[ INFO] es_counter_test.c:42:Testing: CFE_ES_RegisterGenCounter
[ PASS] 07.001 es_counter_test.c:47 - CFE_ES_RegisterGenCounter(&Ids[0], NULL) (-1006632950) == CFE_ES_BAD_ARGUMENT (-1006632950)
[ PASS] 07.002 es_counter_test.c:48 - CFE_ES_RegisterGenCounter(NULL, CounterName) (-1006632950) == CFE_ES_BAD_ARGUMENT (-1006632950)
[ PASS] 07.004 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ PASS] 07.006 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ PASS] 07.008 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ PASS] 07.010 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ PASS] 07.012 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ PASS] 07.014 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ PASS] 07.016 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ PASS] 07.017 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (-1006632917) == CFE_ES_NO_RESOURCE_IDS_AVAILABLE (-1006632917) -> match
[ PASS] 07.018 es_counter_test.c:70 - NumCounters (7) <= CFE_PLATFORM_ES_MAX_GEN_COUNTERS (8)

And here is what the same run looks like with "verbose" log level:

[ INFO] es_counter_test.c:42:Testing: CFE_ES_RegisterGenCounter
[ PASS] 07.001 es_counter_test.c:47 - CFE_ES_RegisterGenCounter(&Ids[0], NULL) (-1006632950) == CFE_ES_BAD_ARGUMENT (-1006632950)
[ PASS] 07.002 es_counter_test.c:48 - CFE_ES_RegisterGenCounter(NULL, CounterName) (-1006632950) == CFE_ES_BAD_ARGUMENT (-1006632950)
[ FLOW] 07.003 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_ES_NO_RESOURCE_IDS_AVAILABLE (-1006632917) -> not match
[ PASS] 07.004 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ FLOW] 07.005 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_ES_NO_RESOURCE_IDS_AVAILABLE (-1006632917) -> not match
[ PASS] 07.006 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ FLOW] 07.007 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_ES_NO_RESOURCE_IDS_AVAILABLE (-1006632917) -> not match
[ PASS] 07.008 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ FLOW] 07.009 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_ES_NO_RESOURCE_IDS_AVAILABLE (-1006632917) -> not match
[ PASS] 07.010 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ FLOW] 07.011 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_ES_NO_RESOURCE_IDS_AVAILABLE (-1006632917) -> not match
[ PASS] 07.012 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ FLOW] 07.013 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_ES_NO_RESOURCE_IDS_AVAILABLE (-1006632917) -> not match
[ PASS] 07.014 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ FLOW] 07.015 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_ES_NO_RESOURCE_IDS_AVAILABLE (-1006632917) -> not match
[ PASS] 07.016 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (0) == CFE_SUCCESS (0) -> match
[ PASS] 07.017 es_counter_test.c:57 - CFE_ES_RegisterGenCounter(&Ids[NumCounters], CounterName) (-1006632917) == CFE_ES_NO_RESOURCE_IDS_AVAILABLE (-1006632917) -> match
[ PASS] 07.018 es_counter_test.c:70 - NumCounters (7) <= CFE_PLATFORM_ES_MAX_GEN_COUNTERS (8)

@jphickey
Copy link
Contributor Author

Note that the "special sauce" of including an extra match/not match tag at the end is done inside the implementation of CFE_Assert_STATUS_MAY_BE -- since this is where we know that the condition is actually describing a boolean expression. At the UtAssert level (i.e. UtAssert_Message), its just a generic informational message.

@jphickey
Copy link
Contributor Author

IMO, its kinda redundant, because the raw info (numbers) are already there, you can already see its not a match. But if this helps, I'm OK with it.

@zanzaben
Copy link
Contributor

Is CFE_Assert_STATUS_MUST_BE also adding that match/not match text. I don't think it should be since it is a hard pass or fail test.

@skliper
Copy link
Contributor

skliper commented Aug 18, 2021

Any method you want to report in the log what the test thinks the result is works for me, I think the implementation in the macro is ideal. You could even change it to just show != within the FLOW case type and drop the match/not match.

@skliper
Copy link
Contributor

skliper commented Aug 18, 2021

To me then it would basically read as for the MAY_BE test it was either PASS based on the result in the text or was FLOW based on the result shown in the text. Makes it really clear it's a non-failure and just a decision point. But really I'm fine with it as-is also since it meets my desired criteria... just brainstorming.

@skliper
Copy link
Contributor

skliper commented Aug 18, 2021

IMO, its kinda redundant, because the raw info (numbers) are already there, you can already see its not a match. But if this helps, I'm OK with it.

This really does help me. I very much struggle with comparing -1021399484 with -1021399484 with -1021394984 quickly and benefit greatly from knowing what the code thought the result was. Somewhat trivial here (although I honestly do still struggle w/ this simple example and have to study it for quite a while before I'm really sure), but string comparisons if we eventually support those in a soft test are much harder to spot quickly.

@jphickey jphickey force-pushed the fix-1815-utassert-retroactive branch from fdeac78 to 621cc35 Compare August 18, 2021 20:38
@jphickey
Copy link
Contributor Author

OK - the latest update squashes all the activity, along with the following cleanup:

  • use "==" and "!=" rather than an extra match / no match tag (should be clear enough)
  • Use the "UtAssert_GetCaseTypeAbbrev" function rather than duplicating the case type switch

Should be good to go, however this depends on nasa/osal#1131 (this is why the CI is failing build, as soon as OSAL is merged should be able to re-run and pass).

@jphickey jphickey requested a review from skliper August 18, 2021 20:49
@jphickey
Copy link
Contributor Author

OK, the only downside/weirdness that I can see is that when a case of CFE_Assert_STATUS_MUST_BE fails, it goes through the same helper function, and also inverts the condition in the string (match/no match did not suffer from this issue).

Example, I hacked the CreatePipe max test to force a failure - basically to check MUST_BE(CFE_STATUS_EXTERNAL_RESOURCE_FAIL) instead of MUST_BE(CFE_SUCCESS) and this is what the failure line looks like:

[ INFO] sb_pipe_mang_test.c:62:Testing: CFE_SB_CreatePipe, maximum pipe limit
[ FLOW] 52.001 sb_pipe_mang_test.c:75 - CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName) (0) != CFE_SB_MAX_PIPES_MET (-905969660)
[ FAIL] 52.002 sb_pipe_mang_test.c:75 - CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName) (0) != CFE_STATUS_EXTERNAL_RESOURCE_FAIL (-939524091)

@jphickey
Copy link
Contributor Author

To clarify - match/no match was still added/printed in the MUST_BE case, it just made a little more sense than switching to != in this context

Add a set of macros that decouple the function call from the
expected status:

- CFE_UtAssert_STATUS_STORE
- CFE_UtAssert_STATUS_MAY_BE
- CFE_UtAssert_STATUS_MUST_BE

The first will make the function call and put the status into
a temporary holding area, but will not assert on any particular
result.

The may/must macros then check the value of the holding area.
@jphickey jphickey force-pushed the fix-1815-utassert-retroactive branch from 621cc35 to 52f77e3 Compare August 19, 2021 15:08
@jphickey
Copy link
Contributor Author

Updated again to change the != back to an extra [false] tag at the end of the line. The trace now looks like this:

[ INFO] sb_pipe_mang_test.c:62:Testing: CFE_SB_CreatePipe, maximum pipe limit
[ FLOW] 52.001 sb_pipe_mang_test.c:75 - CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName) (0) == CFE_SB_MAX_PIPES_MET (-905969660) [false]
[ FAIL] 52.002 sb_pipe_mang_test.c:75 - CFE_SB_CreatePipe(&PipeId[NumPipes], 10, PipeName) (0) == CFE_STATUS_EXTERNAL_RESOURCE_FAIL (-939524091) [false]

I like this better because we are being accurate about the actual condition that was checked for in all cases, but it still should be clear if that had evaluated as false. Note that I did not add a corresponding [true] tag, since most statements should be true, this keeps the [PASS] messages consistent with other pass messages.

Copy link
Contributor

@skliper skliper left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good to me, I would like to consider the additional [false] marker for the other macros under our control for consistency (fine as a separate/future issue).

@jphickey
Copy link
Contributor Author

Note - the build failure currently reported from CI is fixed by nasa/osal#1131 - currently in IC - so if this gets merged (or if we just finish the OSAL merge) this should work OK.

I'd like to get this merged in the build before the new RC tag is created, if possible.

@astrogeco astrogeco merged commit 1a29d37 into nasa:integration-candidate Aug 20, 2021
astrogeco added a commit to nasa/cFS that referenced this pull request Aug 20, 2021
astrogeco added a commit to nasa/cFS that referenced this pull request Aug 21, 2021
**Combines**

nasa/cFE# v6.8.0-rc1+dev933
nasa/osal# v5.1.0-rc1+dev594

**Includes**

*osal*

nasa/osal#1131, add test case types similar to NA

*cFE*

nasa/cFE#1803, Add software bus tests
nasa/cFE#1756, separate variable for OSAL status
nasa/cFE#1809, increase SB pool max size bucket
nasa/cFE#1842, Add Null check for CFE_ResourceId_FindNext
nasa/cFE#1828, Improve TBL coverage tests
nasa/cFE#1833, Clean up Message ID Functional Test #1824, Add missing cases for msg id func tests
nasa/cFE#1832, Combine SB Set/Get message characteristics group #1831, Consolidate msg get/set doxygen group
nasa/cFE#1836, Adding coverage tests to cFE TIME
nasa/cFE#1848, enable strict resource id w/OMIT_DEPRECATED
nasa/cFE#1845, HOTFIX IC-20210819, type correction TBL coverage test
nasa/cFE#1806, Add test for ES BackgroundWakeup
nasa/cFE#1813, Success Test for CFE_ES_RestartApp
nasa/cFE#1814, Subscribe to Message Limit Greater Than CFE_PLATFORM_SB_DEFAULT_MSG_LIMIT
nasa/cFE#1811, Success Test for CFE_ES_GetMemPoolStats
nasa/cFE#1822, Group MSG APIs documentation by header type
nasa/cFE#1816, add retroactive CFE status asserts
nasa/cFE#1854, remove unused CFE_TBL_ERR_BAD_APP_ID
nasa/cFE#1855, correct syslog message in pool create
nasa/cFE#1853, remove unused CFE_ES_POOL_BOUNDS_ERROR
nasa/cFE#1859, remove unused CFE_TBL_ERR_FILE_NOT_FOUND
nasa/cFE#1856, Check error ctr to TransmitMsg test
nasa/cFE#1857, End Child Task requirement remove error code
nasa/cFE#1782, Add functional tests for resource misc

Co-authored-by: Jacob Hageman           <skliper@users.noreply.github.com>
Co-authored-by: Joseph Hickey           <jphickey@users.noreply.github.com>
Co-authored-by: Alex Campbell           <zanzaben@users.noreply.github.com>
Co-authored-by: Niall Mullane           <nmullane@users.noreply.github.com>
Co-authored-by: Ariel Adams             <ArielSAdamsNASA@users.noreply.github.com>
Co-authored-by: Jose F Martinez Pedraza <pepepr08@users.noreply.github.com>
@jphickey jphickey deleted the fix-1815-utassert-retroactive branch August 23, 2021 17:55
@skliper skliper added this to the 7.0.0 milestone Sep 24, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
CCB:Approved Indicates code review and approval by community CCB
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants