rendered paste body[root@asterisk1 asterisk]# !tail
tail -f /var/log/asterisk/full
Dec 12 13:49:00 VERBOSE[5481] logger.c: < Call Ref: len= 2 (reference 1655/0x677) (Originator)
Dec 12 13:49:00 VERBOSE[5481] logger.c: < Message type: STATUS (125)
Dec 12 13:49:00 VERBOSE[5481] logger.c: < [08 03 82 e5 0d]
Dec 12 13:49:00 VERBOSE[5481] logger.c: < Cause (len= 5) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the local user (2)
Dec 12 13:49:00 VERBOSE[5481] logger.c: < Ext: 1 Cause: Message not compatible with call state (101), class = Protocol Error (6) ]
Dec 12 13:49:00 VERBOSE[5481] logger.c: < Cause data 1: 0d (13, SETUP ACKNOWLEDGE message)
Dec 12 13:49:00 VERBOSE[5481] logger.c: < [14 01 06]
Dec 12 13:49:00 VERBOSE[5481] logger.c: < Call State (len= 3) [ Ext: 0 Coding: CCITT (ITU) standard (0) Call state: Call Present (6)
Dec 12 13:49:00 VERBOSE[5481] logger.c: -- Processing IE 8 (cs0, Cause)
Dec 12 13:49:00 VERBOSE[5481] logger.c: -- Processing IE 20 (cs0, Call State)
Dec 12 13:49:03 DEBUG[25548] chan_zap.c: Enabled echo cancellation on channel 32
Dec 12 13:49:03 VERBOSE[25548] logger.c: -- Executing Dial("Zap/32-1", "Zap/g1/9744") in new stack
Dec 12 13:49:03 DEBUG[25548] dsp.c: dsp busy pattern set to 2500,500
Dec 12 13:49:03 VERBOSE[25548] logger.c: -- Requested transfer capability: 0x00 - SPEECH
Dec 12 13:49:03 VERBOSE[25548] logger.c: -- Called g1/9744
Dec 12 13:49:03 DEBUG[5482] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/8 span 3
Dec 12 13:49:03 VERBOSE[25548] logger.c: -- Zap/56-1 is proceeding passing it to Zap/32-1
Dec 12 13:49:03 DEBUG[25548] chan_zap.c: Requested indication 15 on channel Zap/32-1
Dec 12 13:49:03 DEBUG[25548] chan_zap.c: Received AST_CONTROL_PROCEEDING on Zap/32-1
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Protocol Discriminator: Q.931 (8) len=14
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Call Ref: len= 2 (reference 1655/0x677) (Terminator)
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Message type: CALL PROCEEDING (2)
Dec 12 13:49:03 VERBOSE[25548] logger.c: > [18 03 a9 83 88]
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Exclusive Dchan: 0
Dec 12 13:49:03 VERBOSE[25548] logger.c: > ChanSel: Reserved
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Ext: 1 Coding: 0 Number Specified Channel Type: 3
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Ext: 1 Channel: 8 ]
Dec 12 13:49:03 VERBOSE[25548] logger.c: > [1e 02 81 88]
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1)
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Ext: 1 Progress Description: Inband information or appropriate pattern now available. (8) ]
Dec 12 13:49:03 DEBUG[5482] chan_zap.c: Enabled echo cancellation on channel 56
Dec 12 13:49:03 VERBOSE[25548] logger.c: -- Zap/56-1 is ringing
Dec 12 13:49:03 DEBUG[25548] chan_zap.c: Requested indication 3 on channel Zap/32-1
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Protocol Discriminator: Q.931 (8) len=9
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Call Ref: len= 2 (reference 1655/0x677) (Terminator)
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Message type: ALERTING (1)
Dec 12 13:49:03 VERBOSE[25548] logger.c: > [1e 02 81 88]
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1)
Dec 12 13:49:03 VERBOSE[25548] logger.c: > Ext: 1 Progress Description: Inband information or appropriate pattern now available. (8) ]
Dec 12 13:49:03 VERBOSE[5481] logger.c: < Protocol Discriminator: Q.931 (8) len=13
Dec 12 13:49:03 VERBOSE[5481] logger.c: < Call Ref: len= 2 (reference 1655/0x677) (Originator)
Dec 12 13:49:03 VERBOSE[5481] logger.c: < Message type: STATUS (125)
Dec 12 13:49:03 VERBOSE[5481] logger.c: < [08 03 82 e3 1e]
Dec 12 13:49:03 VERBOSE[5481] logger.c: < Cause (len= 5) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the local user (2)
Dec 12 13:49:03 VERBOSE[5481] logger.c: < Ext: 1 Cause: Info. element nonexist or not implemented (99), class = Protocol Error (6) ]
Dec 12 13:49:03 VERBOSE[5481] logger.c: < Cause data 1: 1e (30, Progress Indicator IE)
Dec 12 13:49:03 VERBOSE[5481] logger.c: < [14 01 06]
Dec 12 13:49:03 VERBOSE[5481] logger.c: < Call State (len= 3) [ Ext: 0 Coding: CCITT (ITU) standard (0) Call state: Call Present (6)
Dec 12 13:49:03 VERBOSE[5481] logger.c: -- Processing IE 8 (cs0, Cause)
Dec 12 13:49:03 VERBOSE[5481] logger.c: -- Processing IE 20 (cs0, Call State)
Dec 12 13:49:06 DEBUG[5482] chan_zap.c: Echo cancellation already on
Dec 12 13:49:06 VERBOSE[25548] logger.c: -- Zap/56-1 answered Zap/32-1
Dec 12 13:49:06 DEBUG[25548] chan_zap.c: Requested indication -1 on channel Zap/32-1
Dec 12 13:49:06 VERBOSE[25548] logger.c: > Protocol Discriminator: Q.931 (8) len=14
Dec 12 13:49:06 VERBOSE[25548] logger.c: > Call Ref: len= 2 (reference 1655/0x677) (Terminator)
Dec 12 13:49:06 VERBOSE[25548] logger.c: > Message type: CONNECT (7)
Dec 12 13:49:06 VERBOSE[25548] logger.c: > [18 03 a9 83 88]
Dec 12 13:49:06 VERBOSE[25548] logger.c: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Exclusive Dchan: 0
Dec 12 13:49:06 VERBOSE[25548] logger.c: > ChanSel: Reserved
Dec 12 13:49:06 VERBOSE[25548] logger.c: > Ext: 1 Coding: 0 Number Specified Channel Type: 3
Dec 12 13:49:06 VERBOSE[25548] logger.c: > Ext: 1 Channel: 8 ]
Dec 12 13:49:06 VERBOSE[25548] logger.c: > [1e 02 81 82]
Dec 12 13:49:06 VERBOSE[25548] logger.c: > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1)
Dec 12 13:49:06 VERBOSE[25548] logger.c: > Ext: 1 Progress Description: Called equipment is non-ISDN. (2) ]
Dec 12 13:49:06 VERBOSE[25548] logger.c: -- Attempting native bridge of Zap/32-1 and Zap/56-1
Dec 12 13:49:06 DEBUG[25548] chan_zap.c: master: 32, slave: 56, nothingok: 0
Dec 12 13:49:06 DEBUG[25548] chan_zap.c: Stopping tones on 32/0 talking to 56/0
Dec 12 13:49:06 DEBUG[25548] chan_zap.c: Stopping tones on 56/0 talking to 32/0
Dec 12 13:49:06 DEBUG[25548] chan_zap.c: disabled echo cancellation on channel 32
Dec 12 13:49:06 DEBUG[25548] chan_zap.c: disabled echo cancellation on channel 56
Dec 12 13:49:06 DEBUG[25548] chan_zap.c: Making 56 slave to master 32 at 0
Dec 12 13:49:06 DEBUG[25548] chan_zap.c: Added 36 to conference 9/32
Dec 12 13:49:06 DEBUG[25548] chan_zap.c: Added 20 to conference 9/56
Dec 12 13:49:06 DEBUG[25548] chan_zap.c: Updated conferencing on 32, with 0 conference users
Dec 12 13:49:06 DEBUG[25548] chan_zap.c: Updated conferencing on 56, with 0 conference users
Dec 12 13:49:06 VERBOSE[5481] logger.c: < Protocol Discriminator: Q.931 (8) len=5
Dec 12 13:49:06 VERBOSE[5481] logger.c: < Call Ref: len= 2 (reference 1655/0x677) (Originator)
Dec 12 13:49:06 VERBOSE[5481] logger.c: < Message type: CONNECT ACKNOWLEDGE (15)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1114' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1113' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1106' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1101' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1111' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1115' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1105' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1103' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1109' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1112' to 60 seconds (requested 300)
Dec 12 13:49:12 DEBUG[5484] chan_sip.c: Stopping retransmission on '2c21bd610f15ee6c691a1f04456ce576@192.168.1.250' of Request 102: Match Found
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1102' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1108' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1107' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1110' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1104' to 60 seconds (requested 300)
Dec 12 13:49:12 NOTICE[5475] chan_iax2.c: Restricting registration for peer '1100' to 60 seconds (requested 300)
Dec 12 13:49:16 DEBUG[5484] chan_sip.c: Auto destroying call '5a2cb396e953418601e9919413d2dcfb@192.168.1.106'
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Protocol Discriminator: Q.931 (8) len=65
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Call Ref: len= 2 (reference 1656/0x678) (Originator)
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Message type: SETUP (5)
Dec 12 13:49:25 VERBOSE[5481] logger.c: < [04 03 80 90 a2]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Bearer Capability (len= 5) [ Ext: 1 Q.931 Std: 0 Info transfer capability: Speech (0)
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16)
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Ext: 1 User information layer 1: u-Law (34)
Dec 12 13:49:25 VERBOSE[5481] logger.c: < [18 03 a1 83 8a]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Preferred Dchan: 0
Dec 12 13:49:25 VERBOSE[5481] logger.c: < ChanSel: Reserved
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Ext: 1 Coding: 0 Number Specified Channel Type: 3
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Ext: 1 Channel: 10 ]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < [1c 17 9f 8b 01 00 a1 11 02 01 01 02 01 00 80 09 4c 41 44 55 45 2c 20 4d 4f]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Facility (len=25, codeset=0) [ Dec 12 13:49:25 VERBOSE[5481] logger.c: < Facility (len=25, codeset=0) [ 0x9f, 0x8b, 0x01, 0x00, 0xa1, 0x11, 0x02, 0x01, 0x01, 0x02, 0x01, 0x00, 0x80, 0x09, 'LADUE', 0x2c, 0x20, 'MO'Dec 12 13:49:25 VERBOSE[5481] logger.c: < Facility (len=25, codeset=0) [ 0x9f, 0x8b, 0x01, 0x00, 0xa1, 0x11, 0x02, 0x01, 0x01, 0x02, 0x01, 0x00, 0x80, 0x09, 'LADUE', 0x2c, 0x20, 'MO' ]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < [1e 02 82 83]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the local user (2)
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Ext: 1 Progress Description: Calling equipment is non-ISDN. (3) ]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < [6c 0c 21 82 33 31 34 37 39 31 30 30 36 32]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Calling Number (len=14) [ Ext: 0 TON: National Number (2) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1)
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Presentation: Presentation permitted, user number failed network screening (2) '3147910062' ]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < [70 05 a1 36 36 34 33]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Called Number (len= 7) [ Ext: 1 TON: National Number (2) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) '6643' ]
Dec 12 13:49:25 VERBOSE[5481] logger.c: -- Making new call for cr 1656
Dec 12 13:49:25 VERBOSE[5481] logger.c: -- Processing Q.931 Call Setup
Dec 12 13:49:25 VERBOSE[5481] logger.c: -- Processing IE 4 (cs0, Bearer Capability)
Dec 12 13:49:25 VERBOSE[5481] logger.c: -- Processing IE 24 (cs0, Channel Identification)
Dec 12 13:49:25 VERBOSE[5481] logger.c: -- Processing IE 28 (cs0, Facility)
Dec 12 13:49:25 VERBOSE[5481] logger.c: Handle Q.932 ROSE Invoke component
Dec 12 13:49:25 VERBOSE[5481] logger.c: -- Processing IE 30 (cs0, Progress Indicator)
Dec 12 13:49:25 VERBOSE[5481] logger.c: -- Processing IE 108 (cs0, Calling Party Number)
Dec 12 13:49:25 VERBOSE[5481] logger.c: -- Processing IE 112 (cs0, Called Party Number)
Dec 12 13:49:25 VERBOSE[5481] logger.c: > Protocol Discriminator: Q.931 (8) len=14
Dec 12 13:49:25 VERBOSE[5481] logger.c: > Call Ref: len= 2 (reference 1656/0x678) (Terminator)
Dec 12 13:49:25 VERBOSE[5481] logger.c: > Message type: SETUP ACKNOWLEDGE (13)
Dec 12 13:49:25 VERBOSE[5481] logger.c: > [18 03 a9 83 8a]
Dec 12 13:49:25 VERBOSE[5481] logger.c: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Exclusive Dchan: 0
Dec 12 13:49:25 VERBOSE[5481] logger.c: > ChanSel: Reserved
Dec 12 13:49:25 VERBOSE[5481] logger.c: > Ext: 1 Coding: 0 Number Specified Channel Type: 3
Dec 12 13:49:25 VERBOSE[5481] logger.c: > Ext: 1 Channel: 10 ]
Dec 12 13:49:25 VERBOSE[5481] logger.c: > [1e 02 81 82]
Dec 12 13:49:25 VERBOSE[5481] logger.c: > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1)
Dec 12 13:49:25 VERBOSE[5481] logger.c: > Ext: 1 Progress Description: Called equipment is non-ISDN. (2) ]
Dec 12 13:49:25 DEBUG[5481] dsp.c: dsp busy pattern set to 2500,500
Dec 12 13:49:25 VERBOSE[5481] logger.c: -- Accepting overlap call from '3147910062' to '6643' on channel 0/10, span 2
Dec 12 13:49:25 VERBOSE[25592] logger.c: -- Starting simple switch on 'Zap/34-1'
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Protocol Discriminator: Q.931 (8) len=13
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Call Ref: len= 2 (reference 1656/0x678) (Originator)
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Message type: STATUS (125)
Dec 12 13:49:25 VERBOSE[5481] logger.c: < [08 03 82 e5 0d]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Cause (len= 5) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the local user (2)
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Ext: 1 Cause: Message not compatible with call state (101), class = Protocol Error (6) ]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Cause data 1: 0d (13, SETUP ACKNOWLEDGE message)
Dec 12 13:49:25 VERBOSE[5481] logger.c: < [14 01 06]
Dec 12 13:49:25 VERBOSE[5481] logger.c: < Call State (len= 3) [ Ext: 0 Coding: CCITT (ITU) standard (0) Call state: Call Present (6)
Dec 12 13:49:25 VERBOSE[5481] logger.c: -- Processing IE 8 (cs0, Cause)
Dec 12 13:49:25 VERBOSE[5481] logger.c: -- Processing IE 20 (cs0, Call State)
Dec 12 13:49:27 DEBUG[5484] chan_sip.c: Stopping retransmission on '0f64eaf418ba68565d1aa3937889adc6@192.168.1.250' of Request 102: Match Found
Dec 12 13:49:28 DEBUG[25592] chan_zap.c: Enabled echo cancellation on channel 34
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Macro("Zap/34-1", "exten-vm|6643|6643") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Macro("Zap/34-1", "user-callerid") in new stack
Dec 12 13:49:28 DEBUG[25592] pbx.c: Expression result is '0'
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing GotoIf("Zap/34-1", "0?report") in new stack
Dec 12 13:49:28 DEBUG[25592] pbx.c: Not taking any branch
Dec 12 13:49:28 DEBUG[25592] pbx.c: Expression result is '0'
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing GotoIf("Zap/34-1", "0?start") in new stack
Dec 12 13:49:28 DEBUG[25592] pbx.c: Not taking any branch
Dec 12 13:49:28 DEBUG[25592] pbx.c: Function result is '3147910062'
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Set("Zap/34-1", "REALCALLERIDNUM=3147910062") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing NoOp("Zap/34-1", "REALCALLERIDNUM is 3147910062") in new stack
Dec 12 13:49:28 DEBUG[25592] db.c: Unable to find key '3147910062/user' in family 'DEVICE'
Dec 12 13:49:28 DEBUG[25592] func_db.c: DB: DEVICE/3147910062/user not found in database.
Dec 12 13:49:28 DEBUG[25592] pbx.c: Function result is ''
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Set("Zap/34-1", "AMPUSER=") in new stack
Dec 12 13:49:28 DEBUG[25592] db.c: Unable to find key '/cidname' in family 'AMPUSER'
Dec 12 13:49:28 DEBUG[25592] func_db.c: DB: AMPUSER//cidname not found in database.
Dec 12 13:49:28 DEBUG[25592] pbx.c: Function result is ''
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Set("Zap/34-1", "AMPUSERCIDNAME=") in new stack
Dec 12 13:49:28 DEBUG[25592] pbx.c: Expression result is '1'
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing GotoIf("Zap/34-1", "1?report") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Goto (macro-user-callerid,s,10)
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing NoOp("Zap/34-1", "TTL: ARG1: 6643") in new stack
Dec 12 13:49:28 DEBUG[25592] pbx.c: Expression result is '0'
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing GotoIf("Zap/34-1", "0?continue") in new stack
Dec 12 13:49:28 DEBUG[25592] pbx.c: Not taking any branch
Dec 12 13:49:28 DEBUG[25592] pbx.c: Expression result is '1'
Dec 12 13:49:28 DEBUG[25592] pbx.c: Expression result is '-1'
Dec 12 13:49:28 DEBUG[25592] pbx.c: Function result is '64'
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Set("Zap/34-1", "_TTL=64") in new stack
Dec 12 13:49:28 DEBUG[25592] pbx.c: Expression result is '1'
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing GotoIf("Zap/34-1", "1?continue") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Goto (macro-user-callerid,s,20)
Dec 12 13:49:28 DEBUG[25592] pbx.c: Function result is '"LADUE, MO" <3147910062>'
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing NoOp("Zap/34-1", "Using CallerID "LADUE, MO" <3147910062>") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing NoOp("Zap/34-1", "CAME FROM: ") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Set("Zap/34-1", "RRNODEST=") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Set("Zap/34-1", "_NODEST=") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Set("Zap/34-1", "FROMCONTEXT=exten-vm") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Set("Zap/34-1", "VMBOX=6643") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Set("Zap/34-1", "EXTTOCALL=6643") in new stack
Dec 12 13:49:28 DEBUG[25592] db.c: Unable to find key '6643' in family 'CFU'
Dec 12 13:49:28 DEBUG[25592] func_db.c: DB: CFU/6643 not found in database.
Dec 12 13:49:28 DEBUG[25592] pbx.c: Function result is ''
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Set("Zap/34-1", "CFUEXT=") in new stack
Dec 12 13:49:28 DEBUG[25592] pbx.c: Expression result is '1'
Dec 12 13:49:28 DEBUG[25592] pbx.c: Expression result is '0'
Dec 12 13:49:28 DEBUG[25592] pbx.c: Expression result is '1'
Dec 12 13:49:28 DEBUG[25592] pbx.c: Function result is '15'
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Set("Zap/34-1", "RT=15") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing Macro("Zap/34-1", "record-enable|6643|IN") in new stack
Dec 12 13:49:28 DEBUG[25592] pbx.c: Function result is '0'
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing GotoIf("Zap/34-1", "0 > 0?2:4") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Goto (macro-record-enable,s,4)
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Executing DeadAGI("Zap/34-1", "recordingcheck|20061212-134928|1165952965.7756") in new stack
Dec 12 13:49:28 VERBOSE[25592] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Protocol Discriminator: Q.931 (8) len=65
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Call Ref: len= 2 (reference 1656/0x678) (Originator)
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Message type: SETUP (5)
Dec 12 13:49:29 VERBOSE[5481] logger.c: < [04 03 80 90 a2]
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Bearer Capability (len= 5) [ Ext: 1 Q.931 Std: 0 Info transfer capability: Speech (0)
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16)
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Ext: 1 User information layer 1: u-Law (34)
Dec 12 13:49:29 VERBOSE[5481] logger.c: < [18 03 a1 83 8a]
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Preferred Dchan: 0
Dec 12 13:49:29 VERBOSE[5481] logger.c: < ChanSel: Reserved
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Ext: 1 Coding: 0 Number Specified Channel Type: 3
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Ext: 1 Channel: 10 ]
Dec 12 13:49:29 VERBOSE[5481] logger.c: < [1c 17 9f 8b 01 00 a1 11 02 01 01 02 01 00 80 09 4c 41 44 55 45 2c 20 4d 4f]
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Facility (len=25, codeset=0) [ Dec 12 13:49:29 VERBOSE[5481] logger.c: < Facility (len=25, codeset=0) [ 0x9f, 0x8b, 0x01, 0x00, 0xa1, 0x11, 0x02, 0x01, 0x01, 0x02, 0x01, 0x00, 0x80, 0x09, 'LADUE', 0x2c, 0x20, 'MO'Dec 12 13:49:29 VERBOSE[5481] logger.c: < Facility (len=25, codeset=0) [ 0x9f, 0x8b, 0x01, 0x00, 0xa1, 0x11, 0x02, 0x01, 0x01, 0x02, 0x01, 0x00, 0x80, 0x09, 'LADUE', 0x2c, 0x20, 'MO' ]
Dec 12 13:49:29 VERBOSE[5481] logger.c: < [1e 02 82 83]
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the local user (2)
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Ext: 1 Progress Description: Calling equipment is non-ISDN. (3) ]
Dec 12 13:49:29 VERBOSE[5481] logger.c: < [6c 0c 21 82 33 31 34 37 39 31 30 30 36 32]
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Calling Number (len=14) [ Ext: 0 TON: National Number (2) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1)
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Presentation: Presentation permitted, user number failed network screening (2) '3147910062' ]
Dec 12 13:49:29 VERBOSE[5481] logger.c: < [70 05 a1 36 36 34 33]
Dec 12 13:49:29 VERBOSE[5481] logger.c: < Called Number (len= 7) [ Ext: 1 TON: National Number (2) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) '6643' ]
Dec 12 13:49:29 VERBOSE[5481] logger.c: -- Processing Q.931 Call Setup
Dec 12 13:49:29 VERBOSE[5481] logger.c: -- Processing IE 4 (cs0, Bearer Capability)
Dec 12 13:49:29 VERBOSE[5481] logger.c: -- Processing IE 24 (cs0, Channel Identification)
Dec 12 13:49:29 VERBOSE[5481] logger.c: -- Processing IE 28 (cs0, Facility)
Dec 12 13:49:29 VERBOSE[5481] logger.c: Handle Q.932 ROSE Invoke component
Dec 12 13:49:29 VERBOSE[5481] logger.c: -- Processing IE 30 (cs0, Progress Indicator)
Dec 12 13:49:29 VERBOSE[5481] logger.c: -- Processing IE 108 (cs0, Calling Party Number)
Dec 12 13:49:29 VERBOSE[5481] logger.c: -- Processing IE 112 (cs0, Called Party Number)
Dec 12 13:49:31 VERBOSE[25592] logger.c: recordingcheck|20061212-134928|1165952965.7756: Inbound recording not enabled
Dec 12 13:49:31 VERBOSE[25592] logger.c: -- AGI Script recordingcheck completed, returning 0
Dec 12 13:49:31 VERBOSE[25592] logger.c: -- Executing NoOp("Zap/34-1", "No recording needed") in new stack
Dec 12 13:49:31 DEBUG[25592] pbx.c: Expression result is '0'
Dec 12 13:49:31 VERBOSE[25592] logger.c: -- Executing GotoIf("Zap/34-1", "0?dolocaldial|1") in new stack
Dec 12 13:49:31 DEBUG[25592] pbx.c: Not taking any branch
Dec 12 13:49:31 VERBOSE[25592] logger.c: -- Executing Macro("Zap/34-1", "dial|15|tr|6643") in new stack
Dec 12 13:49:31 VERBOSE[25592] logger.c: -- Executing DeadAGI("Zap/34-1", "dialparties.agi") in new stack
Dec 12 13:49:31 VERBOSE[25592] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Dec 12 13:49:32 DEBUG[5484] chan_sip.c: Auto destroying call '8bccc3064f55ca2b1d4800cc42a8f7df@192.168.1.105'
Dec 12 13:49:33 VERBOSE[5481] logger.c: < Protocol Discriminator: Q.931 (8) len=9
Dec 12 13:49:33 VERBOSE[5481] logger.c: < Call Ref: len= 2 (reference 1656/0x678) (Originator)
Dec 12 13:49:33 VERBOSE[5481] logger.c: < Message type: DISCONNECT (69)
Dec 12 13:49:33 VERBOSE[5481] logger.c: < [08 02 82 e6]
Dec 12 13:49:33 VERBOSE[5481] logger.c: < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the local user (2)
Dec 12 13:49:33 VERBOSE[5481] logger.c: < Ext: 1 Cause: Recover on timer expiry (102), class = Protocol Error (6) ]
Dec 12 13:49:33 VERBOSE[5481] logger.c: -- Processing IE 8 (cs0, Cause)
Dec 12 13:49:33 VERBOSE[5481] logger.c: -- Channel 0/10, span 2 got hangup request
Dec 12 13:49:33 VERBOSE[25592] logger.c: dialparties.agi: Starting New Dialparties.agi
Dec 12 13:49:33 VERBOSE[25592] logger.c: dialparties.agi: priority is 1
Dec 12 13:49:33 VERBOSE[25592] logger.c: dialparties.agi: Caller ID name is 'LADUE, MO' number is '3147910062'
Dec 12 13:49:33 VERBOSE[25592] logger.c: dialparties.agi: Methodology of ring is 'none'
Dec 12 13:49:33 VERBOSE[25592] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE'
Dec 12 13:49:33 VERBOSE[25592] logger.c: > dialparties.agi: RINGGROUP_INDEX: ''
Dec 12 13:49:33 VERBOSE[25592] logger.c: -- dialparties.agi: Added extension 6643 to extension map
Dec 12 13:49:33 DEBUG[25592] db.c: Unable to find key '6643' in family 'CF'
Dec 12 13:49:33 VERBOSE[25592] logger.c: -- dialparties.agi: Extension 6643 cf is disabled
Dec 12 13:49:33 DEBUG[25592] db.c: Unable to find key '6643' in family 'DND'
Dec 12 13:49:33 VERBOSE[25592] logger.c: -- dialparties.agi: Extension 6643 do not disturb is disabled
Dec 12 13:49:33 DEBUG[25592] db.c: Unable to find key '6643' in family 'CW'
Dec 12 13:49:33 DEBUG[25592] db.c: Unable to find key '6643' in family 'CFB'
Dec 12 13:49:33 DEBUG[25592] db.c: Unable to find key '6643' in family 'CFU'
Dec 12 13:49:33 VERBOSE[25592] logger.c: > dialparties.agi: extnum: 6643
Dec 12 13:49:33 VERBOSE[25592] logger.c: > dialparties.agi: exthascw: 0
Dec 12 13:49:33 VERBOSE[25592] logger.c: > dialparties.agi: exthascfb: 0
Dec 12 13:49:33 VERBOSE[25592] logger.c: > dialparties.agi: extcfb:
Dec 12 13:49:33 VERBOSE[25592] logger.c: > dialparties.agi: exthascfu: 0
Dec 12 13:49:33 VERBOSE[25592] logger.c: > dialparties.agi: extcfu:
Dec 12 13:49:33 DEBUG[25597] manager.c: Manager received command 'login'
Dec 12 13:49:33 VERBOSE[25597] logger.c: == Parsing '/etc/asterisk/manager.conf': Dec 12 13:49:33 VERBOSE[25597] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Dec 12 13:49:33 VERBOSE[25597] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Dec 12 13:49:33 VERBOSE[25597] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Dec 12 13:49:33 DEBUG[25597] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Dec 12 13:49:33 DEBUG[25597] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Dec 12 13:49:33 DEBUG[25597] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Dec 12 13:49:33 DEBUG[25597] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Dec 12 13:49:33 VERBOSE[25597] logger.c: == Manager 'admin' logged on from 127.0.0.1
Dec 12 13:49:33 DEBUG[25597] manager.c: Manager received command 'ExtensionState'
Dec 12 13:49:33 DEBUG[25597] manager.c: Manager received command 'Logoff'
Dec 12 13:49:33 VERBOSE[25597] logger.c: == Manager 'admin' logged off from 127.0.0.1
Dec 12 13:49:34 VERBOSE[25592] logger.c: > dialparties.agi: ExtensionState: 0
Dec 12 13:49:34 VERBOSE[25592] logger.c: dialparties.agi: Extension 6643 has ExtensionState: 0
Dec 12 13:49:34 VERBOSE[25592] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 6643
Dec 12 13:49:34 VERBOSE[25592] logger.c: -- dialparties.agi: dbset CALLTRACE/6643 to 3147910062
Dec 12 13:49:34 VERBOSE[25592] logger.c: -- AGI Script dialparties.agi completed, returning 0
Dec 12 13:49:34 DEBUG[25592] app_macro.c: Extension s, macroexten 6643, priority 9 returned normally even though call was hung up
Dec 12 13:49:34 DEBUG[25592] app_macro.c: Extension s, macroexten 6643, priority 12 returned normally even though call was hung up
Dec 12 13:49:34 DEBUG[25592] pbx.c: Extension 6643, priority 1 returned normally even though call was hung up
Dec 12 13:49:34 DEBUG[25592] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Dec 12 13:49:34 DEBUG[25592] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2006-12-12 13:49:28','\"LADUE, MO\" <3147910062>','3147910062','6643','from-pstn', 'Zap/34-1','','DeadAGI','dialparties.agi',6,0,'NO ANSWER',2,'','1165952965.7756')
Dec 12 13:49:34 DEBUG[25592] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/34-1
Dec 12 13:49:34 DEBUG[25592] chan_zap.c: Hangup: channel: 34 index = 0, normal = 22, callwait = -1, thirdcall = -1
Dec 12 13:49:34 DEBUG[25592] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call
Dec 12 13:49:34 VERBOSE[25592] logger.c: NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Disconnect Indication, peerstate Disconnect Request
Dec 12 13:49:34 VERBOSE[25592] logger.c: > Protocol Discriminator: Q.931 (8) len=9
Dec 12 13:49:34 VERBOSE[25592] logger.c: > Call Ref: len= 2 (reference 1656/0x678) (Terminator)
Dec 12 13:49:34 VERBOSE[25592] logger.c: > Message type: RELEASE (77)
Dec 12 13:49:34 VERBOSE[25592] logger.c: > [08 02 81 e6]
Dec 12 13:49:34 VERBOSE[25592] logger.c: > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1)
Dec 12 13:49:34 VERBOSE[25592] logger.c: > Ext: 1 Cause: Recover on timer expiry (102), class = Protocol Error (6) ]
Dec 12 13:49:34 DEBUG[25592] chan_zap.c: disabled echo cancellation on channel 34
Dec 12 13:49:34 DEBUG[25592] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/34-1
Dec 12 13:49:34 DEBUG[25592] chan_zap.c: Updated conferencing on 34, with 0 conference users
Dec 12 13:49:34 DEBUG[25592] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/34-1
Dec 12 13:49:34 DEBUG[25592] chan_zap.c: disabled echo cancellation on channel 34
Dec 12 13:49:34 VERBOSE[25592] logger.c: -- Hungup 'Zap/34-1'
Dec 12 13:49:34 VERBOSE[5481] logger.c: < Protocol Discriminator: Q.931 (8) len=5
Dec 12 13:49:34 VERBOSE[5481] logger.c: < Call Ref: len= 2 (reference 1656/0x678) (Originator)
Dec 12 13:49:34 VERBOSE[5481] logger.c: < Message type: RELEASE COMPLETE (90)
Dec 12 13:49:34 VERBOSE[5481] logger.c: NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null
Dec 12 13:49:34 VERBOSE[5481] logger.c: NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null