Skip to content

attended_transfer/caller_local_blond: Make more reliable#147

Open
gtjoseph wants to merge 1 commit into
asterisk:masterfrom
gtjoseph:master-caller_local_blonde
Open

attended_transfer/caller_local_blond: Make more reliable#147
gtjoseph wants to merge 1 commit into
asterisk:masterfrom
gtjoseph:master-caller_local_blonde

Conversation

@gtjoseph

Copy link
Copy Markdown
Member
  • Trying to figure out how the test actually works took most of the time.
    To make it easier to understand, instead of using names like referer, referee,
    etc. the scenarios are now named after our usual actors: alice, bob and charlie.
  • Numerous naming clarifications were made to the scenario files.
  • The test description has been re-written to include both a high-level and
    low-level flow.
  • Instead of having the 4 sipp scenarios all bind to 127.0.0.1 with different
    ports, they bind to 127.0.0.2, 3, 4, 5 port 5060.
  • The usual test failure was in the alice_calls_bob scenario when it's supposed
    to receive 2 sipfrag NOTIFYs. For some reason, sipp would occasionally just
    end the scenario after the first NOTIFY with no indication as to why. To get
    around this, alice_calls_bob.xml no longer explicitly deals with the NOTIFYs
    and instead lets sipp deal with them by virtue of the -aa option.
  • Also fixed an issue in sipp.py that prevented SIP packets from being output
    to the Asterisk logs when there was only 1 asterisk instance.

* Trying to figure out how the test actually works took most of the time.
To make it easier to understand, instead of using names like referer, referee,
etc. the scenarios are now named after our usual actors: alice, bob and charlie.
* Numerous naming clarifications were made to the scenario files.
* The test description has been re-written to include both a high-level and
low-level flow.
* Instead of having the 4 sipp scenarios all bind to 127.0.0.1 with different
ports, they bind to 127.0.0.2, 3, 4, 5 port 5060.
* The usual test failure was in the alice_calls_bob scenario when it's supposed
to receive 2 sipfrag NOTIFYs.  For some reason, sipp would occasionally just
end the scenario after the first NOTIFY with no indication as to why.  To get
around this, alice_calls_bob.xml no longer explicitly deals with the NOTIFYs
and instead lets sipp deal with them by virtue of the `-aa` option.
* Also fixed an issue in sipp.py that prevented SIP packets from being output
to the Asterisk logs when there was only 1 asterisk instance.
@gtjoseph

Copy link
Copy Markdown
Member Author

cherry-pick-to: 20
cherry-pick-to: 21
cherry-pick-to: 22
cherry-pick-to: 23
cherry-pick-to: certified/20.7
cherry-pick-to: certified/22.8

@github-actions

Copy link
Copy Markdown

Workflow Check completed successfully

@mbradeen mbradeen left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

sipp changed some end-of-scenario timing with regard to overall timeouts and to coordinated scenario shutdown, which I think is what causes the alice-to-bob scenario to end early. I had put some extra cmd exchanges in at the end to a bunch of the tests to try and deal with it, but as you noted it still shuts down early for some reason. If we con't care about the NOTIFY messages then the -aa should be fine.

@gtjoseph

Copy link
Copy Markdown
Member Author

It doesn't appear that it's "ending" early, sipp actually terminates with a "1" return code after it received the first sipfrag NOTIFY. Here's the output...

 Resolving peer address : 127.0.0.1...
------------------------------ Scenario Screen -------- [1-9]: Change Screen --
  Call rate (length)   Port   Total-time  Total-calls  Remote-host
  10.0(0 ms)/1.000s   5060       1.16 s            1  127.0.0.1:5060(UDP)

  Call limit 1 hit, 0.0 s period          0 ms scheduler resolution            
  0 calls (limit 30)                      Peak was 1 calls, after 0 s
  1 Running, 2 Paused, 5 Woken up
  0 dead call msg (discarded)             0 out-of-call msg (discarded)
  0 open sockets                          0/0/0 UDP errors (send/recv/cong)
  0 open sockets                          0/0/0 UDP errors (send/recv/cong)

                                 Messages  Retrans   Timeout   Unexpected-Msg
