I have recently moved our asterisk server from our LAN to a Debian
Lenny server (Asterisk 1.4.21.2~dfsg-3 ) with a public IP outside our
network. Our phones are behind a natted firewall. An ITSP provides a
PSTN to SIP termination for incoming calls
Public ITSP -->Asterisk server-->Natted firewall-->extension
(192.168.1.x)
Everything works fine (incoming/outgoing audio etc.) except
occasionally an incoming caller is cut off whilst the called extension
stays in the call and can hear a DTMF tone (multimon recognises it as
tone "D"). The asterisk log file shows the call stays active despite
the incoming caller being cut off. This has happened to all our
extensions at some point (a combination of Snoms and Funkwerks). It
happens fairly infrequently, and can happen at any point during a
call.
The public Lenny server's asterisk config is exactly the same as our
LAN Ubuntu asterisk server where we never had this problem. The only
difference is that the ITSP trunk is now ulaw rather than ilbc.
Can anyone help? Relevant files below (trunk and extension codecs are both ulaw)
John
example extension in sip.conf:
[203]
type=friend
username=203
secret=xxxxxx
host=dynamic
dtmfmode=inband
call-limit=2
qualify=yes
nat=yes
/var/log/asterisk/messages:
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Executing
[301xxxxx at fromvoipfone:1] Set("SIP/301xxxxx-09f74a00",
"oh=0") in new
stack
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Executing
[301xxxxx at fromvoipfone:2] NoOp("SIP/301xxxxx-09f74a00",
"01295259352")
in new stack
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Executing
[301xxxxx at fromvoipfone:3] GotoIf("SIP/301xxxxx-09f74a00",
"0?bankhols|200|1") in new stack
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Executing
[301xxxxx at fromvoipfone:4] GotoIfTime("SIP/301xxxxx-09f74a00",
"08:30-18:00|mon-fri|*|*?day|100|1") in new stack
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Goto (day,100,1)
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Executing
[100 at day:1] AGI("SIP/301xxxxx-09f74a00",
"/home/john/phpagi/lookup")
in new stack
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Launched AGI Script
/home/john/phpagi/lookup
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- AGI Script
/home/john/phpagi/lookup completed, returning 0
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Executing
[100 at day:2] Set("SIP/301xxxxx-09f74a00",
"CALLERID(name)=xxxx") in new
stack
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Executing
[100 at day:3] Macro("SIP/301xxxxx-09f74a00",
"monitor|01327xxxxxx|"in"")
in new stack
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Executing
[s at macro-monitor:1] Set("SIP/301xxxxx-09f74a00",
"CALLFILENAME=/home/john/asterisk/asterisk_recordings/"in"-20100104_095856-01295259352")
in new stack
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Executing
[s at macro-monitor:2] Monitor("SIP/301xxxxx-09f74a00",
"wav|/home/john/asterisk/asterisk_recordings/in-20100104_095856-01295259352|m")
in new stack
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Executing
[100 at day:4] Dial("SIP/301xxxxx-09f74a00",
"SIP/203&SIP/204&SIP/206&SIP/207&SIP/220&SIP/221|20|t")
in new stack
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Called 203
[Jan  4 09:58:56] WARNING[10712] app_dial.c: Unable to create channel
of type 'SIP' (cause 3 - No route to destination)
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Called 206
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Called 207
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- Called 220
[Jan  4 09:58:56] WARNING[10712] app_dial.c: Unable to create channel
of type 'SIP' (cause 3 - No route to destination)
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- SIP/220-09fe7748 is ringing
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- SIP/206-0a005eb8 is ringing
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- SIP/207-09fe2c98 is ringing
[Jan  4 09:58:56] VERBOSE[10712] logger.c:     -- SIP/203-0a001138 is ringing
[Jan  4 09:58:57] VERBOSE[10712] logger.c:     -- SIP/220-09fe7748 is ringing
[Jan  4 09:58:57] VERBOSE[10712] logger.c:     -- SIP/203-0a001138 is ringing
[Jan  4 09:58:58] VERBOSE[10712] logger.c:     -- SIP/220-09fe7748 is ringing
[Jan  4 09:58:58] VERBOSE[10712] logger.c:     -- SIP/203-0a001138 is ringing
[Jan  4 09:58:59] VERBOSE[10712] logger.c:     -- SIP/203-0a001138
answered SIP/301xxxxx-09f74a00
We're now getting this problem on outgoing calls. I've forced the port to 100FD but still no joy. Anyone any ideas how to debug this- have added verbose to logger.conf Thanks for any help John 2010/1/4 John Taylor <john at vetsurgeon.org.uk>:> I have recently moved our asterisk server from our LAN to a Debian > Lenny server (Asterisk 1.4.21.2~dfsg-3 ) with a public IP outside our > network. Our phones are behind a natted firewall. An ITSP provides a > PSTN to SIP termination for incoming calls > > Public ITSP -->Asterisk server-->Natted firewall-->extension (192.168.1.x) > > Everything works fine (incoming/outgoing audio etc.) except > occasionally an incoming caller is cut off whilst the called extension > stays in the call and can hear a DTMF tone (multimon recognises it as > tone "D"). The asterisk log file shows the call stays active despite > the incoming caller being cut off. This has happened to all our > extensions at some point (a combination of Snoms and Funkwerks). It > happens fairly infrequently, and can happen at any point during a > call. > > The public Lenny server's asterisk config is exactly the same as our > LAN Ubuntu asterisk server where we never had this problem. The only > difference is that the ITSP trunk is now ulaw rather than ilbc. > > Can anyone help? Relevant files below (trunk and extension codecs are both ulaw) > > John > > > example extension in sip.conf: > [203] > type=friend > username=203 > secret=xxxxxx > host=dynamic > dtmfmode=inband > call-limit=2 > qualify=yes > nat=yes > > > /var/log/asterisk/messages: > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [301xxxxx at fromvoipfone:1] Set("SIP/301xxxxx-09f74a00", "oh=0") in new > stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [301xxxxx at fromvoipfone:2] NoOp("SIP/301xxxxx-09f74a00", "01295259352") > in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [301xxxxx at fromvoipfone:3] GotoIf("SIP/301xxxxx-09f74a00", > "0?bankhols|200|1") in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [301xxxxx at fromvoipfone:4] GotoIfTime("SIP/301xxxxx-09f74a00", > "08:30-18:00|mon-fri|*|*?day|100|1") in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Goto (day,100,1) > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [100 at day:1] AGI("SIP/301xxxxx-09f74a00", "/home/john/phpagi/lookup") > in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Launched AGI Script > /home/john/phpagi/lookup > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- AGI Script > /home/john/phpagi/lookup completed, returning 0 > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [100 at day:2] Set("SIP/301xxxxx-09f74a00", "CALLERID(name)=xxxx") in new > stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [100 at day:3] Macro("SIP/301xxxxx-09f74a00", "monitor|01327xxxxxx|"in"") > in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [s at macro-monitor:1] Set("SIP/301xxxxx-09f74a00", > "CALLFILENAME=/home/john/asterisk/asterisk_recordings/"in"-20100104_095856-01295259352") > in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [s at macro-monitor:2] Monitor("SIP/301xxxxx-09f74a00", > "wav|/home/john/asterisk/asterisk_recordings/in-20100104_095856-01295259352|m") > in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [100 at day:4] Dial("SIP/301xxxxx-09f74a00", > "SIP/203&SIP/204&SIP/206&SIP/207&SIP/220&SIP/221|20|t") in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Called 203 > [Jan ?4 09:58:56] WARNING[10712] app_dial.c: Unable to create channel > of type 'SIP' (cause 3 - No route to destination) > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Called 206 > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Called 207 > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Called 220 > [Jan ?4 09:58:56] WARNING[10712] app_dial.c: Unable to create channel > of type 'SIP' (cause 3 - No route to destination) > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- SIP/220-09fe7748 is ringing > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- SIP/206-0a005eb8 is ringing > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- SIP/207-09fe2c98 is ringing > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- SIP/203-0a001138 is ringing > [Jan ?4 09:58:57] VERBOSE[10712] logger.c: ? ? -- SIP/220-09fe7748 is ringing > [Jan ?4 09:58:57] VERBOSE[10712] logger.c: ? ? -- SIP/203-0a001138 is ringing > [Jan ?4 09:58:58] VERBOSE[10712] logger.c: ? ? -- SIP/220-09fe7748 is ringing > [Jan ?4 09:58:58] VERBOSE[10712] logger.c: ? ? -- SIP/203-0a001138 is ringing > [Jan ?4 09:58:59] VERBOSE[10712] logger.c: ? ? -- SIP/203-0a001138 > answered SIP/301xxxxx-09f74a00 >
Hi all, I've now set dtmfmode=rfc2833 instead of inband and that seems to have fixed it John 2010/1/4 John Taylor <john at vetsurgeon.org.uk>:> I have recently moved our asterisk server from our LAN to a Debian > Lenny server (Asterisk 1.4.21.2~dfsg-3 ) with a public IP outside our > network. Our phones are behind a natted firewall. An ITSP provides a > PSTN to SIP termination for incoming calls > > Public ITSP -->Asterisk server-->Natted firewall-->extension (192.168.1.x) > > Everything works fine (incoming/outgoing audio etc.) except > occasionally an incoming caller is cut off whilst the called extension > stays in the call and can hear a DTMF tone (multimon recognises it as > tone "D"). The asterisk log file shows the call stays active despite > the incoming caller being cut off. This has happened to all our > extensions at some point (a combination of Snoms and Funkwerks). It > happens fairly infrequently, and can happen at any point during a > call. > > The public Lenny server's asterisk config is exactly the same as our > LAN Ubuntu asterisk server where we never had this problem. The only > difference is that the ITSP trunk is now ulaw rather than ilbc. > > Can anyone help? Relevant files below (trunk and extension codecs are both ulaw) > > John > > > example extension in sip.conf: > [203] > type=friend > username=203 > secret=xxxxxx > host=dynamic > dtmfmode=inband > call-limit=2 > qualify=yes > nat=yes > > > /var/log/asterisk/messages: > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [301xxxxx at fromvoipfone:1] Set("SIP/301xxxxx-09f74a00", "oh=0") in new > stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [301xxxxx at fromvoipfone:2] NoOp("SIP/301xxxxx-09f74a00", "01295259352") > in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [301xxxxx at fromvoipfone:3] GotoIf("SIP/301xxxxx-09f74a00", > "0?bankhols|200|1") in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [301xxxxx at fromvoipfone:4] GotoIfTime("SIP/301xxxxx-09f74a00", > "08:30-18:00|mon-fri|*|*?day|100|1") in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Goto (day,100,1) > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [100 at day:1] AGI("SIP/301xxxxx-09f74a00", "/home/john/phpagi/lookup") > in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Launched AGI Script > /home/john/phpagi/lookup > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- AGI Script > /home/john/phpagi/lookup completed, returning 0 > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [100 at day:2] Set("SIP/301xxxxx-09f74a00", "CALLERID(name)=xxxx") in new > stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [100 at day:3] Macro("SIP/301xxxxx-09f74a00", "monitor|01327xxxxxx|"in"") > in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [s at macro-monitor:1] Set("SIP/301xxxxx-09f74a00", > "CALLFILENAME=/home/john/asterisk/asterisk_recordings/"in"-20100104_095856-01295259352") > in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [s at macro-monitor:2] Monitor("SIP/301xxxxx-09f74a00", > "wav|/home/john/asterisk/asterisk_recordings/in-20100104_095856-01295259352|m") > in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Executing > [100 at day:4] Dial("SIP/301xxxxx-09f74a00", > "SIP/203&SIP/204&SIP/206&SIP/207&SIP/220&SIP/221|20|t") in new stack > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Called 203 > [Jan ?4 09:58:56] WARNING[10712] app_dial.c: Unable to create channel > of type 'SIP' (cause 3 - No route to destination) > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Called 206 > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Called 207 > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- Called 220 > [Jan ?4 09:58:56] WARNING[10712] app_dial.c: Unable to create channel > of type 'SIP' (cause 3 - No route to destination) > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- SIP/220-09fe7748 is ringing > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- SIP/206-0a005eb8 is ringing > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- SIP/207-09fe2c98 is ringing > [Jan ?4 09:58:56] VERBOSE[10712] logger.c: ? ? -- SIP/203-0a001138 is ringing > [Jan ?4 09:58:57] VERBOSE[10712] logger.c: ? ? -- SIP/220-09fe7748 is ringing > [Jan ?4 09:58:57] VERBOSE[10712] logger.c: ? ? -- SIP/203-0a001138 is ringing > [Jan ?4 09:58:58] VERBOSE[10712] logger.c: ? ? -- SIP/220-09fe7748 is ringing > [Jan ?4 09:58:58] VERBOSE[10712] logger.c: ? ? -- SIP/203-0a001138 is ringing > [Jan ?4 09:58:59] VERBOSE[10712] logger.c: ? ? -- SIP/203-0a001138 > answered SIP/301xxxxx-09f74a00 >