- Asterisk Version: 1.8.11.1-1digium1~lucid
- Linux 2.6.32-24-server #38-Ubuntu SMP Mon Jul 5 10:29:32 UTC 2010 x86_64 GNU/Linux
Recently our SIP provider has reported to us that our Asterisk server is taking a long time to response to invites, usually 4-5 seconds. One example conversation (y.y.y.y is the SIP provider IP and x.x.x.x is our Asterisk server’s IP):
Aug 19 9:55:17.435 AM y.y.y.y > x.x.x.x INVITE sip:7148887588@x.x.x.x:5060 SIP/2.0
Aug 19 9:55:18.0 AM y.y.y.y > x.x.x.x INVITE sip:7148887588@x.x.x.x:5060 SIP/2.0
Aug 19 9:55:19.0 AM y.y.y.y > x.x.x.x INVITE sip:7148887588@x.x.x.x:5060 SIP/2.0
Aug 19 9:55:21.374 AM y.y.y.y < x.x.x.x SIP/2.0 100 Trying
Aug 19 9:55:21.375 AM y.y.y.y > x.x.x.x CANCEL sip:7148887588@x.x.x.x:5060 SIP/2.0
Aug 19 9:55:21.519 AM y.y.y.y < x.x.x.x SIP/2.0 100 Trying
Aug 19 9:55:21.519 AM y.y.y.y < x.x.x.x SIP/2.0 100 Trying
Aug 19 9:55:21.519 AM y.y.y.y < x.x.x.x SIP/2.0 487 Request Terminated
Aug 19 9:55:21.519 AM y.y.y.y < x.x.x.x SIP/2.0 200 OK
Aug 19 9:55:21.519 AM y.y.y.y > x.x.x.x ACK sip:7148887588@x.x.x.x:5060 SIP/2.0
By running Wireshark, we can observe incoming and outgoing packets, and compare that output to the Asterisk debug output. With Wireshark, we discover the following example:
15:19:20: -> INVITE
15:19:20: -> INVITE
15:19:21: -> INVITE
15:19:24: <- 100 Trying
We see three INVITE attempts coming down the wire, however our Asterisk debug output logs the first INVITE packet at 15:19:24, a three second delay between the OS sees the packet and when Asterisk sees the packet.
This behavior is not consistent and we don’t see any relevant-looking errors in /var/log/asterisk/messages.