Jul 18 11:58:34 DEBUG[11883] acl.c: ##### Testing 1.1.2.58 with 1.1.0.0 Jul 18 11:58:34 DEBUG[11883] chan_sip.c: Allocating new SIP dialog for 3c3b9d549c40-3f0nyer3no3j@snom320-00041324A7FC - INVITE (With RTP) Jul 18 11:58:34 DEBUG[11883] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jul 18 11:58:34 DEBUG[11883] chan_sip.c: * SIP extension value: 7 for call 3c3b9d549c40-3f0nyer3no3j@snom320-00041324A7FC Jul 18 11:58:34 DEBUG[11883] chan_sip.c: Setting NAT on RTP to 0 Jul 18 11:58:34 DEBUG[11883] chan_sip.c: = Found Their Call ID: 3c3b9d549c40-3f0nyer3no3j@snom320-00041324A7FC Their Tag bw0lzlrqo1 Our tag: as01448940 Jul 18 11:58:34 DEBUG[11883] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jul 18 11:58:34 DEBUG[11883] chan_sip.c: Stopping retransmission on '3c3b9d549c40-3f0nyer3no3j@snom320-00041324A7FC' of Response 1: Match Found Jul 18 11:58:34 DEBUG[24973] rtp.c: Got RTCP report of 52 bytes Jul 18 11:58:34 DEBUG[11883] chan_sip.c: = Found Their Call ID: 3c3b9d549c40-3f0nyer3no3j@snom320-00041324A7FC Their Tag bw0lzlrqo1 Our tag: as01448940 Jul 18 11:58:34 DEBUG[11883] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jul 18 11:58:34 DEBUG[11883] chan_sip.c: Setting NAT on RTP to 0 Jul 18 11:58:34 DEBUG[11883] chan_sip.c: Checking SIP call limits for device skrimm Jul 18 11:58:34 DEBUG[11883] chan_sip.c: Updating call counter for incoming call Jul 18 11:58:34 DEBUG[11883] chan_sip.c: build_route: Contact hop: ;flow-id=1 Jul 18 11:58:34 DEBUG[11876] chan_sip.c: Checking device state for peer skrimm Jul 18 11:58:34 DEBUG[11876] devicestate.c: Changing state for SIP/skrimm - state 2 (In use) .. .. .. Jul 18 11:58:34 VERBOSE[25027] logger.c: -- Executing Dial("SIP/skrimm-a659e7c8", "Zap/g1/0XXXXX2121") in new stack Jul 18 11:58:34 DEBUG[25027] chan_zap.c: Using channel 1 Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable STACK-intern-*6001-2. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable MACRO_DEPTH. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable STACK-macro-kurzwahl-s-12. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable STACK-macro-kurzwahl-s-8. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable MYSQL_STATUS. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable STACK-macro-kurzwahl-s-7. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable STACK-macro-kurzwahl-s-6. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable fetchid. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable v_kurzwahlnr_dial. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable STACK-macro-kurzwahl-s-5. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable resultid. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable STACK-macro-kurzwahl-s-4. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable esuch. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable STACK-macro-kurzwahl-s-3. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable connid. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable STACK-macro-kurzwahl-s-2. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable STACK-macro-kurzwahl-s-1. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable STACK-intern-*6001-1. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable SIPCALLID. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable SIPUSERAGENT. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable SIPDOMAIN. Jul 18 11:58:34 DEBUG[25027] channel.c: Not copying variable SIPURI. Jul 18 11:58:34 VERBOSE[25027] logger.c: -- Requested transfer capability: 0x00 - SPEECH Jul 18 11:58:34 VERBOSE[25027] logger.c: -- Called g1/069745367 Jul 18 11:58:34 DEBUG[25027] channel.c: Set channel Zap/1-1 to read format slin Jul 18 11:58:34 DEBUG[25027] channel.c: Set channel SIP/skrimm-a659e7c8 to write format slin Jul 18 11:58:34 DEBUG[25027] channel.c: Set channel SIP/skrimm-a659e7c8 to read format slin Jul 18 11:58:34 DEBUG[25027] channel.c: Set channel Zap/1-1 to write format slin Jul 18 11:58:34 DEBUG[11876] devicestate.c: Changing state for Zap/1 - state 2 (In use) Jul 18 11:58:34 DEBUG[11876] devicestate.c: Changing state for Zap/1 - state 2 (In use) Jul 18 11:58:34 DEBUG[25028] app_queue.c: Device 'SIP/skrimm' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 18 11:58:34 DEBUG[25029] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 18 11:58:34 DEBUG[25030] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 18 11:58:34 DEBUG[25027] rtp.c: Ooh, format changed from unknown to ulaw Jul 18 11:58:34 DEBUG[11883] chan_sip.c: = Found Their Call ID: 3c26700f1388-m8j3bh85uu3m@snom320-00041324A7FC Their Tag ex8ctnbqe5 Our tag: as7fac9300 Jul 18 11:58:34 DEBUG[11883] chan_sip.c: Stopping retransmission on '3c26700f1388-m8j3bh85uu3m@snom320-00041324A7FC' of Request 2027: Match Found Jul 18 11:58:34 DEBUG[25027] rtp.c: Got RTCP report of 52 bytes . . . Jul 18 11:58:35 VERBOSE[25027] logger.c: -- Zap/1-1 is proceeding passing it to SIP/skrimm-a659e7c8 Jul 18 11:58:35 DEBUG[11884] chan_zap.c: Enabled echo cancellation on channel 1 Jul 18 11:58:35 VERBOSE[25027] logger.c: -- Zap/1-1 is ringing Jul 18 11:58:35 DEBUG[11876] devicestate.c: Changing state for Zap/1 - state 6 (Ringing) Jul 18 11:58:35 DEBUG[25031] app_queue.c: Device 'Zap/1' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Jul 18 11:58:36 DEBUG[11883] chan_sip.c: ** SIP timers: Rescheduling retransmission 7 to 4000 ms (t1 500 ms (Retrans id #1412038)) Jul 18 11:58:36 DEBUG[11883] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) Jul 18 11:58:36 DEBUG[11883] acl.c: ##### Testing 1.1.2.152 with 1.1.0.0 Jul 18 11:58:36 DEBUG[11883] chan_sip.c: = Found Their Call ID: 515390764491718f21df0b4a206852b1@1.1.1.17 Their Tag Our tag: as7fa2292b Jul 18 11:58:36 DEBUG[11883] chan_sip.c: Stopping retransmission on '515390764491718f21df0b4a206852b1@1.1.1.17' of Request 102: Match Found Jul 18 11:58:36 VERBOSE[11883] logger.c: -- Got SIP response 405 "Method Not Allowed" back from 1.1.2.152 Jul 18 11:58:38 DEBUG[24952] rtp.c: Got RTCP report of 52 bytes Jul 18 11:58:39 DEBUG[24973] rtp.c: Got RTCP report of 52 bytes Jul 18 11:58:39 DEBUG[25027] rtp.c: Got RTCP report of 52 bytes Jul 18 11:58:40 WARNING[11883] chan_sip.c: Maximum retries exceeded on transmission 3c3b9cf8b239-nglvku0smhjb@snom320-00041324A7FC for seqno 2 (Critical Response) Jul 18 11:58:43 DEBUG[24952] rtp.c: Got RTCP report of 52 bytes Jul 18 11:58:44 DEBUG[24973] rtp.c: Got RTCP report of 52 bytes Jul 18 11:58:44 DEBUG[25027] rtp.c: Got RTCP report of 52 bytes