obelix*CLI> Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:2392 find_call: Calling sip_alloc con CallID=AISq0-R*G0Af2@192.168.2.175 Jul 5 16:45:50 NOTICE[131080]: chan_sip.c:781 sip_cancel_destroy: Cancel destruction of SIP call name=(null) autokillid=-1 Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:5164 check_user_full: Before searching local user: fromuser= 0192 our_contact= callerid="Planet" <0192> Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:5185 check_user_full: Setting NAT on RTP to 0 Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:4479 check_auth: check_auth rand: username: 0192 secret: pbxip method: INVITE uri: sip:*8@192.168.2.175 ignore:0 Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:817 __sip_ack: Stopping retransmission on 'AISq0-R*G0Af2@192.168.2.175' of Response 89: Found Jul 5 16:45:50 NOTICE[131080]: chan_sip.c:781 sip_cancel_destroy: Cancel destruction of SIP call name=(null) autokillid=30 Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:5164 check_user_full: Before searching local user: fromuser= 0192 our_contact= callerid="Planet" <0192> Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:5185 check_user_full: Setting NAT on RTP to 0 Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:4479 check_auth: check_auth rand: 41d5b291 username: 0192 secret: pbxip method: INVITE uri: sip:*8@192.168.2.175 ignore:0 Jul 5 16:45:50 NOTICE[131080]: chan_sip.c:781 sip_cancel_destroy: Cancel destruction of SIP call name=(null) autokillid=-1 Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:6873 handle_request: Update user count for 0192 Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:1603 update_user_counter: Call from user '0192' is 1 out of 0 Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:4795 get_destination: Call from 0192@192.168.2.175 looking for *8 in local Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:6887 handle_request: Values for response uri=sip:0192@192.168.2.192:5061 domain=192.168.2.175 our_contact= Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:1961 sip_new: Creating new sip channel Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:1975 sip_new: New local sip channel host= 0192 Jul 5 16:45:50 NOTICE[131080]: channel.c:2391 ast_setstate: Channel SIP/0192@ipcontact-0a77: state changed from:Down to state:Down Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:4412 build_route: build_route: Contact hop: Planet Jul 5 16:45:50 NOTICE[131080]: channel.c:2391 ast_setstate: Channel SIP/0192@ipcontact-0a77: state changed from:Down to state:Ring Jul 5 16:45:50 DEBUG[131080]: res_parking.c:751 ast_pickup_call: Call pickup on chan 'SIP/0195@ipcontact-34a5' by 'SIP/0192@ipcontact-0a77' Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:1781 sip_answer: sip_answer called in SIP/0192@ipcontact-0a77 Jul 5 16:45:50 NOTICE[131080]: channel.c:2391 ast_setstate: Channel SIP/0192@ipcontact-0a77: state changed from:Ring to state:Up Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:3496 transmit_response_with_sdp: Adding UniqueId: 1089056750.5 to sip header Jul 5 16:45:50 NOTICE[131080]: channel.c:2391 ast_setstate: Channel SIP/0192@ipcontact-0a77: state changed from:Up to state:Up Jul 5 16:45:50 DEBUG[131080]: channel.c:2126 ast_channel_masquerade: Planning to masquerade SIP/0192@ipcontact-0a77 into the structure of SIP/0195@ipcontact-34a5 Jul 5 16:45:50 DEBUG[131080]: channel.c:2139 ast_channel_masquerade: Done planning to masquerade SIP/0195@ipcontact-34a5 into the structure of SIP/0192@ipcontact-0a77 Jul 5 16:45:50 WARNING[245773]: channel.c:1180 ast_read: Calling ast_do_masquerade on SIP/0195@ipcontact-34a5 Jul 5 16:45:50 DEBUG[245773]: channel.c:2172 ast_do_masquerade: Actually Masquerading SIP/0192@ipcontact-0a77(6) into the structure of SIP/0195@ipcontact-34a5(5) Jul 5 16:45:50 DEBUG[245773]: channel.c:2183 ast_do_masquerade: Got clone lock on 'SIP/0192@ipcontact-0a77' at 0x816b590 ########## Order changed from here on ################# ########## We keep on channel.c:ast_do_masquerade and call sip_fixup() and sip_hangup() from here ################# Jul 5 16:45:50 DEBUG[245773]: chan_sip.c:1856 sip_fixup: sip_fixup called in SIP/0192@ipcontact-0a77 to SIP/0192@ipcontact-0a77 Jul 5 16:45:50 DEBUG[245773]: chan_sip.c:1699 sip_hangup: update_user_counter(0195) - decrement outUse counter ########## State = 6 (AST_STATE_UP) => CANCEL won't be sent ########### Jul 5 16:45:50 WARNING[245773]: chan_sip.c:1726 sip_hangup: Hangup on channel:SIP/0192@ipcontact-0a77 peername:0195 needcancel=0 state=6 alreadygone=0 from= ourcontact= ################################################################### Jul 5 16:45:50 WARNING[245773]: chan_sip.c:1731 sip_hangup: Channel SIP/0192@ipcontact-0a77 startin disconnect Jul 5 16:45:50 DEBUG[245773]: channel.c:2324 ast_do_masquerade: Putting channel SIP/0192@ipcontact-0a77 in 16/16 formats Jul 5 16:45:50 DEBUG[245773]: chan_sip.c:1856 sip_fixup: sip_fixup called in SIP/0195@ipcontact-34a5 to SIP/0192@ipcontact-0a77 Jul 5 16:45:50 DEBUG[245773]: channel.c:2349 ast_do_masquerade: Released clone lock on 'SIP/0195@ipcontact-34a5' Jul 5 16:45:50 DEBUG[245773]: channel.c:2357 ast_do_masquerade: Done Masquerading SIP/0192@ipcontact-0a77 (6) -- SIP/0192@ipcontact-0a77 answered SIP/0190@ipcontact-7e16 Jul 5 16:45:50 DEBUG[245773]: chan_sip.c:1903 sip_indicate: sip_indicate called in SIP/0190@ipcontact-7e16 Jul 5 16:45:50 DEBUG[245773]: chan_sip.c:1781 sip_answer: sip_answer called in SIP/0190@ipcontact-7e16 Jul 5 16:45:50 NOTICE[245773]: channel.c:2391 ast_setstate: Channel SIP/0190@ipcontact-7e16: state changed from:Ring to state:Up Jul 5 16:45:50 DEBUG[245773]: chan_sip.c:3496 transmit_response_with_sdp: Adding UniqueId: 1089056736.3 to sip header Jul 5 16:45:50 NOTICE[245773]: channel.c:2391 ast_setstate: Channel SIP/0190@ipcontact-7e16: state changed from:Up to state:Up -- Attempting native bridge of SIP/0190@ipcontact-7e16 and SIP/0192@ipcontact-0a77 Jul 5 16:45:50 NOTICE[245773]: channel.c:2391 ast_setstate: Channel SIP/0192@ipcontact-0a77: state changed from:Up to state:Up Jul 5 16:45:50 DEBUG[245773]: channel.c:2616 ast_channel_bridge: Got a FRAME_CONTROL (4) frame on channel SIP/0192@ipcontact-0a77 Jul 5 16:45:50 DEBUG[245773]: channel.c:2678 ast_channel_bridge: Bridge stops bridging channels SIP/0190@ipcontact-7e16 and SIP/0192@ipcontact-0a77 Jul 5 16:45:50 DEBUG[245773]: res_parking.c:421 ast_bridge_call: Read from SIP/0192@ipcontact-0a77 (4,4) -- Attempting native bridge of SIP/0190@ipcontact-7e16 and SIP/0192@ipcontact-0a77 Jul 5 16:45:50 NOTICE[131080]: channel.c:2391 ast_setstate: Channel SIP/0195@ipcontact-34a5: state changed from:Up to state:Down Jul 5 16:45:50 NOTICE[131080]: chan_sip.c:6965 handle_request: Calling Hangup in channel: SIP/0195@ipcontact-34a5 Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:817 __sip_ack: Stopping retransmission on '51b2ec-c0a802be-13c4-fec71-3e339e0e-7d7@192.168.2.175' of Response 2: Found Jul 5 16:45:50 DEBUG[131080]: chan_sip.c:817 __sip_ack: Stopping retransmission on 'AISq0-R*G0Af2@192.168.2.175' of Response 90: Found Jul 5 16:45:50 DEBUG[245773]: rtp.c:1132 ast_rtp_write: Ooh, format changed from UNKN to ULAW Jul 5 16:45:51 DEBUG[245773]: rtp.c:1132 ast_rtp_write: Ooh, format changed from UNKN to G726 obelix*CLI>