I have FreePBX 2.11.0.35 / Asterisk 11.8 running on a beagle bone black (www . beaglebone-asterisk.org /downloads/ ) I’ve been playing around with it, getting sip trunks and sip extensions working. Maybe I did something bad, but nothing obvious. Now I cannot make any calls. When I call, it connects for about 5 seconds and then disconnects. The error is
Retransmission timeout reached on transmission [email protected] for seqno 52420 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6400ms with no response
[2014-09-30 23:51:14] WARNING[1777] chan_sip.c: Hanging up call [email protected] - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
Googling shows this error often from routing / NAT issues, but here I’m dialing the voicemail extension (*97) on the freepbx server on a sip phone (grandstream GXP280) registered to that same freepbx server. The freepbx server and grandstream sip phone are on the same subnet. I get the same problem when trying to dial out / other extensions, but I figured this was the simplest case and hopefully easier to debug.
Here is a full asterisk log from reboot on freepbx to registereing my sip phone to dialing voicemail:
[2014-09-30 23:39:45] VERBOSE[1738] config.c: == Parsing '/etc/asterisk/cli.conf': Found
[2014-09-30 23:40:20] VERBOSE[1777][C-00000000] netsock2.c: == Using SIP RTP TOS bits 184
[2014-09-30 23:40:20] VERBOSE[1777][C-00000000] netsock2.c: == Using SIP RTP CoS mark 5
[2014-09-30 23:40:20] VERBOSE[1777][C-00000001] netsock2.c: == Using SIP RTP TOS bits 184
[2014-09-30 23:40:20] VERBOSE[1777][C-00000001] netsock2.c: == Using SIP RTP CoS mark 5
[2014-09-30 23:40:20] VERBOSE[1973][C-00000001] pbx.c: -- Executing [30@from-internal:1] ResetCDR("SIP/50-00000000", "") in new stack
[2014-09-30 23:40:20] VERBOSE[1973][C-00000001] pbx.c: -- Executing [30@from-internal:2] NoCDR("SIP/50-00000000", "") in new stack
[2014-09-30 23:40:20] VERBOSE[1973][C-00000001] pbx.c: -- Executing [30@from-internal:3] Progress("SIP/50-00000000", "") in new stack
[2014-09-30 23:40:20] VERBOSE[1973][C-00000001] pbx.c: -- Executing [30@from-internal:4] Wait("SIP/50-00000000", "1") in new stack
[2014-09-30 23:40:21] VERBOSE[1973][C-00000001] pbx.c: -- Executing [30@from-internal:5] Progress("SIP/50-00000000", "") in new stack
[2014-09-30 23:40:21] VERBOSE[1973][C-00000001] pbx.c: -- Executing [30@from-internal:6] Playback("SIP/50-00000000", "silence/1&cannot-complete-as-dialed&check-number-dial-again,noanswer") in new stack
[2014-09-30 23:40:21] VERBOSE[1973][C-00000001] file.c: -- <SIP/50-00000000> Playing 'silence/1.slin' (language 'en')
[2014-09-30 23:40:22] VERBOSE[1973][C-00000001] file.c: -- <SIP/50-00000000> Playing 'cannot-complete-as-dialed.slin' (language 'en')
[2014-09-30 23:40:25] VERBOSE[1973][C-00000001] file.c: -- <SIP/50-00000000> Playing 'check-number-dial-again.slin' (language 'en')
[2014-09-30 23:40:27] VERBOSE[1973][C-00000001] pbx.c: -- Executing [30@from-internal:7] Wait("SIP/50-00000000", "1") in new stack
[2014-09-30 23:40:28] VERBOSE[1973][C-00000001] pbx.c: -- Executing [30@from-internal:8] Congestion("SIP/50-00000000", "20") in new stack
[2014-09-30 23:40:28] VERBOSE[1973][C-00000001] pbx.c: == Spawn extension (from-internal, 30, 8) exited non-zero on 'SIP/50-00000000'
[2014-09-30 23:40:28] VERBOSE[1973][C-00000001] pbx.c: -- Executing [h@from-internal:1] Hangup("SIP/50-00000000", "") in new stack
[2014-09-30 23:40:28] VERBOSE[1973][C-00000001] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/50-00000000'
[2014-09-30 23:40:34] WARNING[1777] chan_sip.c: Retransmission timeout reached on transmission [email protected] for seqno 30054 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6400ms with no response
[2014-09-30 23:49:38] VERBOSE[1777] chan_sip.c: -- Registered SIP '50' at 192.168.10.50:5060
[2014-09-30 23:49:38] NOTICE[1777] chan_sip.c: Peer '50' is now Reachable. (29ms / 2000ms)
[2014-09-30 23:51:07] VERBOSE[1777][C-00000002] netsock2.c: == Using SIP RTP TOS bits 184
[2014-09-30 23:51:07] VERBOSE[1777][C-00000002] netsock2.c: == Using SIP RTP CoS mark 5
[2014-09-30 23:51:07] VERBOSE[1777][C-00000003] netsock2.c: == Using SIP RTP TOS bits 184
[2014-09-30 23:51:07] VERBOSE[1777][C-00000003] netsock2.c: == Using SIP RTP CoS mark 5
[2014-09-30 23:51:08] VERBOSE[1777][C-00000004] netsock2.c: == Using SIP RTP TOS bits 184
[2014-09-30 23:51:08] VERBOSE[1777][C-00000004] netsock2.c: == Using SIP RTP CoS mark 5
[2014-09-30 23:51:08] VERBOSE[2405][C-00000004] pbx.c: -- Executing [*97@from-internal:1] Answer("SIP/50-00000001", "") in new stack
[2014-09-30 23:51:08] VERBOSE[2405][C-00000004] pbx.c: -- Executing [*97@from-internal:2] Wait("SIP/50-00000001", "1") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [*97@from-internal:3] Macro("SIP/50-00000001", "user-callerid,") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/50-00000001", "TOUCH_MONITOR=1412117468.1") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:2] Set("SIP/50-00000001", "AMPUSER=50") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:3] GotoIf("SIP/50-00000001", "0?report") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:4] ExecIf("SIP/50-00000001", "1?Set(REALCALLERIDNUM=50)") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/50-00000001", "AMPUSER=50") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/50-00000001", "0?limit") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:7] Set("SIP/50-00000001", "AMPUSERCIDNAME=John Doe") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:8] GotoIf("SIP/50-00000001", "0?report") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:9] Set("SIP/50-00000001", "AMPUSERCID=50") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:10] Set("SIP/50-00000001", "__DIAL_OPTIONS=Ttr") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:11] Set("SIP/50-00000001", "CALLERID(all)="John Doe" <50>") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:12] GotoIf("SIP/50-00000001", "0?limit") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:13] ExecIf("SIP/50-00000001", "0?Set(GROUP(concurrency_limit)=50)") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:14] GotoIf("SIP/50-00000001", "0?continue") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:15] Set("SIP/50-00000001", "__TTL=64") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:16] GotoIf("SIP/50-00000001", "1?continue") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Goto (macro-user-callerid,s,27)
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:27] Set("SIP/50-00000001", "CALLERID(number)=50") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:28] Set("SIP/50-00000001", "CALLERID(name)=John Doe") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:29] Set("SIP/50-00000001", "CDR(cnum)=50") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:30] Set("SIP/50-00000001", "CDR(cnam)=John Doe") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-user-callerid:31] Set("SIP/50-00000001", "CHANNEL(language)=en") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [*97@from-internal:4] Macro("SIP/50-00000001", "get-vmcontext,50") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-get-vmcontext:1] Set("SIP/50-00000001", "VMCONTEXT=default") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-get-vmcontext:2] GotoIf("SIP/50-00000001", "0?200:300") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Goto (macro-get-vmcontext,s,300)
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [s@macro-get-vmcontext:300] NoOp("SIP/50-00000001", "") in new stack
[2014-09-30 23:51:09] WARNING[2405][C-00000004] app_voicemail.c: MAILBOX_EXISTS is deprecated. Please use ${VM_INFO(50,exists)} instead.
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [*97@from-internal:5] Set("SIP/50-00000001", "VMBOXEXISTSSTATUS=SUCCESS") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [*97@from-internal:6] GotoIf("SIP/50-00000001", "1?mbexist") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Goto (from-internal,*97,106)
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] pbx.c: -- Executing [*97@from-internal:106] VoiceMailMain("SIP/50-00000001", "50@default") in new stack
[2014-09-30 23:51:09] VERBOSE[2405][C-00000004] file.c: -- <SIP/50-00000001> Playing 'vm-password.slin' (language 'en')
[2014-09-30 23:51:14] WARNING[1777] chan_sip.c: Retransmission timeout reached on transmission [email protected] for seqno 52420 (Critical Response) -- See https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions
Packet timed out after 6400ms with no response
[2014-09-30 23:51:14] WARNING[1777] chan_sip.c: Hanging up call [email protected] - no reply to our critical packet (see https://wiki.asterisk.org/wiki/display/AST/SIP+Retransmissions).
[2014-09-30 23:51:14] WARNING[2405][C-00000004] app_voicemail.c: Unable to read password
[2014-09-30 23:51:14] VERBOSE[2405][C-00000004] pbx.c: -- Executing [h@from-internal:1] Hangup("SIP/50-00000001", "") in new stack
[2014-09-30 23:51:14] VERBOSE[2405][C-00000004] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/50-00000001'
Any ideas / suggestions appreciated.
Thanks,