zighouse / doubango

Automatically exported from code.google.com/p/doubango
0 stars 0 forks source link

SigComp manager test gets caught in infinite loop #189

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago
What steps will reproduce the problem?
1.See additional information below
2.
3.

What is the expected output? What do you see instead?
See additional information below

What version of the product are you using? On what operating system?
Latest 2.0 branch; Windows 7 64-bit

Please provide any additional information below.

I noticed that the Doubango SigComp Manager tests (compiled by me) end up in an 
endless loop.  I spent some time looking into this and think the problem 
relates to the NACK not being processed correctly.  However the issue could 
like in the compression of the message or the formulation of the NACK.

I noticed that the decompress of the NACK resulted in no decompressed message 
output.  Is this correct?  Typically, on decompression, an output message 
length greater than 0 is deemed successful.

I added the following line to test_manager.h to see what the absolute numbers 
were for message size before and after compression

TSK_DEBUG_INFO("==INVITE compression ratio (msg size: %d, compressed size: %d)= 
%f%%==", tsk_strlen(SIGCOMP_MSG_INVITE), outLen, 
((float)tsk_strlen(SIGCOMP_MSG_INVITE) / (float)outLen) * 100.f);

This gave the following on the cycles through test_manager() for loop
Loop 1     *INFO: ==INVITE compression ratio (msg size: 1951, compressed size: 
783)= 249.169860%==
Loop 2     *INFO: ==INVITE compression ratio (msg size: 1951, compressed size: 
43)= 4537.209302%==

It is in the second loop that the compression to 43 bytes results in a 
decompression failure by the ‘server’.  The handle_nack routine 
communicates the nack to the ‘client’; it is the processing of the NACK 
that appears to fail resulting in the same highly compressed message being sent 
again and so on.

In tcomp_statehandler_handleNack the nackinfo->reasonCode is 1 (the same as 
NACK_STATE_NOT_FOUND) however the boolean test of 
‘tcomp_compartment_hasNack(lpCompartement, &sha_id)’ does not return true 
for any of the items in the list.  This results in no action being taken based 
on the NACK and then the test routine ends up in an endless cycle of 
compressing the INVITE, cannot decompress, fail to process NACK etc.

Below is the test output and some extracts of relevant code.

Doubango output

*INFO: Compressing stateless message.
*INFO: ==REGISTER compression ratio = 91.129032%==
*INFO: SigComp - Creating stateless message.
*INFO: SigComp - Add new state.
*INFO: Compressing stateless message.
*INFO: ==200 REGISTER compression ratio = 181.122449%==
*INFO: SigComp - Create feedback item.
*INFO: SigComp - Creating stateless message.
*INFO: SigComp - Add new state.
*INFO: Compressing stateful message.
*INFO: ==INVITE compression ratio = 249.169860%==
*INFO: SigComp - Create feedback item.
*INFO: SigComp - Creating stateful message.
*INFO: SigComp - Add new state.
*INFO: Compressing stateful message.
*INFO: ==488 INVITE compression ratio = 181.180812%==
*INFO: SigComp - Create feedback item.
*INFO: SigComp - Creating stateful message.
*INFO: SigComp - Add new state.
*INFO: Compressing stateful message.
*INFO: ==ACK compression ratio = 761.224490%==
*INFO: SigComp - Create feedback item.
*INFO: SigComp - Creating stateful message.
*INFO: SigComp - Add new state.
*INFO: Compressing stateful message.
*INFO: ==REGISTER compression ratio = 2739.393939%==
*INFO: SigComp - Create feedback item.
*INFO: SigComp - Creating stateful message.
*INFO: SigComp - Add new state.
*INFO: Compressing stateful message.
*INFO: ==200 REGISTER compression ratio = 4226.190476%==
*INFO: SigComp - Create feedback item.
*INFO: SigComp - Creating stateful message.
*INFO: SigComp - Add new state.
*INFO: Compressing stateful message.
*INFO: ==INVITE compression ratio = 4537.209302%==
*INFO: SigComp - Create feedback item.
*INFO: SigComp - Creating stateful message.
***ERROR: function: "tcomp_udvm_runByteCode()"
file: "c:\users\abc\documents\myboghe\doubango\branches\2.0\doubango\tinysigcomp
\src\tcomp_udvm.c"
line: "49"
MSG: Cannot run()/execute() invalid bytecode
***ERROR: function: "test_manager()"
file: "c:\users\abc\documents\myboghe\doubango\branches\2.0\doubango\tinysigcomp
\test\test_manager.h"
line: "551"
MSG: Failed to decompress INVITE request
*INFO: SigComp - Initializing NACK message.
*INFO: Compressing stateful message.
*INFO: ==INVITE compression ratio = 4537.209302%==
*INFO: SigComp - Create feedback item.
*INFO: SigComp - Creating stateful message.
***ERROR: function: "tcomp_udvm_runByteCode()"
file: "c:\users\abc\documents\myboghe\doubango\branches\2.0\doubango\tinysigcomp
\src\tcomp_udvm.c"
line: "49"
MSG: Cannot run()/execute() invalid bytecode
***ERROR: function: "test_manager()"
file: "c:\users\abc\documents\myboghe\doubango\branches\2.0\doubango\tinysigcomp
\test\test_manager.h"
line: "551"
MSG: Failed to decompress INVITE request
*INFO: SigComp - Initializing NACK message.
*INFO: Decompressed message:
*INFO: Compressing stateful message.
*INFO: ==INVITE compression ratio = 4537.209302%==
*INFO: SigComp - Create feedback item.
*INFO: SigComp - Creating stateful message.
***ERROR: function: "tcomp_udvm_runByteCode()"
file: "c:\users\abc\documents\myboghe\doubango\branches\2.0\doubango\tinysigcomp
\src\tcomp_udvm.c"
line: "49"
MSG: Cannot run()/execute() invalid bytecode
***ERROR: function: "test_manager()"
file: "c:\users\abc\documents\myboghe\doubango\branches\2.0\doubango\tinysigcomp
\test\test_manager.h"
line: "551"
MSG: Failed to decompress INVITE request
*INFO: SigComp - Initializing NACK message.
*INFO: Decompressed message:

