[2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:1] NoOp("SIP/94144-035afab5", "Redundancy Test") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:2] GotoIf("SIP/94144-035afab5", "0?PlayRecording:OK") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Goto (entry,5941445116411113,6) [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:6] NoOp("SIP/94144-035afab5", "192.168.168.41^192.168.22.41-1345") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:7] Set("SIP/94144-035afab5", "STARTTIME=2015-01-21 20:01:00") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:8] Set("SIP/94144-035afab5", "SHARED(CONNECTTIME)=") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:9] Set("SIP/94144-035afab5", "SHARED(OUTCODEC)=0") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:10] Set("SIP/94144-035afab5", "SHARED(BLEGSIPCALLIP)=") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:11] Set("SIP/94144-035afab5", "_INCHANNEL=SIP/94144-035afab5") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:12] Set("SIP/94144-035afab5", "ClientIP=192.168.23") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:13] SIPAddHeader("SIP/94144-035afab5", "SessionID: 01421870460002941490") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:14] SIPAddHeader("SIP/94144-035afab5", "InSIPCallID: 566577-3630859052-694814@SBC2.mydomain.com") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5941445116411113@entry:15] Goto("SIP/94144-035afab5", "softswitch,5116411113,1") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Goto (softswitch,5116411113,1) [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:1] NoOp("SIP/94144-035afab5", "softswitch") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:2] GotoIf("SIP/94144-035afab5", "1?keep_going") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Goto (softswitch,5116411113,9) [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:9] NoOp("SIP/94144-035afab5", "") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:10] GotoIf("SIP/94144-035afab5", "1?keep_going3") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Goto (softswitch,5116411113,15) [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:15] NoOp("SIP/94144-035afab5", "") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:16] Set("SIP/94144-035afab5", "LocalActive=1") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:17] Set("SIP/94144-035afab5", "LocalCount=12") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:18] Set("SIP/94144-035afab5", "SSAPPSNUM=12") in new stack [2015-01-21 20:01:00.200] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:19] Set("SIP/94144-035afab5", "NUMBER=9") in new stack [2015-01-21 20:01:00.201] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:20] Set("SIP/94144-035afab5", "APPNUM=9") in new stack [2015-01-21 20:01:00.201] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:21] Set("SIP/94144-035afab5", "COUNTER=0") in new stack [2015-01-21 20:01:00.201] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:22] GotoIf("SIP/94144-035afab5", "0?not_found") in new stack [2015-01-21 20:01:00.201] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:23] Set("SIP/94144-035afab5", "SSApp=NO") in new stack [2015-01-21 20:01:00.201] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:24] Set("SIP/94144-035afab5", "SSAPPSIPPORT=192.168.170.72:3003") in new stack [2015-01-21 20:01:00.201] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:25] NoOp("SIP/94144-035afab5", " CALL-TRACE [01421870460002941490] CallStart [SIP/94144-035afab5] [3980043]->[5116411113] to 192.168.170.72:30030 [1421870460]") in new stack [2015-01-21 20:01:00.201] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:26] GotoIf("SIP/94144-035afab5", "1?NOCODECCHANGE") in new stack [2015-01-21 20:01:00.201] VERBOSE[15332][C-0195216a] pbx.c: -- Goto (softswitch,5116411113,32) [2015-01-21 20:01:00.201] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [5116411113@softswitch:32] AGI("SIP/94144-035afab5", "agi://192.168.170.72:30030/SoftSwitchApp 192.168.170.72:3003 2 01421870460002941490") in new stack [2015-01-21 20:01:00.262] VERBOSE[15332][C-0195216a] func_timeout.c: -- Channel will hangup at 2015-01-21 20:02:04.262 UTC. [2015-01-21 20:01:00.272] VERBOSE[15332][C-0195216a] res_agi.c: -- AGI Script Executing Application: (SIPAddHeader) Options: (P-hint: Outbound_IP_Port: [ 192.168.168.41^192.168.22.41 5060 ].) [2015-01-21 20:01:00.275] VERBOSE[15332][C-0195216a] func_timeout.c: -- Channel will hangup at 2015-01-21 22:31:55.275 UTC. [2015-01-21 20:01:00.275] VERBOSE[15332][C-0195216a] res_agi.c: -- AGI Script Executing Application: (DIAL) Options: (SIP/C10846-T1378/553435116411113,60,M(ConnectMacro^agi://192.168.170.72:30035/ConnectionEstablished^3941648^SIP/94144-035afab5^10846^5116411113)L(8996000)g) [2015-01-21 20:01:00.275] VERBOSE[15332][C-0195216a] features.c: -- Setting call duration limit to 8996.000 seconds. [2015-01-21 20:01:00.276] VERBOSE[15332][C-0195216a] netsock2.c: == Using SIP RTP CoS mark 5 [2015-01-21 20:01:00.277] VERBOSE[15332][C-0195216a] app_dial.c: -- Called SIP/C10846-T1378/553435116411113 [2015-01-21 20:01:04.074] VERBOSE[15332][C-0195216a] app_dial.c: -- SIP/C10846-T1378-035afac7 is making progress passing it to SIP/94144-035afab5 [2015-01-21 20:01:33.908] VERBOSE[15332][C-0195216a] app_dial.c: -- SIP/C10846-T1378-035afac7 answered SIP/94144-035afab5 [2015-01-21 20:01:33.908] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [s@macro-ConnectMacro:1] NoOp("SIP/C10846-T1378-035afac7", "01421870460002941670") in new stack [2015-01-21 20:01:33.908] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [s@macro-ConnectMacro:2] Set("SIP/C10846-T1378-035afac7", "SHARED(CONNECTTIME,SIP/94144-035afab5)=2015-01-21 20:01:33") in new stack [2015-01-21 20:01:33.909] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [s@macro-ConnectMacro:3] Set("SIP/C10846-T1378-035afac7", "TIMEOUT(absolute)=12") in new stack [2015-01-21 20:01:33.909] VERBOSE[15332][C-0195216a] func_timeout.c: -- Channel will hangup at 2015-01-21 20:01:45.909 UTC. [2015-01-21 20:01:33.909] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [s@macro-ConnectMacro:4] AGI("SIP/C10846-T1378-035afac7", "agi://192.168.170.72:30035/ConnectionEstablished 3941648 1421870493 SIP/C10846-T1378-035afac7)") in new stack [2015-01-21 20:01:34.039] VERBOSE[15332][C-0195216a] func_timeout.c: -- Channel will hangup at 2015-01-21 22:31:30.039 UTC. [2015-01-21 20:01:34.041] VERBOSE[15332][C-0195216a] res_agi.c: -- AGI Script agi://192.168.170.72:30035/ConnectionEstablished 3941648 1421870493 SIP/C10846-T1378-035afac7) completed, returning 0 [2015-01-21 20:01:34.041] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [s@macro-ConnectMacro:5] GotoIf("SIP/C10846-T1378-035afac7", "1?ok:not_ok") in new stack [2015-01-21 20:01:34.041] VERBOSE[15332][C-0195216a] pbx.c: -- Goto (macro-ConnectMacro,s,10) [2015-01-21 20:01:34.041] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [s@macro-ConnectMacro:10] NoOp("SIP/C10846-T1378-035afac7", "OK") in new stack [2015-01-21 20:01:34.041] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [s@macro-ConnectMacro:11] Set("SIP/C10846-T1378-035afac7", "SHARED(OUTCODEC,SIP/94144-035afab5)=g729:20") in new stack [2015-01-21 20:01:34.041] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [s@macro-ConnectMacro:12] Set("SIP/C10846-T1378-035afac7", "SHARED(BLEGSIPCALLIP,SIP/94144-035afab5)=7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060") in new stack [2015-01-21 20:01:34.041] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [s@macro-ConnectMacro:13] NoOp("SIP/C10846-T1378-035afac7", " CALL-TRACE [01421870460002941490] CallConnect OK Channel[SIP/94144-035afab5]->[SIP/C10846-T1378-035afac7] OutTrunk[10846] DNIS[5116411113] [1421870494]") in new stack [2015-01-21 20:02:31.004] NOTICE[5325] chan_sip.c: Disconnecting call 'SIP/94144-035afab5' for lack of RTP activity in 30 seconds [2015-01-21 20:02:33.376] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:03:05.376] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:03:37.377] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:04:09.376] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:04:41.376] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:05:13.377] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:05:45.376] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:06:17.376] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:06:49.377] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:07:21.376] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:07:53.376] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:08:25.376] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:08:57.377] WARNING[5325] chan_sip.c: Autodestruct on dialog '566577-3630859052-694814@SBC2.mydomain.com' with owner SIP/94144-035afab5 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:02:31.004] NOTICE[5325] chan_sip.c: Disconnecting call 'SIP/C10846-T1378-035afac7' for lack of RTP activity in 30 seconds [2015-01-21 20:04:20.109] WARNING[5325] chan_sip.c: Autodestruct on dialog '7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060' with owner SIP/C10846-T1378-035afac7 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:04:52.108] WARNING[5325] chan_sip.c: Autodestruct on dialog '7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060' with owner SIP/C10846-T1378-035afac7 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:05:24.108] WARNING[5325] chan_sip.c: Autodestruct on dialog '7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060' with owner SIP/C10846-T1378-035afac7 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:05:56.108] WARNING[5325] chan_sip.c: Autodestruct on dialog '7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060' with owner SIP/C10846-T1378-035afac7 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:06:28.109] WARNING[5325] chan_sip.c: Autodestruct on dialog '7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060' with owner SIP/C10846-T1378-035afac7 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:07:00.108] WARNING[5325] chan_sip.c: Autodestruct on dialog '7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060' with owner SIP/C10846-T1378-035afac7 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:07:32.108] WARNING[5325] chan_sip.c: Autodestruct on dialog '7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060' with owner SIP/C10846-T1378-035afac7 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:08:04.108] WARNING[5325] chan_sip.c: Autodestruct on dialog '7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060' with owner SIP/C10846-T1378-035afac7 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:08:36.108] WARNING[5325] chan_sip.c: Autodestruct on dialog '7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060' with owner SIP/C10846-T1378-035afac7 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:09:08.109] WARNING[5325] chan_sip.c: Autodestruct on dialog '7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060' with owner SIP/C10846-T1378-035afac7 in place (Method: BYE). Rescheduling destruction for 10000 ms [2015-01-21 20:09:19.425] VERBOSE[15332][C-0195216a] res_agi.c: -- AGI Script agi://192.168.170.72:30030/SoftSwitchApp 192.168.170.72:3003 2 01421870460002941490 completed, returning 4 [2015-01-21 20:09:19.425] VERBOSE[15332][C-0195216a] pbx.c: == Spawn extension (softswitch, 5116411113, 32) exited non-zero on 'SIP/94144-035afab5' [2015-01-21 20:09:19.426] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [h@softswitch:1] NoOp("SIP/94144-035afab5", "CallObj=3941648 1421870460002941490 start[2015-01-21 20:01:00] answer[2015-01-21 20:01:33] end[2015-01-21 20:09:19]") in new stack [2015-01-21 20:09:19.426] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [h@softswitch:2] NoOp("SIP/94144-035afab5", "CallEnd=DONE SHARED(OUTCODEC)[g729:20] SHARED(BLEGSIPCALLIP)[7514859678c01b1205bd56de158ba7c0@192.168.170.99:5060] RTPAUDIOQOS[ssrc=685526271;themssrc=170021613;lp=0;rxjitter=0.000647;rxcount=2857;txjitter=0.000000;txcount=2856;rlp=0;rtt=0.054000] RTPAUDIOQOSBRIDGED[ssrc=412236102;themssrc=1464965981;lp=3;rxjitter=0.000099;rxcount=2871;txjitter=0.000000;txcount=2851;rlp=0;rtt=0.000000]") in new stack [2015-01-21 20:09:19.426] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [h@softswitch:3] Set("SIP/94144-035afab5", "ENDTIME=1421870959") in new stack [2015-01-21 20:09:19.426] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [h@softswitch:4] NoOp("SIP/94144-035afab5", "CALL-TRACE [01421870460002941490] CallEnd InTrunk[1345] [1421870959]") in new stack [2015-01-21 20:09:19.426] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [h@softswitch:5] GotoIf("SIP/94144-035afab5", "1?end") in new stack [2015-01-21 20:09:19.426] VERBOSE[15332][C-0195216a] pbx.c: -- Goto (softswitch,h,15) [2015-01-21 20:09:19.426] VERBOSE[15332][C-0195216a] pbx.c: -- Executing [h@softswitch:15] Set("SIP/94144-035afab5", "RESPONSE=") in new stack