[Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 1799CF70-3BD2-42FE-8A00-838C53B5AFF8@192.168.1.61 Their Tag 499379620042 Our tag: as3065f979 [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 390353B5-5F17-4506-8119-0E5ECBA9C3E6@192.168.1.73 Their Tag 72430469513 Our tag: as048124d7 [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: EB591AEA-262D-40CF-8488-159F95754A1E@192.168.1.66 Their Tag 2433429624092 Our tag: as7ef80db5 [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 3CFB88CD-8A54-41A4-9DC5-E211225D449F@192.168.1.72 Their Tag 7972442114437 Our tag: as7c45e816 [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 2EC53EE7-CAE8-4C8C-910D-EF0889EAD3CD@192.168.1.62 Their Tag 245749061172 Our tag: as6747fd23 [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 03F08FB2-1DD2-11B2-8234-801AD065B997@192.168.1.65 Their Tag 19609584901331156973 Our tag: as5b06caaf [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: C6F4B8BE-8543-47AD-B593-6E3408273AC4@192.168.1.63 Their Tag 2444490631525 Our tag: as40762700 [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to Off [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:2578 do_setnat: Setting NAT on VRTP to Off [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for 4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan - INVITE (With RTP) [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:14590 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to Off [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:2578 do_setnat: Setting NAT on VRTP to Off [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:4359 find_call: = Found Their Call ID: 4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan Their Tag 047e0383-25d6-db11-99a4-00179a37ab91 Our tag: as7a2b628e [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:14590 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan' of Response 1: Match Not Found [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:4359 find_call: = Found Their Call ID: 4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan Their Tag 047e0383-25d6-db11-99a4-00179a37ab91 Our tag: as7a2b628e [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:14590 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:2573 do_setnat: Setting NAT on RTP to Off [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:2578 do_setnat: Setting NAT on VRTP to Off [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:5123 process_sdp: T38 state changed to 0 on channel [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:5203 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:13378 handle_request_invite: Checking SIP call limits for device ibc-ekiga [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:3001 update_call_counter: Updating call counter for incoming call [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:3803 sip_new: *** Our native formats are 0x8 (alaw) [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:3804 sip_new: *** Joint capabilities are 0xe (gsm|ulaw|alaw) [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:3805 sip_new: *** Our capabilities are 0xe (gsm|ulaw|alaw) [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:3806 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:3829 sip_new: This channel will not be able to handle video. [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:7964 build_route: build_route: Contact hop: [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:13453 handle_request_invite: SIP/ibc-ekiga-081e9058: New call is still down.... Trying... [Mar 21 15:24:06] DEBUG[10447]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ibc-ekiga-081e9058 [Mar 21 15:24:06] DEBUG[10444]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ibc-ekiga [Mar 21 15:24:06] DEBUG[10444]: chan_sip.c:15201 sip_devicestate: Checking device state for peer ibc-ekiga [Mar 21 15:24:06] DEBUG[10444]: devicestate.c:287 do_state_change: Changing state for SIP/ibc-ekiga - state 1 (Not in use) [Mar 21 15:24:06] DEBUG[10493]: pbx.c:1791 pbx_extension_helper: Launching 'Goto' [Mar 21 15:24:06] -- Executing [901@desde-usuarios:1] Goto("SIP/ibc-ekiga-081e9058", "pruebas-ivr|s|1") in new stack [Mar 21 15:24:06] -- Goto (pruebas-ivr,s,1) [Mar 21 15:24:06] DEBUG[10493]: pbx.c:1791 pbx_extension_helper: Launching 'Playback' [Mar 21 15:24:06] -- Executing [s@pruebas-ivr:1] Playback("SIP/ibc-ekiga-081e9058", "welcome") in new stack [Mar 21 15:24:06] DEBUG[10493]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ibc-ekiga-081e9058 [Mar 21 15:24:06] DEBUG[10444]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ibc-ekiga [Mar 21 15:24:06] DEBUG[10444]: chan_sip.c:15201 sip_devicestate: Checking device state for peer ibc-ekiga [Mar 21 15:24:06] DEBUG[10444]: devicestate.c:287 do_state_change: Changing state for SIP/ibc-ekiga - state 1 (Not in use) [Mar 21 15:24:06] DEBUG[10493]: chan_sip.c:3461 sip_answer: SIP answering channel: SIP/ibc-ekiga-081e9058 [Mar 21 15:24:06] DEBUG[10493]: chan_sip.c:6414 transmit_response_with_sdp: Setting framing from config on incoming call [Mar 21 15:24:06] DEBUG[10493]: chan_sip.c:6182 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: False [Mar 21 15:24:06] DEBUG[10493]: chan_sip.c:6183 add_sdp: ** Our prefcodec: 0x0 (nothing) [Mar 21 15:24:06] DEBUG[10493]: chan_sip.c:6314 add_sdp: -- Done with adding codecs to SDP [Mar 21 15:24:06] DEBUG[10493]: channel.c:2381 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Mar 21 15:24:06] DEBUG[10493]: chan_sip.c:6359 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [Mar 21 15:24:06] DEBUG[10493]: rtp.c:2670 ast_rtp_write: Ooh, format changed from unknown to alaw [Mar 21 15:24:06] DEBUG[10493]: rtp.c:2687 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160 [Mar 21 15:24:06] -- Playing 'welcome' (language 'es') [Mar 21 15:24:06] DEBUG[10494]: app_queue.c:546 changethread: Device 'SIP/ibc-ekiga' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 21 15:24:06] DEBUG[10495]: app_queue.c:546 changethread: Device 'SIP/ibc-ekiga' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:4359 find_call: = Found Their Call ID: 4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan Their Tag 047e0383-25d6-db11-99a4-00179a37ab91 Our tag: as65f31ebd [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:14590 handle_request: **** Received ACK (6) - Command in SIP ACK [Mar 21 15:24:06] DEBUG[10447]: chan_sip.c:2087 __sip_ack: Stopping retransmission on '4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan' of Response 2: Match Not Found [Mar 21 15:24:07] NOTICE[10493]: sched.c:220 ast_sched_add_variable: Scheduled event in 0 ms? [Mar 21 15:24:07] DEBUG[10493]: pbx.c:1791 pbx_extension_helper: Launching 'WaitExten' [Mar 21 15:24:07] -- Executing [s@pruebas-ivr:2] WaitExten("SIP/ibc-ekiga-081e9058", "10") in new stack [Mar 21 15:24:09] DEBUG[10447]: chan_sip.c:4308 sip_alloc: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Mar 21 15:24:11] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4) [Mar 21 15:24:11] DEBUG[10493]: rtp.c:620 send_dtmf: Ignore potential DTMF echo from '192.168.1.58' [Mar 21 15:24:11] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4) [Mar 21 15:24:11] DEBUG[10493]: rtp.c:620 send_dtmf: Ignore potential DTMF echo from '192.168.1.58' [Mar 21 15:24:11] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4) [Mar 21 15:24:11] DEBUG[10493]: rtp.c:620 send_dtmf: Ignore potential DTMF echo from '192.168.1.58' [Mar 21 15:24:11] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4) [Mar 21 15:24:11] DEBUG[10493]: rtp.c:620 send_dtmf: Ignore potential DTMF echo from '192.168.1.58' [Mar 21 15:24:11] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4) [Mar 21 15:24:11] DEBUG[10493]: rtp.c:620 send_dtmf: Ignore potential DTMF echo from '192.168.1.58' [Mar 21 15:24:11] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4) [Mar 21 15:24:11] DEBUG[10493]: rtp.c:620 send_dtmf: Ignore potential DTMF echo from '192.168.1.58' [Mar 21 15:24:11] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4) [Mar 21 15:24:11] DEBUG[10493]: rtp.c:620 send_dtmf: Ignore potential DTMF echo from '192.168.1.58' [Mar 21 15:24:11] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4) [Mar 21 15:24:11] DEBUG[10493]: rtp.c:620 send_dtmf: Ignore potential DTMF echo from '192.168.1.58' [Mar 21 15:24:11] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4) [Mar 21 15:24:11] DEBUG[10493]: rtp.c:620 send_dtmf: Ignore potential DTMF echo from '192.168.1.58' [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 5f9512b052560d3c2dbf14944ca80326@192.168.1.203 Their Tag Our tag: as2086f0ed [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan Their Tag 047e0383-25d6-db11-99a4-00179a37ab91 Our tag: as65f31ebd [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 1799CF70-3BD2-42FE-8A00-838C53B5AFF8@192.168.1.61 Their Tag 499379620042 Our tag: as3065f979 [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 390353B5-5F17-4506-8119-0E5ECBA9C3E6@192.168.1.73 Their Tag 72430469513 Our tag: as048124d7 [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: EB591AEA-262D-40CF-8488-159F95754A1E@192.168.1.66 Their Tag 2433429624092 Our tag: as7ef80db5 [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 3CFB88CD-8A54-41A4-9DC5-E211225D449F@192.168.1.72 Their Tag 7972442114437 Our tag: as7c45e816 [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = Found Their Call ID: 2EC53EE7-CAE8-4C8C-910D-EF0889EAD3CD@192.168.1.62 Their Tag 245749061172 Our tag: as6747fd23 [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:14590 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:14807 sipsock_read: SIP message could not be handled, bad request: 2EC53EE7-CAE8-4C8C-910D-EF0889EAD3CD@192.168.1.62 [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 5f9512b052560d3c2dbf14944ca80326@192.168.1.203 Their Tag Our tag: as2086f0ed [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan Their Tag 047e0383-25d6-db11-99a4-00179a37ab91 Our tag: as65f31ebd [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 1799CF70-3BD2-42FE-8A00-838C53B5AFF8@192.168.1.61 Their Tag 499379620042 Our tag: as3065f979 [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 390353B5-5F17-4506-8119-0E5ECBA9C3E6@192.168.1.73 Their Tag 72430469513 Our tag: as048124d7 [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: EB591AEA-262D-40CF-8488-159F95754A1E@192.168.1.66 Their Tag 2433429624092 Our tag: as7ef80db5 [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:4359 find_call: = Found Their Call ID: 3CFB88CD-8A54-41A4-9DC5-E211225D449F@192.168.1.72 Their Tag 7972442114437 Our tag: as7c45e816 [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:14590 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Mar 21 15:24:12] DEBUG[10447]: chan_sip.c:14807 sipsock_read: SIP message could not be handled, bad request: 3CFB88CD-8A54-41A4-9DC5-E211225D449F@192.168.1.72 [Mar 21 15:24:13] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000002 (len = 4) [Mar 21 15:24:13] DEBUG[10493]: rtp.c:626 send_dtmf: Sending dtmf: 50 (2), at 192.168.1.58 [Mar 21 15:24:13] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000002 (len = 4) [Mar 21 15:24:13] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000002 (len = 4) [Mar 21 15:24:13] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000002 (len = 4) [Mar 21 15:24:13] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000002 (len = 4) [Mar 21 15:24:13] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000002 (len = 4) [Mar 21 15:24:13] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000002 (len = 4) [Mar 21 15:24:13] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000002 (len = 4) [Mar 21 15:24:13] DEBUG[10493]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000002 (len = 4) [Mar 21 15:24:13] DEBUG[10447]: chan_sip.c:3107 sip_destroy: Destroying SIP dialog 5f9512b052560d3c2dbf14944ca80326@192.168.1.203 [Mar 21 15:24:13] Really destroying SIP dialog '5f9512b052560d3c2dbf14944ca80326@192.168.1.203' Method: OPTIONS [Mar 21 15:24:13] DEBUG[10447]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/omas-softphone [Mar 21 15:24:13] DEBUG[10444]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - omas [Mar 21 15:24:13] DEBUG[10444]: chan_sip.c:15201 sip_devicestate: Checking device state for peer omas [Mar 21 15:24:13] DEBUG[10444]: devicestate.c:287 do_state_change: Changing state for SIP/omas - state 4 (Invalid) [Mar 21 15:24:13] DEBUG[10496]: app_queue.c:546 changethread: Device 'SIP/omas' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Mar 21 15:24:16] DEBUG[10447]: chan_sip.c:4359 find_call: = Found Their Call ID: 4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan Their Tag 047e0383-25d6-db11-99a4-00179a37ab91 Our tag: as65f31ebd [Mar 21 15:24:16] DEBUG[10447]: chan_sip.c:14590 handle_request: **** Received BYE (8) - Command in SIP BYE [Mar 21 15:24:16] DEBUG[10447]: chan_sip.c:1631 sip_alreadygone: Setting SIP_ALREADYGONE on dialog 4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan [Mar 21 15:24:16] DEBUG[10447]: chan_sip.c:14167 handle_request_bye: Received bye, issuing owner hangup [Mar 21 15:24:16] DEBUG[10493]: pbx.c:2389 __ast_pbx_run: Spawn extension (pruebas-ivr,s,2) exited non-zero on 'SIP/ibc-ekiga-081e9058' [Mar 21 15:24:16] == Spawn extension (pruebas-ivr, s, 2) exited non-zero on 'SIP/ibc-ekiga-081e9058' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '"Iñaki Ekiga" ' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'ibc-ekiga' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 's' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'pruebas-ivr' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'SIP/ibc-ekiga-081e9058' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'WaitExten' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '10' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-21 15:24:06' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-21 15:24:06' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '2007-03-21 15:24:16' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '10' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '10' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '1174487046.0' [Mar 21 15:24:16] DEBUG[10493]: pbx.c:1644 pbx_substitute_variables_helper_full: Function result is '' [Mar 21 15:24:16] DEBUG[10493]: channel.c:1693 ast_hangup: Hanging up channel 'SIP/ibc-ekiga-081e9058' [Mar 21 15:24:16] DEBUG[10493]: chan_sip.c:3310 sip_hangup: Hangup call SIP/ibc-ekiga-081e9058, SIP callid 4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan) [Mar 21 15:24:16] DEBUG[10493]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/ibc-ekiga-081e9058 [Mar 21 15:24:16] DEBUG[10444]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - ibc-ekiga [Mar 21 15:24:16] DEBUG[10444]: chan_sip.c:15201 sip_devicestate: Checking device state for peer ibc-ekiga [Mar 21 15:24:16] DEBUG[10444]: devicestate.c:287 do_state_change: Changing state for SIP/ibc-ekiga - state 1 (Not in use) [Mar 21 15:24:16] DEBUG[10497]: app_queue.c:546 changethread: Device 'SIP/ibc-ekiga' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Mar 21 15:24:16] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan Their Tag 047e0383-25d6-db11-99a4-00179a37ab91 Our tag: as65f31ebd [Mar 21 15:24:16] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 1799CF70-3BD2-42FE-8A00-838C53B5AFF8@192.168.1.61 Their Tag 499379620042 Our tag: as3065f979 [Mar 21 15:24:16] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 390353B5-5F17-4506-8119-0E5ECBA9C3E6@192.168.1.73 Their Tag 72430469513 Our tag: as048124d7 [Mar 21 15:24:16] DEBUG[10447]: chan_sip.c:4359 find_call: = Found Their Call ID: EB591AEA-262D-40CF-8488-159F95754A1E@192.168.1.66 Their Tag 2433429624092 Our tag: as7ef80db5 [Mar 21 15:24:16] DEBUG[10447]: chan_sip.c:14590 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Mar 21 15:24:16] DEBUG[10447]: chan_sip.c:14807 sipsock_read: SIP message could not be handled, bad request: EB591AEA-262D-40CF-8488-159F95754A1E@192.168.1.66 [Mar 21 15:24:16] Really destroying SIP dialog '4c770383-25d6-db11-99a4-00179a37ab91@ibc.ilimit.lan' Method: BYE [Mar 21 15:24:17] DEBUG[10447]: chan_sip.c:4359 find_call: = No match Their Call ID: 1799CF70-3BD2-42FE-8A00-838C53B5AFF8@192.168.1.61 Their Tag 499379620042 Our tag: as3065f979 [Mar 21 15:24:17] DEBUG[10447]: chan_sip.c:4359 find_call: = Found Their Call ID: 390353B5-5F17-4506-8119-0E5ECBA9C3E6@192.168.1.73 Their Tag 72430469513 Our tag: as048124d7 [Mar 21 15:24:17] DEBUG[10447]: chan_sip.c:14590 handle_request: **** Received OPTIONS (3) - Command in SIP OPTIONS [Mar 21 15:24:17] DEBUG[10447]: chan_sip.c:14807 sipsock_read: SIP message could not be handled, bad request: 390353B5-5F17-4506-8119-0E5ECBA9C3E6@192.168.1.73