tsk_bool_t tcomp_statehandler_handleNack(tcomp_statehandler_t *statehandler, 
const tcomp_nackinfo_t * nackinfo)
{
     tcomp_buffer_handle_t* sha_id;
     tsk_list_item_t *item;
     if(!statehandler){
          TSK_DEBUG_ERROR("Invalid parameter");
          return tsk_false;
     }

     if(!(sha_id = tcomp_buffer_create_null())){
          TSK_DEBUG_ERROR("Failed to create buffer handle");
          return tsk_false;
     }

     tcomp_buffer_referenceBuff(sha_id, ((tcomp_nackinfo_t*)nackinfo)->sha1, TSK_SHA1_DIGEST_SIZE);

     tsk_list_foreach(item, statehandler->compartments)
     {
          tcomp_compartment_t* lpCompartement = item->data;
          if(tcomp_compartment_hasNack(lpCompartement, &sha_id))
          {
              // this compartment is responsible for this nack
              switch(nackinfo->reasonCode)
              {
              case NACK_STATE_NOT_FOUND:
                   {
                        // Next commented because in this version remote state ids are never saved.
                        // Only the ghost has information on last partial state id to use --> reset the ghost
                        /*SigCompState* lpState = NULL;
                        lpCompartement->findState(&nack_info->details, &lpState);
                        if(lpState)
                        {
                             lpCompartement->freeState(lpState);
                        }*/
                        tcomp_compartment_freeGhostState(lpCompartement);
                   }
                   break;

              default:
                   {
                        tcomp_compartment_clearStates(lpCompartement);
                   }
                   break;
              }
          }
     }

     TSK_OBJECT_SAFE_FREE(sha_id);

     return tsk_true;
}

Original issue reported on code.google.com by alistair...@gmail.com on 10 Jan 2013 at 3:20

GoogleCodeExporter commented 9 years ago

Original comment by boss...@yahoo.fr on 11 Jan 2013 at 10:09

GoogleCodeExporter commented 9 years ago
I cannot reproduce this issue. The test is executed 10 (SIGCOMP_LOOP_COUNT) 
times without any error.
Are you running the code unmodified?

Original comment by boss...@yahoo.fr on 15 Jan 2013 at 4:31

GoogleCodeExporter commented 9 years ago
I was running the code unmodified. However, it appears that the latest changes 
you made have stopped the error situation.

Original comment by alistair...@gmail.com on 15 Jan 2013 at 5:04

GoogleCodeExporter commented 9 years ago
Ok. Let's close the issue know and reopen it if you manage to reproduce it.
There is a bug on the NACK creation fixed on our code but not committed yet:
http://code.google.com/p/doubango/source/browse/branches/2.0/doubango/tinySIGCOM
P/src/tcomp_udvm.nack.c?spec=svn805&r=805#45
The first parameter must be "udvm->lpResult->nack_info" instead of 
"nackbuffer_ptr". This is an regression introduce in the latest commit.

Original comment by boss...@yahoo.fr on 15 Jan 2013 at 5:16