[Apr 3 17:19:53] VERBOSE[30883] netsock.c: == Using SIP RTP CoS mark 5 [Apr 3 17:19:53] DEBUG[30883] chan_sip.c: Setting NAT on RTP to On [Apr 3 17:19:53] DEBUG[30883] chan_sip.c: Allocating new SIP dialog for 0jkdAv75bzVipdsicH9pR0nnoR7dTQ2i - INVITE (With RTP) [Apr 3 17:19:53] DEBUG[30883] chan_sip.c: Setting NAT on RTP to On [Apr 3 17:19:53] DEBUG[30883] chan_sip.c: Stopping retransmission on '0jkdAv75bzVipdsicH9pR0nnoR7dTQ2i' of Response 32721: Match Found [Apr 3 17:19:53] DEBUG[30883] chan_sip.c: Setting NAT on RTP to On [Apr 3 17:19:53] DEBUG[30883] chan_sip.c: Checking SIP call limits for device 2000 [Apr 3 17:19:53] DEBUG[31920] pbx.c: Launching 'Gosub' [Apr 3 17:19:53] VERBOSE[31920] pbx.c: -- Executing [5130582@internal:1] Gosub("SIP/2000-0000005e", "gv-out,s,1(19895130582)") in new stack [Apr 3 17:19:53] DEBUG[31920] app_stack.c: Channel SIP/2000-0000005e has no datastore, so we're allocating one. [Apr 3 17:19:53] DEBUG[31920] app_stack.c: Setting 'ARG1' to '19895130582' [Apr 3 17:19:53] DEBUG[31920] pbx.c: Launching 'Wait' [Apr 3 17:19:53] VERBOSE[31920] pbx.c: -- Executing [s@gv-out:1] Wait("SIP/2000-0000005e", "1") in new stack [Apr 3 17:19:54] DEBUG[31920] pbx.c: Launching 'Set' [Apr 3 17:19:54] VERBOSE[31920] pbx.c: -- Executing [s@gv-out:2] Set("SIP/2000-0000005e", "ACCTNAME=henshaw.barnt") in new stack [Apr 3 17:19:54] DEBUG[31920] pbx.c: Launching 'Set' [Apr 3 17:19:54] VERBOSE[31920] pbx.c: -- Executing [s@gv-out:3] Set("SIP/2000-0000005e", "ACCTPASS=400babies") in new stack [Apr 3 17:19:54] DEBUG[31920] pbx.c: Launching 'Set' [Apr 3 17:19:54] VERBOSE[31920] pbx.c: -- Executing [s@gv-out:4] Set("SIP/2000-0000005e", "RINGBACK=14156513741") in new stack [Apr 3 17:19:54] DEBUG[31920] pbx.c: Launching 'Set' [Apr 3 17:19:54] VERBOSE[31920] pbx.c: -- Executing [s@gv-out:5] Set("SIP/2000-0000005e", "CALLPARK=7020") in new stack [Apr 3 17:19:54] DEBUG[31920] pbx.c: Launching 'Playback' [Apr 3 17:19:54] VERBOSE[31920] pbx.c: -- Executing [s@gv-out:6] Playback("SIP/2000-0000005e", "pls-wait-connect-call") in new stack [Apr 3 17:19:54] DEBUG[31920] chan_sip.c: SIP answering channel: SIP/2000-0000005e [Apr 3 17:19:54] DEBUG[31920] chan_sip.c: Setting framing from config on incoming call [Apr 3 17:19:54] DEBUG[31920] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True [Apr 3 17:19:54] DEBUG[31920] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Apr 3 17:19:54] DEBUG[30883] chan_sip.c: Stopping retransmission on '0jkdAv75bzVipdsicH9pR0nnoR7dTQ2i' of Response 32722: Match Found [Apr 3 17:19:54] WARNING[31920] file.c: File pls-wait-connect-call does not exist in any format [Apr 3 17:19:54] WARNING[31920] file.c: Unable to open pls-wait-connect-call (format 0x4 (ulaw)): No such file or directory [Apr 3 17:19:54] WARNING[31920] app_playback.c: ast_streamfile failed on SIP/2000-0000005e for pls-wait-connect-call [Apr 3 17:19:54] DEBUG[31920] pbx.c: Launching 'System' [Apr 3 17:19:54] VERBOSE[31920] pbx.c: -- Executing [s@gv-out:7] System("SIP/2000-0000005e", "gvoice -e henshaw.barnt -p 400babies call 19895130582 14156513741") in new stack [Apr 3 17:19:58] DEBUG[31920] pbx.c: Launching 'Set' [Apr 3 17:19:58] VERBOSE[31920] pbx.c: -- Executing [s@gv-out:8] Set("SIP/2000-0000005e", "PARKINGEXTEN=7020") in new stack [Apr 3 17:19:58] DEBUG[31920] pbx.c: Launching 'Park' [Apr 3 17:19:58] VERBOSE[31920] pbx.c: -- Executing [s@gv-out:9] Park("SIP/2000-0000005e", "") in new stack [Apr 3 17:19:59] DEBUG[31920] features.c: Parkinglot: default [Apr 3 17:19:59] DEBUG[31920] channel.c: Planning to masquerade channel SIP/2000-0000005e into the structure of Parked/SIP/2000-0000005e [Apr 3 17:19:59] DEBUG[31920] channel.c: Done planning to masquerade channel SIP/2000-0000005e into the structure of Parked/SIP/2000-0000005e [Apr 3 17:19:59] DEBUG[31920] channel.c: Putting channel SIP/2000-0000005e in 4/4 formats [Apr 3 17:19:59] DEBUG[31920] channel.c: Released clone lock on 'Parked/SIP/2000-0000005e' [Apr 3 17:19:59] DEBUG[31920] channel.c: Done Masquerading SIP/2000-0000005e (6) [Apr 3 17:19:59] VERBOSE[31920] features.c: == Parked SIP/2000-0000005e on 7020 (lot default). Will timeout back to extension [gv-out] s, 1 in 45 seconds [Apr 3 17:19:59] DEBUG[31920] pbx.c: Added extension '7020' priority 1 to parkedcalls (0x8ec1c20) [Apr 3 17:19:59] VERBOSE[31920] pbx.c: -- Added extension '7020' priority 1 to parkedcalls (0x8ec1c20) [Apr 3 17:19:59] DEBUG[31920] channel.c: Set channel SIP/2000-0000005e to write format gsm [Apr 3 17:19:59] DEBUG[31920] rtp.c: Ooh, format changed from unknown to ulaw [Apr 3 17:19:59] DEBUG[31920] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [Apr 3 17:19:59] DEBUG[31920] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Apr 3 17:19:59] VERBOSE[31920] file.c: -- Playing 'digits/7.gsm' (language 'en') [Apr 3 17:19:59] DEBUG[31920] rtp.c: RTP NAT: Got audio from other end. Now sending to address 71.13.223.53:37469 [Apr 3 17:20:00] DEBUG[31920] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:00] DEBUG[31920] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:00] DEBUG[31920] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:00] DEBUG[31920] channel.c: Set channel SIP/2000-0000005e to write format ulaw [Apr 3 17:20:00] DEBUG[31920] channel.c: Set channel SIP/2000-0000005e to write format gsm [Apr 3 17:20:00] DEBUG[31920] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Apr 3 17:20:00] VERBOSE[31920] file.c: -- Playing 'digits/0.gsm' (language 'en') [Apr 3 17:20:01] DEBUG[30883] chan_sip.c: Target address 204.155.28.10 is not local, substituting externip [Apr 3 17:20:01] VERBOSE[30883] netsock.c: == Using SIP RTP CoS mark 5 [Apr 3 17:20:01] DEBUG[30883] chan_sip.c: Setting NAT on RTP to On [Apr 3 17:20:01] DEBUG[30883] chan_sip.c: Allocating new SIP dialog for 40d78e4323386eda7f1db49c29669f44@sipgate.com - INVITE (With RTP) [Apr 3 17:20:01] DEBUG[30883] chan_sip.c: Setting NAT on RTP to On [Apr 3 17:20:01] DEBUG[30883] chan_sip.c: Checking SIP call limits for device 4408404e1 [Apr 3 17:20:01] DEBUG[31922] pbx.c: Launching 'NoOp' [Apr 3 17:20:01] VERBOSE[31922] pbx.c: -- Executing [4408404e1@sipgate-in:1] NoOp("SIP/sipgate-0000005f", "Incoming SIP Gate Call from : 9894920536") in new stack [Apr 3 17:20:01] DEBUG[31922] pbx.c: Expression result is '1' [Apr 3 17:20:01] DEBUG[31922] pbx.c: Launching 'GotoIf' [Apr 3 17:20:01] VERBOSE[31922] pbx.c: -- Executing [4408404e1@sipgate-in:2] GotoIf("SIP/sipgate-0000005f", "1?gvringback:gvincoming") in new stack [Apr 3 17:20:01] VERBOSE[31922] pbx.c: -- Goto (sipgate-in,4408404e1,4) [Apr 3 17:20:01] DEBUG[31922] pbx.c: Launching 'Answer' [Apr 3 17:20:01] VERBOSE[31922] pbx.c: -- Executing [4408404e1@sipgate-in:4] Answer("SIP/sipgate-0000005f", "") in new stack [Apr 3 17:20:01] DEBUG[31922] chan_sip.c: SIP answering channel: SIP/sipgate-0000005f [Apr 3 17:20:01] DEBUG[31922] chan_sip.c: Setting framing from config on incoming call [Apr 3 17:20:01] DEBUG[31922] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True [Apr 3 17:20:01] DEBUG[31922] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Apr 3 17:20:01] DEBUG[31920] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:01] DEBUG[31920] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:01] DEBUG[31920] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:01] DEBUG[31920] channel.c: Set channel SIP/2000-0000005e to write format ulaw [Apr 3 17:20:01] DEBUG[31920] channel.c: Set channel SIP/2000-0000005e to write format gsm [Apr 3 17:20:01] DEBUG[31920] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Apr 3 17:20:01] VERBOSE[31920] file.c: -- Playing 'digits/2.gsm' (language 'en') [Apr 3 17:20:01] DEBUG[30883] chan_sip.c: Stopping retransmission on '40d78e4323386eda7f1db49c29669f44@sipgate.com' of Response 103: Match Found [Apr 3 17:20:01] DEBUG[30883] chan_sip.c: Allocating new SIP dialog for 53fd72b72719c4bd13da349d5a1a8785@ebolla.homeip.net - OPTIONS (No RTP) [Apr 3 17:20:01] DEBUG[30883] chan_sip.c: Target address 71.13.223.53 is not local, substituting externip [Apr 3 17:20:01] DEBUG[30883] chan_sip.c: Initializing initreq for method OPTIONS - callid 6200d677624926494a0ab2c17bbe2e7b@ebolla.homeip.net [Apr 3 17:20:01] DEBUG[30883] chan_sip.c: Stopping retransmission on '6200d677624926494a0ab2c17bbe2e7b@ebolla.homeip.net' of Request 102: Match Found [Apr 3 17:20:01] DEBUG[31922] pbx.c: Launching 'ParkedCall' [Apr 3 17:20:01] VERBOSE[31922] pbx.c: -- Executing [4408404e1@sipgate-in:5] ParkedCall("SIP/sipgate-0000005f", "7020") in new stack [Apr 3 17:20:01] DEBUG[31922] channel.c: Set channel SIP/2000-0000005e to write format ulaw [Apr 3 17:20:01] VERBOSE[31922] features.c: -- Channel SIP/sipgate-0000005f connected to parked call 7020 [Apr 3 17:20:01] VERBOSE[31922] rtp.c: -- Packet2Packet bridging SIP/sipgate-0000005f and SIP/2000-0000005e [Apr 3 17:20:01] DEBUG[31922] channel.c: Thread -1219101808 Blocking 'SIP/2000-0000005e', already blocked by thread -1219347568 in procedure ast_waitfor_nandfds [Apr 3 17:20:01] WARNING[31922] chan_sip.c: Asked to transmit frame type 2, while native formats is 0x4 (ulaw)(4) read/write = 0x4 (ulaw)(4)/0x4 (ulaw)(4) [Apr 3 17:20:01] WARNING[31922] chan_sip.c: Asked to transmit frame type 2, while native formats is 0x4 (ulaw)(4) read/write = 0x4 (ulaw)(4)/0x4 (ulaw)(4) [Apr 3 17:20:01] WARNING[31922] chan_sip.c: Asked to transmit frame type 2, while native formats is 0x4 (ulaw)(4) read/write = 0x4 (ulaw)(4)/0x4 (ulaw)(4) [Apr 3 17:20:01] WARNING[31922] chan_sip.c: Asked to transmit frame type 2, while native formats is 0x4 (ulaw)(4) read/write = 0x4 (ulaw)(4)/0x4 (ulaw)(4) [Apr 3 17:20:01] WARNING[31922] chan_sip.c: Asked to transmit frame type 2, while native formats is 0x4 (ulaw)(4) read/write = 0x4 (ulaw)(4)/0x4 (ulaw)(4) [Apr 3 17:20:01] WARNING[31922] chan_sip.c: Asked to transmit frame type 2, while native formats is 0x4 (ulaw)(4) read/write = 0x4 (ulaw)(4)/0x4 (ulaw)(4) [Apr 3 17:20:01] WARNING[31922] chan_sip.c: Asked to transmit frame type 2, while native formats is 0x4 (ulaw)(4) read/write = 0x4 (ulaw)(4)/0x4 (ulaw)(4) [Apr 3 17:20:02] WARNING[31922] chan_sip.c: Asked to transmit frame type 2, while native formats is 0x4 (ulaw)(4) read/write = 0x4 (ulaw)(4)/0x4 (ulaw)(4) [Apr 3 17:20:02] DEBUG[31922] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:02] DEBUG[31920] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:02] DEBUG[31920] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:02] DEBUG[31920] channel.c: Set channel SIP/2000-0000005e to write format gsm [Apr 3 17:20:02] DEBUG[31920] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Apr 3 17:20:02] VERBOSE[31920] file.c: -- Playing 'digits/0.gsm' (language 'en') [Apr 3 17:20:03] DEBUG[31922] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:03] DEBUG[31920] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:03] DEBUG[31920] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Apr 3 17:20:03] DEBUG[31920] channel.c: Set channel SIP/2000-0000005e to write format ulaw [Apr 3 17:20:03] DEBUG[31920] pbx.c: Spawn extension (gv-out,s,1) exited non-zero on 'Parked/SIP/2000-0000005e' [Apr 3 17:20:03] VERBOSE[31920] pbx.c: == Spawn extension (gv-out, s, 1) exited non-zero on 'Parked/SIP/2000-0000005e' [Apr 3 17:20:03] DEBUG[31920] channel.c: Soft-Hanging up channel 'Parked/SIP/2000-0000005e' [Apr 3 17:20:03] DEBUG[31920] channel.c: Hanging up zombie 'Parked/SIP/2000-0000005e' [Apr 3 17:20:04] DEBUG[30883] chan_sip.c: Allocating new SIP dialog for 67258e9d08a56b98155b6f526b35fa67@ebolla.homeip.net - OPTIONS (No RTP) [Apr 3 17:20:04] DEBUG[30883] chan_sip.c: Initializing initreq for method OPTIONS - callid 78267e2d7c4f99442c7bb83b23f3a520@ebolla.homeip.net [Apr 3 17:20:05] DEBUG[31922] rtp.c: RTCP NAT: Got RTCP from other end. Now sending to address 71.13.223.53:44508 [Apr 3 17:20:05] DEBUG[31922] rtp.c: Got RTCP report of 52 bytes [Apr 3 17:20:05] DEBUG[30857] chan_iax2.c: ip callno count decremented to 1 for 24.247.43.157 [Apr 3 17:20:05] DEBUG[30868] chan_iax2.c: ip callno count incremented to 2 for 24.247.43.157 [Apr 3 17:20:06] DEBUG[30869] chan_iax2.c: schedule decrement of callno used for 24.247.43.157 in 60 seconds [Apr 3 17:20:06] DEBUG[30869] chan_iax2.c: Peer kevin: got pong, lastms 19, historicms 19, maxms 2000 [Apr 3 17:20:10] DEBUG[31922] rtp.c: Got RTCP report of 52 bytes [Apr 3 17:20:16] DEBUG[31922] rtp.c: Got RTCP report of 52 bytes [Apr 3 17:20:16] DEBUG[31922] channel.c: Returning from native bridge, channels: SIP/sipgate-0000005f, SIP/2000-0000005e [Apr 3 17:20:16] DEBUG[31922] channel.c: Hanging up channel 'SIP/2000-0000005e' [Apr 3 17:20:16] DEBUG[31922] chan_sip.c: Hangup call SIP/2000-0000005e, SIP callid 0jkdAv75bzVipdsicH9pR0nnoR7dTQ2i [Apr 3 17:20:16] DEBUG[31922] pbx.c: Spawn extension (sipgate-in,4408404e1,5) exited non-zero on 'SIP/sipgate-0000005f' [Apr 3 17:20:16] VERBOSE[31922] pbx.c: == Spawn extension (sipgate-in, 4408404e1, 5) exited non-zero on 'SIP/sipgate-0000005f' [Apr 3 17:20:16] DEBUG[31922] channel.c: Soft-Hanging up channel 'SIP/sipgate-0000005f' [Apr 3 17:20:16] DEBUG[31922] channel.c: Hanging up channel 'SIP/sipgate-0000005f' [Apr 3 17:20:16] DEBUG[31922] chan_sip.c: Hangup call SIP/sipgate-0000005f, SIP callid 40d78e4323386eda7f1db49c29669f44@sipgate.com