0 :      INVITE ---------->         1         0         0                            
1 :         100 <----------         1         0         0         0                  
2 :         101 <----------         0         0         0         0                  
3 :         180 <----------         1         0         0         0                  
4 :         200 <----------  E-RTD1 1         0         0         0                  

5 :         ACK ---------->         1         0                                      
6 :      INVITE ---------->         1         0         0                            
7 :         100 <----------         0         0         0         0                  
8 :         101 <----------         0         0         0         0                  
9 :         180 <----------         0         0         0         0                  
10:         200 <----------  E-RTD1 1         0         0         0                  

11:         ACK ---------->         1         0                                      
12:        [ Sent Command ]         1                                      
13:    [ Received Command ]         1                                      
14:       REFER ---------->         1         0                                      
15:         202 <----------  E-RTD1 1         0         0         0                  

16:      NOTIFY <----------         1         0         0         0                  
17:         200 ---------->         0         0                                      
18:      NOTIFY <----------         0         0         0         0                  
19:         200 ---------->         0         0                                      
20:    [ Received Command ]         0                                      
21:         BYE ---------->         0         0         0                            
22:         481 <----------         0         0         0         0                  
23:         200 <----------  E-RTD1 0         0         0         0                  

------------------------------ Test Terminated --------------------------------
----------------------------- Statistics Screen ------- [1-9]: Change Screen --
  Start Time             | 2026-06-23	13:38:58.839017	1782221938.839017         
  Last Reset Time        | 2026-06-23	13:39:02.006630	1782221942.006630         
  Current Time           | 2026-06-23	13:39:02.006670	1782221942.006670         
-------------------------+---------------------------+--------------------------
  Counter Name           | Periodic value            | Cumulative value
-------------------------+---------------------------+--------------------------
  Elapsed Time           | 00:00:00:000000           | 00:00:00:000000          
  Call Rate              |    0.000 cps              |    0.316 cps             
-------------------------+---------------------------+--------------------------
  Incoming calls created |        0                  |        0                 
  Outgoing calls created |        0                  |        1                 
  Total Calls created    |                           |        1                 
  Current Calls          |        0                  |                          
-------------------------+---------------------------+--------------------------
  Successful call        |        0                  |        0                 
  Failed call            |        0                  |        1                 
-------------------------+---------------------------+--------------------------
  Response Time 1        | 00:00:00:000000           | 00:00:00:000000          
  Call Length            | 00:00:00:000000           | 00:00:00:000000          
------------------------------ Test Terminated --------------------------------

No errors, no unexpected messages, no timeouts, etc. It just ends.
Not every time of course. That would make too much sense.

@mbradeen

Copy link
Copy Markdown
Contributor

@gtjoseph - looking at https://github.com/asterisk/asterisk/actions/runs/27999754131/job/82869878857 ... i think this is a 3pcc thing (I know different test) - if you look at the logs, the referee finishes which I think is triggering sipp to close the referer with a 1 because of what I mentioned before with the change in teardown by sipp on 3pcc scenarios. I'm wondering if a pause or timewait at the end of both scenarios would allow the linked scenario to finish. Maybe swapping the -3pcc flag for -3pcc-C ...

@gtjoseph

Copy link
Copy Markdown
Member Author

In this test, the referee (alice_calls_charlie) isn't ending before the referer (alice_calls_bob). alice_calls_charlie sends the ACK to the 603 then the sendCmd that's supposed to tell alice_calls_bob to end but alice_calls_bob has already died at that point.

Here's the log and pcap. If you see something different, let me know.

fail.zip

Just FYI... I ran over 300 iterations with this change without an error.

@mbradeen

Copy link
Copy Markdown
Contributor

If we don't care about the NOTIFY messages, then I am all for just using the -aa method on this and all other failing transfer tests :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants