---------------------- Test Involved peers ---------------------- SIP/703 - belongs to tecnologia context when registered SIP/spaprueba - belongs to pstn context when registered --------------- (Almost)Minimun AEL dialplan:--------------------- globals { DTO=40; // Dial TimeOut }; context default { h => NoOp(H extension default context); }; context pstn { _x. => { BackGround(tt-monkeys); }; h => NoOp(H extension pstn context); }; context tecnologia { includes { local; }; h => NoOp(H extension tecnologia context); }; context local { _9xxxxxxx => &Discar(SIP/spaprueba/${EXTEN:1}); h => NoOp(H extension local context); }; macro Discar(NRADISCAR){ Dial(${NRADISCAR}|${DTO}|); }; ------------------------ Asterisk log setup ------------------------------------- logger.conf with: messages => notice,warning,error,debug,verbose Asterisk started as: $ asterisk -vvvvddddc ------------------------- Logged output ----------------------------------------- [Mar 20 20:39:50] VERBOSE[10046] logger.c: Asterisk Event Logger restarted [Mar 20 20:39:50] VERBOSE[10046] logger.c: Asterisk Queue Logger restarted [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: Setting NAT on RTP to Off [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: Allocating new SIP dialog for zubdueewtvwfyuj@192.168.1.235 - INVITE (With RTP) [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: Setting NAT on RTP to Off [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: Stopping retransmission on 'zubdueewtvwfyuj@192.168.1.235' of Response 891: Match Not Found [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: Setting NAT on RTP to Off [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: T38 state changed to 0 on channel [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: Checking SIP call limits for device 703 [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: Updating call counter for incoming call [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: *** Our capabilities are 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: This channel will not be able to handle video. [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: build_route: Contact hop: [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: SIP/703-081b6978: New call is still down.... Trying... [Mar 20 20:39:59] DEBUG[10066] devicestate.c: Notification of state change to be queued on device/channel SIP/703-081b6978 [Mar 20 20:39:59] DEBUG[10892] pbx.c: Launching 'Macro' [Mar 20 20:39:59] VERBOSE[10892] logger.c: -- Executing [94006666@tecnologia:1] Macro("SIP/703-081b6978", "Discar|SIP/spaprueba/4006666") i n new stack [Mar 20 20:39:59] DEBUG[10892] pbx.c: Launching 'Set' [Mar 20 20:39:59] VERBOSE[10892] logger.c: -- Executing [s@macro-Discar:1] Set("SIP/703-081b6978", "NRADISCAR=SIP/spaprueba/4006666") in ne w stack [Mar 20 20:39:59] DEBUG[10892] pbx.c: Launching 'Dial' [Mar 20 20:39:59] VERBOSE[10892] logger.c: -- Executing [s@macro-Discar:2] Dial("SIP/703-081b6978", "SIP/spaprueba/4006666|40|") in new sta ck [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: Setting NAT on RTP to Off [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: *** Joint capabilities are 0x0 (nothing) [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: *** Our capabilities are 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: This channel will not be able to handle video. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable STACK-macro-Discar-s-2. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable MACRO_DEPTH. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable NRADISCAR. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable STACK-macro-Discar-s-1. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable ARG1. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable MACRO_PRIORITY. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable MACRO_CONTEXT. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable MACRO_EXTEN. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable STACK-tecnologia-94006666-1. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable SIPCALLID. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable SIPUSERAGENT. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable SIPDOMAIN. [Mar 20 20:39:59] DEBUG[10892] channel.c: Not copying variable SIPURI. [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: Outgoing Call for 4006666 [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: Updating call counter for outgoing call [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: Our T38 capability (0), joint T38 capability (0) [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: False [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: -- Done with adding codecs to SDP [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [Mar 20 20:39:59] VERBOSE[10892] logger.c: -- Called spaprueba/4006666 [Mar 20 20:39:59] DEBUG[10049] devicestate.c: No provider found, checking channel drivers for SIP - 703 [Mar 20 20:39:59] DEBUG[10049] chan_sip.c: Checking device state for peer 703 [Mar 20 20:39:59] DEBUG[10049] devicestate.c: Changing state for SIP/703 - state 1 (Not in use) [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1fedfb974519050627bf349e51f691f1@19 2.168.1.235' Request 102: Found [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: SIP response 100 to standard invite [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1fedfb974519050627bf349e51f691f1@19 2.168.1.235' Request 102: Found [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: SIP response 180 to standard invite [Mar 20 20:39:59] DEBUG[10066] devicestate.c: Notification of state change to be queued on device/channel SIP/spaprueba-081c0568 [Mar 20 20:39:59] VERBOSE[10892] logger.c: -- SIP/spaprueba-081c0568 is ringing [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: Acked pending invite 102 [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: Stopping retransmission on '1fedfb974519050627bf349e51f691f1@192.168.1.235' of Request 102: Match No t Found [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: SIP response 200 to standard invite [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: T38 state changed to 0 on channel SIP/spaprueba-081c0568 [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: We have an owner, now see if we need to change this call [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: Updating call counter for outgoing call [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: build_route: Contact hop: spaprueba [Mar 20 20:39:59] DEBUG[10049] devicestate.c: No provider found, checking channel drivers for SIP - spaprueba [Mar 20 20:39:59] DEBUG[10049] chan_sip.c: Checking device state for peer spaprueba [Mar 20 20:39:59] DEBUG[10049] devicestate.c: Changing state for SIP/spaprueba - state 1 (Not in use) [Mar 20 20:39:59] DEBUG[10893] app_queue.c: Device 'SIP/703' changed to state '1' (Not in use) but we don't care because they're not a member o f any queue. [Mar 20 20:39:59] VERBOSE[10892] logger.c: -- Call on SIP/spaprueba-081c0568 left from hold [Mar 20 20:39:59] DEBUG[10892] devicestate.c: Notification of state change to be queued on device/channel SIP/spaprueba-081c0568 [Mar 20 20:39:59] VERBOSE[10892] logger.c: -- SIP/spaprueba-081c0568 answered SIP/703-081b6978 [Mar 20 20:39:59] DEBUG[10892] devicestate.c: Notification of state change to be queued on device/channel SIP/703-081b6978 [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: SIP answering channel: SIP/703-081b6978 [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: Setting framing from config on incoming call [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: ** Our capability: 0x4 (ulaw) Video flag: True [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: -- Done with adding codecs to SDP [Mar 20 20:39:59] DEBUG[10892] chan_sip.c: Done building SDP. Settling with this capability: 0x4 (ulaw) [Mar 20 20:39:59] VERBOSE[10892] logger.c: -- Packet2Packet bridging SIP/703-081b6978 and SIP/spaprueba-081c0568 [Mar 20 20:39:59] DEBUG[10049] devicestate.c: No provider found, checking channel drivers for SIP - spaprueba [Mar 20 20:39:59] DEBUG[10049] chan_sip.c: Checking device state for peer spaprueba [Mar 20 20:39:59] DEBUG[10049] devicestate.c: Changing state for SIP/spaprueba - state 1 (Not in use) [Mar 20 20:39:59] DEBUG[10049] devicestate.c: No provider found, checking channel drivers for SIP - 703 [Mar 20 20:39:59] DEBUG[10049] chan_sip.c: Checking device state for peer 703 [Mar 20 20:39:59] DEBUG[10049] devicestate.c: Changing state for SIP/703 - state 1 (Not in use) [Mar 20 20:39:59] DEBUG[10894] app_queue.c: Device 'SIP/spaprueba' changed to state '1' (Not in use) but we don't care because they're not a me mber of any queue. [Mar 20 20:39:59] DEBUG[10895] app_queue.c: Device 'SIP/spaprueba' changed to state '1' (Not in use) but we don't care because they're not a me mber of any queue. [Mar 20 20:39:59] DEBUG[10896] app_queue.c: Device 'SIP/703' changed to state '1' (Not in use) but we don't care because they're not a member o f any queue. [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Mar 20 20:39:59] DEBUG[10066] chan_sip.c: Stopping retransmission on 'zubdueewtvwfyuj@192.168.1.235' of Response 892: Match Not Found [Mar 20 20:39:59] DEBUG[10892] rtp.c: Got RTCP report of 44 bytes [Mar 20 20:40:05] DEBUG[10892] rtp.c: Got RTCP report of 88 bytes [Mar 20 20:40:07] DEBUG[10066] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Mar 20 20:40:07] DEBUG[10066] chan_sip.c: Setting SIP_ALREADYGONE on dialog zubdueewtvwfyuj@192.168.1.235 [Mar 20 20:40:07] DEBUG[10066] chan_sip.c: Received bye, issuing owner hangup [Mar 20 20:40:07] DEBUG[10892] rtp.c: Oooh, got a hangup [Mar 20 20:40:07] DEBUG[10892] channel.c: Returning from native bridge, channels: SIP/703-081b6978, SIP/spaprueba-081c0568 [Mar 20 20:40:07] DEBUG[10892] channel.c: Hanging up channel 'SIP/spaprueba-081c0568' [Mar 20 20:40:07] DEBUG[10892] chan_sip.c: Hangup call SIP/spaprueba-081c0568, SIP callid 1fedfb974519050627bf349e51f691f1@192.168.1.235) [Mar 20 20:40:07] DEBUG[10892] devicestate.c: Notification of state change to be queued on device/channel SIP/spaprueba-081c0568 [Mar 20 20:40:07] DEBUG[10892] rtp.c: Channel '' has no RTP, not doing anything [Mar 20 20:40:07] DEBUG[10892] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Mar 20 20:40:07] DEBUG[10892] app_macro.c: Spawn extension (macro-Discar,s,2) exited non-zero on 'SIP/703-081b6978' in macro 'Discar' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Spawn extension (macro-Discar,s,2) exited non-zero on 'SIP/703-081b6978' [Mar 20 20:40:07] VERBOSE[10892] logger.c: == Spawn extension (macro-Discar, s, 2) exited non-zero on 'SIP/703-081b6978' [Mar 20 20:40:07] DEBUG[10049] devicestate.c: No provider found, checking channel drivers for SIP - spaprueba [Mar 20 20:40:07] DEBUG[10049] chan_sip.c: Checking device state for peer spaprueba [Mar 20 20:40:07] DEBUG[10049] devicestate.c: Changing state for SIP/spaprueba - state 1 (Not in use) [Mar 20 20:40:07] DEBUG[10892] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. [Mar 20 20:40:07] DEBUG[10892] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,ds tchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,userfield) VALUES ('2007-03-20 20:39:59','\"Jose Callero\" <703>',' 703','94006666','tecnologia', 'SIP/703-081b6978','SIP/spaprueba-081c0568','Dial','SIP/spaprueba/4006666|40|',8,8,'ANSWERED',3,'','') [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is '"Jose Callero" <703>' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is '703' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is '94006666' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is 'tecnologia' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is 'SIP/703-081b6978' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is 'SIP/spaprueba-081c0568' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is 'Dial' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is 'SIP/spaprueba/4006666|40|' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is '2007-03-20 20:39:59' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is '2007-03-20 20:39:59' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is '2007-03-20 20:40:07' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is '8' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is '8' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is 'ANSWERED' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is 'DOCUMENTATION' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is '' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is '1174433999.12' [Mar 20 20:40:07] DEBUG[10892] pbx.c: Function result is '' [Mar 20 20:40:07] DEBUG[10892] channel.c: Hanging up channel 'SIP/703-081b6978' [Mar 20 20:40:07] DEBUG[10892] chan_sip.c: Hangup call SIP/703-081b6978, SIP callid zubdueewtvwfyuj@192.168.1.235) [Mar 20 20:40:07] DEBUG[10892] devicestate.c: Notification of state change to be queued on device/channel SIP/703-081b6978 [Mar 20 20:40:07] DEBUG[10066] chan_sip.c: Stopping retransmission on '1fedfb974519050627bf349e51f691f1@192.168.1.235' of Request 103: Match No t Found [Mar 20 20:40:07] VERBOSE[10066] logger.c: Really destroying SIP dialog '1fedfb974519050627bf349e51f691f1@192.168.1.235' Method: INVITE [Mar 20 20:40:07] VERBOSE[10066] logger.c: Really destroying SIP dialog 'zubdueewtvwfyuj@192.168.1.235' Method: BYE [Mar 20 20:40:07] DEBUG[10049] devicestate.c: No provider found, checking channel drivers for SIP - 703 [Mar 20 20:40:07] DEBUG[10049] chan_sip.c: Checking device state for peer 703 [Mar 20 20:40:07] DEBUG[10049] devicestate.c: Changing state for SIP/703 - state 1 (Not in use) [Mar 20 20:40:07] DEBUG[10901] app_queue.c: Device 'SIP/spaprueba' changed to state '1' (Not in use) but we don't care because they're not a me mber of any queue. [Mar 20 20:40:07] DEBUG[10902] app_queue.c: Device 'SIP/703' changed to state '1' (Not in use) but we don't care because they're not a member o f any queue. [Mar 20 20:40:10] DEBUG[10066] chan_sip.c: Auto destroying SIP dialog '1cd60b07-a5dfcb5a@192.168.1.186' [Mar 20 20:40:10] DEBUG[10066] chan_sip.c: Destroying SIP dialog 1cd60b07-a5dfcb5a@192.168.1.186 [Mar 20 20:40:10] VERBOSE[10066] logger.c: Really destroying SIP dialog '1cd60b07-a5dfcb5a@192.168.1.186' Method: REGISTER [Mar 20 20:40:10] DEBUG[10066] chan_sip.c: Auto destroying SIP dialog '60b7f5ee-742d059f@192.168.1.186' [Mar 20 20:40:10] DEBUG[10066] chan_sip.c: Destroying SIP dialog 60b7f5ee-742d059f@192.168.1.186 [Mar 20 20:40:10] VERBOSE[10066] logger.c: Really destroying SIP dialog '60b7f5ee-742d059f@192.168.1.186' Method: REGISTER [Mar 20 20:40:14] DEBUG[10066] chan_sip.c: Auto destroying SIP dialog 'c21d73b1-8ef26b61@192.168.1.244' [Mar 20 20:40:14] DEBUG[10066] chan_sip.c: Destroying SIP dialog c21d73b1-8ef26b61@192.168.1.244 [Mar 20 20:40:14] VERBOSE[10066] logger.c: Really destroying SIP dialog 'c21d73b1-8ef26b61@192.168.1.244' Method: REGISTER