Asterisk
  1. Asterisk
  2. ASTERISK-26771

ARI: HTTP requests take 200ms to be taken into account

    Details

    • Type: Bug Bug
    • Status: Open
    • Severity: Major Major
    • Resolution: Unresolved
    • Affects Version/s: 14.2.1, GIT
    • Target Release Version/s: None
    • Component/s: Resources/res_stasis
    • Security Level: None
    • Labels:
    • Environment:
      Debian 8.5
      3.16.0-4-686-pae
      gcc (Debian 4.9.2-10) 4.9.2

      Description

      Frequency

      Systematic issue.

      Symptoms

      ARI http requests take a huge time to be taken into account (and respond with the appropriate SIP messages)

      Steps required to reproduce the issue

      • Setup an extension with a stasis application (withouth the answer app). E.g.,
        exten => 6100,1,NoOp()
         same =>      n,Stasis(bug)
         same =>      n,Hangup()
        
      • Place a call from a phone (sip or pjsip user. It doesn't matter) to the stasis extension (6100 in the example)
      • Perform a ARI http request for a answer (or any other request on the channel):
        curl -v -u asterisk:asterisk -X POST "http://192.168.210.132:8088/ari/channels/atom_asterisk-1486386024.1/answer"
        

      Expected Behaviour

      The SIP message "200 OK" should be sent soon after the http POST request (let's say after a few milliseconds).

      Behaviour actually encountered

      The SIP message "200 OK" takes an unacceptable time to be sent after the http POST request (>100ms the WCET is 200ms)
      (see the wireshark trace attached)

      Hints

      When a channel enter a stasis application, a new thread is spawned and the function stasis_app_exec executed (file res_stasis.c). The function enter in a while loop that performs a ast_waitfor(channel, MAX_WAIT_MS) call that waits for events with a timeout of MAX_WAIT_MS (200ms).

      Before a "channel/answer" request, the control flow is blocked on the ast_waitfor for 200ms, then handles the requests inside control_dispatch_all, then waits again on the ast_waitfor and so on... I see that the while loop repeats exactly every 200ms. So, when a "channel/answer" request arrives, ast_waitfor doesn't wake up immediately but waits for the 200ms timeout. When ast_waitfor exits for timeout, finally the channel performs the answer (WCET for the answer: 200ms).

      After answering the channel, I see that the while cycle enter every 20ms, because ast_waitfor now exits after only 20ms (and not 200ms as before). So, next requests are more responsive (WCET for following requests: 20ms).

      So, it seems to me that the ast_waitfor function doesn't work as expected (it doesn't wake up on http requests, but always wait the timeout expiration)

        Issue Links

          Activity

          Hide
          Asterisk Team added a comment -

          Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution.

          A good first step is for you to review the Asterisk Issue Guidelines if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

          Then, if you are submitting a patch, please review the Patch Contribution Process.

          Show
          Asterisk Team added a comment - Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. A good first step is for you to review the Asterisk Issue Guidelines if you haven't already. The guidelines detail what is expected from an Asterisk issue report. Then, if you are submitting a patch, please review the Patch Contribution Process .
          Hide
          Daniele Pallastrelli added a comment -

          Wireshark trace that shows the delay between a channel/answer ARI request and the "200 OK" sip message.

          Show
          Daniele Pallastrelli added a comment - Wireshark trace that shows the delay between a channel/answer ARI request and the "200 OK" sip message.

            People

            • Votes:
              1 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

              • Created:
                Updated:

                Development