Here’s the entire debug log from a failed call:
[INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘LINKEDID_END’,{ts ‘2017-06-15 12:26:50.741486’},‘192.168.17.110’,‘19216817110’,‘19216817110’,’’,‘3014662709’,‘h’,‘from-sip-external’,‘SIP/192.168.17.110-00000137’,’’,’’,3,’’,‘1497543998.4753’,‘1497543998.4753’,’’,’’,’’)]
[2017-06-15 12:26:54] NOTICE[1794]: chan_sip.c:28201 handle_request_register: Registration from ‘“Reception” sip:[email protected]’ failed for ‘192.168.17.110:5062’ - Wrong password
– Attempting call on Local/s@tc-maint for application NoCDR() (Retry 1)
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_START’,{ts ‘2017-06-15 12:27:00.578435’},’’,’’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ad;1’,’’,’’,3,’’,‘1497544020.4754’,‘1497544020.4754’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_START’,{ts ‘2017-06-15 12:27:00.580569’},’’,’’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ad;2’,’’,’’,3,’’,‘1497544020.4755’,‘1497544020.4754’,’’,’’,’’)]
– Executing [s@tc-maint:1] NoCDR(“Local/s@tc-maint-000008ad;2”, “”) in new stack
– Executing [s@tc-maint:2] Set(“Local/s@tc-maint-000008ad;2”, “TCMAINT=RETURN”) in new stack
– Executing [s@tc-maint:3] Gosub(“Local/s@tc-maint-000008ad;2”, “timeconditions,1,1()”) in new stack
– Executing [1@timeconditions:1] Set(“Local/s@tc-maint-000008ad;2”, “DB(TC/1/INUSESTATE)=INUSE”) in new stack
– Executing [1@timeconditions:2] Set(“Local/s@tc-maint-000008ad;2”, “DB(TC/1/NOT_INUSESTATE)=NOT_INUSE”) in new stack
– Executing [1@timeconditions:3] GotoIfTime(“Local/s@tc-maint-000008ad;2”, “08:30-20:00,mon-thu,1-31,jan-dec,America/New_York?truestate”) in new stack
– Goto (timeconditions,1,14)
– Executing [1@timeconditions:14] GotoIf(“Local/s@tc-maint-000008ad;2”, “0?falsegoto”) in new stack
– Executing [1@timeconditions:15] ExecIf(“Local/s@tc-maint-000008ad;2”, “0?Set(DB(TC/1)=)”) in new stack
– Executing [1@timeconditions:16] Set(“Local/s@tc-maint-000008ad;2”, “DEVICE_STATE(Custom:TC1)=NOT_INUSE”) in new stack
– Executing [1@timeconditions:17] ExecIf(“Local/s@tc-maint-000008ad;2”, “0?Set(NOT_INUSE)”) in new stack
– Executing [1@timeconditions:18] GotoIf(“Local/s@tc-maint-000008ad;2”, “0?app-announcement-1,s,1”) in new stack
– Executing [1@timeconditions:19] Set(“Local/s@tc-maint-000008ad;2”, “TCSTATE=true”) in new stack
– Executing [1@timeconditions:20] Set(“Local/s@tc-maint-000008ad;2”, “TCOVERRIDE=false”) in new stack
– Executing [1@timeconditions:21] Return(“Local/s@tc-maint-000008ad;2”, “”) in new stack
– Executing [s@tc-maint:4] System(“Local/s@tc-maint-000008ad;2”, “/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 1”) in new stack
– Executing [s@tc-maint:5] Answer(“Local/s@tc-maint-000008ad;2”, “”) in new stack
> Channel Local/s@tc-maint-000008ad;1 was answered.
> Launching NoCDR() on Local/s@tc-maint-000008ad;1
[2017-06-15 12:27:00] NOTICE[8958]: pbx_spool.c:402 attempt_thread: Call completed to Local/s@tc-maint
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘ANSWER’,{ts ‘2017-06-15 12:27:00.653222’},‘1’,‘1’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ad;2’,‘Answer’,’’,3,’’,‘1497544020.4755’,‘1497544020.4754’,’’,’’,’’)]
== Spawn extension (tc-maint, s, 5) exited non-zero on ‘Local/s@tc-maint-000008ad;2’
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘ANSWER’,{ts ‘2017-06-15 12:27:00.653309’},‘1’,‘1’,‘1’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ad;1’,’’,’’,3,’’,‘1497544020.4754’,‘1497544020.4754’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘HANGUP’,{ts ‘2017-06-15 12:27:00.653379’},‘1’,‘1’,‘1’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ad;1’,’’,’’,3,’’,‘1497544020.4754’,‘1497544020.4754’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_END’,{ts ‘2017-06-15 12:27:00.653398’},‘1’,‘1’,‘1’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ad;1’,’’,’’,3,’’,‘1497544020.4754’,‘1497544020.4754’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘HANGUP’,{ts ‘2017-06-15 12:27:00.654346’},‘1’,‘1’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ad;2’,’’,’’,3,’’,‘1497544020.4755’,‘1497544020.4754’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_END’,{ts ‘2017-06-15 12:27:00.654365’},‘1’,‘1’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ad;2’,’’,’’,3,’’,‘1497544020.4755’,‘1497544020.4754’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘LINKEDID_END’,{ts ‘2017-06-15 12:27:00.654372’},‘1’,‘1’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ad;2’,’’,’’,3,’’,‘1497544020.4755’,‘1497544020.4754’,’’,’’,’’)]
== Using SIP RTP TOS bits 184
== Using SIP RTP CoS mark 5
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_START’,{ts ‘2017-06-15 12:27:22.425944’},‘192.168.17.110’,‘19216817110’,’’,’’,’’,‘3014662709’,‘from-sip-external’,‘SIP/192.168.17.110-00000138’,’’,’’,3,’’,‘1497544042.4756’,‘1497544042.4756’,’’,’’,’’)]
– Executing [3014662709@from-sip-external:1] NoOp(“SIP/192.168.17.110-00000138”, “Received incoming SIP connection from unknown peer to 3014662709”) in new stack
– Executing [3014662709@from-sip-external:2] Set(“SIP/192.168.17.110-00000138”, “DID=3014662709”) in new stack
– Executing [3014662709@from-sip-external:3] Goto(“SIP/192.168.17.110-00000138”, “s,1”) in new stack
– Goto (from-sip-external,s,1)
– Executing [s@from-sip-external:1] GotoIf(“SIP/192.168.17.110-00000138”, “0?checklang:noanonymous”) in new stack
– Goto (from-sip-external,s,5)
– Executing [s@from-sip-external:5] Set(“SIP/192.168.17.110-00000138”, “TIMEOUT(absolute)=15”) in new stack
– Channel will hangup at 2017-06-15 12:27:37.434 EDT.
– Executing [s@from-sip-external:6] Log(“SIP/192.168.17.110-00000138”, "WARNING,“Rejecting unknown SIP connection from 192.168.17.110"”) in new stack
[2017-06-15 12:27:22] WARNING[8988][C-00000c11]: Ext. s:6 @ from-sip-external: “Rejecting unknown SIP connection from 192.168.17.110”
– Executing [s@from-sip-external:7] Answer(“SIP/192.168.17.110-00000138”, “”) in new stack
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘ANSWER’,{ts ‘2017-06-15 12:27:22.436202’},‘192.168.17.110’,‘19216817110’,‘19216817110’,’’,‘3014662709’,‘s’,‘from-sip-external’,‘SIP/192.168.17.110-00000138’,‘Answer’,’’,3,’’,‘1497544042.4756’,‘1497544042.4756’,’’,’’,’’)]
> 0x7fd76c0027b0 – Probation passed - setting RTP source address to 192.168.17.110:11782
– Executing [s@from-sip-external:8] Wait(“SIP/192.168.17.110-00000138”, “2”) in new stack
[2017-06-15 12:27:24] NOTICE[1794]: chan_sip.c:28201 handle_request_register: Registration from ‘“Reception” sip:[email protected]’ failed for ‘192.168.17.110:5062’ - Wrong password
– Executing [s@from-sip-external:9] Playback(“SIP/192.168.17.110-00000138”, “ss-noservice”) in new stack
– <SIP/192.168.17.110-00000138> Playing ‘ss-noservice.ulaw’ (language ‘en’)
– Executing [s@from-sip-external:10] PlayTones(“SIP/192.168.17.110-00000138”, “congestion”) in new stack
– Executing [s@from-sip-external:11] Congestion(“SIP/192.168.17.110-00000138”, “5”) in new stack
== Spawn extension (from-sip-external, s, 11) exited non-zero on ‘SIP/192.168.17.110-00000138’
– Executing [h@from-sip-external:1] Hangup(“SIP/192.168.17.110-00000138”, “”) in new stack
== Spawn extension (from-sip-external, h, 1) exited non-zero on ‘SIP/192.168.17.110-00000138’
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘HANGUP’,{ts ‘2017-06-15 12:27:34.955007’},‘192.168.17.110’,‘19216817110’,‘19216817110’,’’,‘3014662709’,‘h’,‘from-sip-external’,‘SIP/192.168.17.110-00000138’,’’,’’,3,’’,‘1497544042.4756’,‘1497544042.4756’,’’,’’,’’)]
> [INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,lastapp,lastdata,duration,billsec,disposition,amaflags,uniqueid) VALUES ({ ts ‘2017-06-15 12:27:22’ },’“192.168.17.110” <19216817110>’,‘19216817110’,‘s’,‘from-sip-external’,‘SIP/192.168.17.110-00000138’,‘Congestion’,‘5’,12,12,‘ANSWERED’,3,‘1497544042.4756’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_END’,{ts ‘2017-06-15 12:27:34.959012’},‘192.168.17.110’,‘19216817110’,‘19216817110’,’’,‘3014662709’,‘h’,‘from-sip-external’,‘SIP/192.168.17.110-00000138’,’’,’’,3,’’,‘1497544042.4756’,‘1497544042.4756’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘LINKEDID_END’,{ts ‘2017-06-15 12:27:34.959244’},‘192.168.17.110’,‘19216817110’,‘19216817110’,’’,‘3014662709’,‘h’,‘from-sip-external’,‘SIP/192.168.17.110-00000138’,’’,’’,3,’’,‘1497544042.4756’,‘1497544042.4756’,’’,’’,’’)]
[2017-06-15 12:27:54] NOTICE[1794]: chan_sip.c:28201 handle_request_register: Registration from ‘“Reception” sip:[email protected]’ failed for ‘192.168.17.110:5062’ - Wrong password
– Attempting call on Local/s@tc-maint for application NoCDR() (Retry 1)
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_START’,{ts ‘2017-06-15 12:28:00.728207’},’’,’’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ae;1’,’’,’’,3,’’,‘1497544080.4757’,‘1497544080.4757’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_START’,{ts ‘2017-06-15 12:28:00.729430’},’’,’’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ae;2’,’’,’’,3,’’,‘1497544080.4758’,‘1497544080.4757’,’’,’’,’’)]
– Executing [s@tc-maint:1] NoCDR(“Local/s@tc-maint-000008ae;2”, “”) in new stack
– Executing [s@tc-maint:2] Set(“Local/s@tc-maint-000008ae;2”, “TCMAINT=RETURN”) in new stack
– Executing [s@tc-maint:3] Gosub(“Local/s@tc-maint-000008ae;2”, “timeconditions,1,1()”) in new stack
– Executing [1@timeconditions:1] Set(“Local/s@tc-maint-000008ae;2”, “DB(TC/1/INUSESTATE)=INUSE”) in new stack
– Executing [1@timeconditions:2] Set(“Local/s@tc-maint-000008ae;2”, “DB(TC/1/NOT_INUSESTATE)=NOT_INUSE”) in new stack
– Executing [1@timeconditions:3] GotoIfTime(“Local/s@tc-maint-000008ae;2”, “08:30-20:00,mon-thu,1-31,jan-dec,America/New_York?truestate”) in new stack
– Goto (timeconditions,1,14)
– Executing [1@timeconditions:14] GotoIf(“Local/s@tc-maint-000008ae;2”, “0?falsegoto”) in new stack
– Executing [1@timeconditions:15] ExecIf(“Local/s@tc-maint-000008ae;2”, “0?Set(DB(TC/1)=)”) in new stack
– Executing [1@timeconditions:16] Set(“Local/s@tc-maint-000008ae;2”, “DEVICE_STATE(Custom:TC1)=NOT_INUSE”) in new stack
– Executing [1@timeconditions:17] ExecIf(“Local/s@tc-maint-000008ae;2”, “0?Set(NOT_INUSE)”) in new stack
– Executing [1@timeconditions:18] GotoIf(“Local/s@tc-maint-000008ae;2”, “0?app-announcement-1,s,1”) in new stack
– Executing [1@timeconditions:19] Set(“Local/s@tc-maint-000008ae;2”, “TCSTATE=true”) in new stack
– Executing [1@timeconditions:20] Set(“Local/s@tc-maint-000008ae;2”, “TCOVERRIDE=false”) in new stack
– Executing [1@timeconditions:21] Return(“Local/s@tc-maint-000008ae;2”, “”) in new stack
– Executing [s@tc-maint:4] System(“Local/s@tc-maint-000008ae;2”, “/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 0”) in new stack
– Executing [s@tc-maint:5] Answer(“Local/s@tc-maint-000008ae;2”, “”) in new stack
> Channel Local/s@tc-maint-000008ae;1 was answered.
> Launching NoCDR() on Local/s@tc-maint-000008ae;1
[2017-06-15 12:28:00] NOTICE[8989]: pbx_spool.c:402 attempt_thread: Call completed to Local/s@tc-maint
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘ANSWER’,{ts ‘2017-06-15 12:28:00.962501’},‘0’,‘0’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ae;2’,‘Answer’,’’,3,’’,‘1497544080.4758’,‘1497544080.4757’,’’,’’,’’)]
== Spawn extension (tc-maint, s, 5) exited non-zero on ‘Local/s@tc-maint-000008ae;2’
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘ANSWER’,{ts ‘2017-06-15 12:28:00.962586’},‘0’,‘0’,‘0’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ae;1’,’’,’’,3,’’,‘1497544080.4757’,‘1497544080.4757’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘HANGUP’,{ts ‘2017-06-15 12:28:00.962654’},‘0’,‘0’,‘0’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ae;1’,’’,’’,3,’’,‘1497544080.4757’,‘1497544080.4757’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_END’,{ts ‘2017-06-15 12:28:00.962673’},‘0’,‘0’,‘0’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ae;1’,’’,’’,3,’’,‘1497544080.4757’,‘1497544080.4757’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘HANGUP’,{ts ‘2017-06-15 12:28:00.963659’},‘0’,‘0’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ae;2’,’’,’’,3,’’,‘1497544080.4758’,‘1497544080.4757’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘CHAN_END’,{ts ‘2017-06-15 12:28:00.963680’},‘0’,‘0’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ae;2’,’’,’’,3,’’,‘1497544080.4758’,‘1497544080.4757’,’’,’’,’’)]
> [INSERT INTO cel (eventtype,eventtime,cid_name,cid_num,cid_ani,cid_rdnis,cid_dnid,exten,context,channame,appname,appdata,amaflags,accountcode,uniqueid,linkedid,peer,userdeftype,userfield) VALUES (‘LINKEDID_END’,{ts ‘2017-06-15 12:28:00.963687’},‘0’,‘0’,’’,’’,’’,‘s’,‘tc-maint’,‘Local/s@tc-maint-000008ae;2’,’’,’’,3,’’,‘1497544080.4758’,‘1497544080.4757’,’’,’’,’’)]
[2017-06-15 12:28:25] NOTICE[1794]: chan_sip.c:28201 handle_request_register: Registration from ‘“Reception” sip:[email protected]’ failed for ‘192.168.17.110:5062’ - Wrong password
localhost*CLI>