Summary:ASTERISK-06689: SIP: DTMF INFO before answer causes disconnect
Reporter:Alan Ferrency (ferrency)Labels:
Date Opened:2006-04-03 13:27:22Date Closed:2006-05-24 13:54:45
Versions:Frequency of
Environment:Attachments:( 0) sip-debug-reproduce
( 1) sip-reproduce3
The problem manifests itself with these symptoms:                                                                                          
- an internal SIP extension receives a call from our PRI                                                                                  
- the SIP phone answers the call                                                                                                          
- after approximately 20 seconds, the PRI caller is sent to                                                                                
 voicemail (the next priority in the caller's context), and the
 internal extension is hung up on.

This seemed to happen only randomly, but I figured out how to reproduce                                                                    
it. We are using SIP INFO for DTMF. The problem occurs if the PRI caller                                                                  
enters a DTMF tone after the SIP invite was sent to the SIP phone, but                                                                    
before the SIP phone answers.

It only happens for PRI -> SIP calls, not for SIP -> SIP calls.


Please see attached logs reproducing this problem, below.

In this case, the SIP phone responds to the INFO packet immediately,                                                                      
before the call is answered. Then, when the call is answered, the phone                                                                    
responds to the initial INVITE, and Asterisk sends an ACK for the INVITE.                                                                  
However, the phone never receives an ACK for the INFO response it sent.                                                                    
The phone doesn't care much about this lack of ACK, but it looks like                                                                      
Asterisk didn't see the INFO response. It reports:                                                                                        
@Scheduling destruction of call '1536d1554749f3957bdfebb548bcf9b7@' in 15000 ms                                                
And then, it sends a CANCEL packet to the SIP phone, with the same call                                                                    
sequence number as the initial INFO SIP packet. The call then seems to                                                                    
progress to the next priority in the dial plan, and is sent to                                                                            
The phone rejects the CANCEL packet with an Internal Server Error, but I                                                                  
don't think that's the problem here: the call has already gone to                                                                          
voicemail before the internal server error is received.                                                                                    
I have verified that this is only a problem for PRI->SIP calls.                                                                            
SIP->SIP calls do not generate DTMF INFO packets prior to the call                                                                        
being answered.                                                          

- Asterisk 1.2.3
- Phones are Sipura SPA-841 and SPA-941
- Fedora Core 3
- TE110P call with PRI, United States T-1 style

Since this does not happen on sip->sip calls, we don't currently have the hardware available to test this outside of production on newer/test versions of Asterisk.  (We have a spare TE110P, but no spare PRI; and no spare FXO/FXS cards.)

Comments:By: Olle Johansson (oej) 2006-04-03 14:56:33

I will take a look at this.

By: Alan Ferrency (ferrency) 2006-04-07 11:14:33

I apologize for the lack of debug logging in my earlier attachment.  I had my debug output redirected to a log file instead of console, so I missed it.  I will try to restart Asterisk today and produce a better debug log of the problem, but it depends on achieving zero call volume at some point.

By: Alan Ferrency (ferrency) 2006-04-07 16:07:42

Attached file sip-reproduce3 contains a reproduction of the same situation as in sip-debug-reproduce, but with Asterisk core debugging as well.

The descriptive notes in sip-debug-reproduce apply to sip-reproduce3 as well, with respect to the sequence of events and the filtering I've done on the log.

Please tell me if you require any other information.  Thanks!


By: Olle Johansson (oej) 2006-04-07 16:29:05

Thanks. Will take a look at this on monday.

By: Olle Johansson (oej) 2006-04-07 16:30:16

btw, say hello to Marwin and fix his bad diods :-)

By: Alan Ferrency (ferrency) 2006-04-10 11:41:29

Hmm, perhaps you're thinking of someone else?  I haven't talked to any Marwin for 10 years, and last I knew he wasn't having any problem with diodes :)

By: Olle Johansson (oej) 2006-04-10 13:54:34

"the Asterisk server is marvin (the paranoid android)" - From your log file :-)

By: Alan Ferrency (ferrency) 2006-04-10 14:01:05

Doh! My mistake :)

By: Olle Johansson (oej) 2006-04-13 08:33:25

-- Executing Dial("Zap/3-1", "sip/sip_alan|20|o") in new stack
-- Nobody picked up in 20000 ms
CANCEL sip_alan
-- Executing VoiceMail("Zap/3-1", "u828") in new stack

Actually, it doesn't seem like the INFO packet has anything to do with this, it's forwarded to alan. But we have a timeout from the dial command (20 seconds) that expires - which is the reason for the voicemail.

By: Olle Johansson (oej) 2006-04-13 08:35:08

Tired... Now I found the 200 ok in the middle. Yes, this is weird. I will check if I can repeat this.

By: Alan Ferrency (ferrency) 2006-04-13 08:37:13

> Tired... Now I found the 200 ok in the middle. Yes, this is weird. I will check if I can repeat this.

Yes, the reason it is weird is because the call _does_ connect, and the parties can talk; but 20 seconds later, Asterisk thinks no one ever picked up...

By: Serge Vecher (serge-v) 2006-05-22 20:32:37

hmmm, 1.2.3... Is this still an issue in

By: Alan Ferrency (ferrency) 2006-05-24 13:37:28

> hmmm, 1.2.3... Is this still an issue in

I do not know at this time.  We have worked around the issue in our 1.2.3 production server, and currently have no plans to upgrade to 1.2.7 (though, that may change).  I'll be happy to test again after any upgrade, if we do an upgrade.

I could not reproduce this problem in a pure SIP environment.  Unfortunately, our test box has only a single PRI card and no PSTN connection, so I currently don't have the resources needed to mock up this problem in a test environment.

I still have no confirmation that this has ever been a problem for anyone other than me, even in 1.2.3.  Though if the problem was addressed directly (as opposed to fixed as a side-effect of other changes), I expect Olle would know about it.


By: Joshua C. Colp (jcolp) 2006-05-24 13:54:45

I'll make a decision to close this bug then. While we realize this is an issue, it is not something we can easily fix with the current SIP channel driver - but it is something we will take into consideration when planning the next version. If anyone involves wishes to reopen this bug in the future feel free to.