Sep 20 15:44:18 voip-lab-proxy02 /usr/sbin/kamailio[13028]: INFO: <script>: Branchroute is done. From User is 04319089925448
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [run, udp_trsp.cpp:352] DEBUG: vv M [|] u recvd msg via UDP from 127.0.0.1:5060 vv.--++--.INVITE sip:01998@213.178.65.167:5060 SIP/2.0..Record-Route: <sip:127.0.0.1;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Record-Route: <sip:192.168.253.77;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK4b61.517adcacb8b665328f2734777d42b9a2.0..Via: SIP/2.0/UDP 192.168.253.60:5060;branch=z9hG4bKh46nbt00e0ae1k4u4tc0.1..Via: SIP/2.0/UDP 192.168.178.5:5070;received=217.70.195.35;branch=z9hG4bKPjaa13bc80-f80f-4a35-b4fa-9eea7a293ba6;rport=5070..To: <sip:01998@213.178.65.167>..Contact: <sip:43190899250-qrhsodhehkl28@192.168.253.60:5060;transport=udp>..Call-ID: badc6355-fb93-4f8a-b0ea-f3bb4816730e..CSeq: 4243 INVITE..Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, REFER, MESSAGE..Session-Expires: 1800..Min-SE: 90..Max-Forwards: 68..Content-Type: application/sdp..Content-Length: 265..P-Preferred-Identity: <sip:04319089925448@sip-vip.tng.de;user=phone>..P-Asserted-Identity: <sip:043190899250@sip.tng.de;user=phone>..From: <sip:04319089925448@sip-vip.tng.de>;tag=8aec53fc-2817-435a-b674-6a31b4600c90..X-TNG-CHANGE-URI: 01998..X-TNG-DOMAIN: 213.178.65.167..P-App-Name: sbc..P-App-Param: profile=out....v=0..o=- 1094331725 2083156140 IN IP4 192.168.253.60..s=Asterisk..c=IN IP4 192.168.253.60..t=0 0..m=audio 10726 RTP/AVP 8 0 101..a=rtpmap:8 PCMA/8000..a=rtpmap:0 PCMU/8000..a=rtpmap:101 telephone-event/8000..a=fmtp:101 0-16..a=maxptime:150..a=sendrecv..a=ptime:20..--++--
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5060) to int (5060)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bK4b61.517adcacb8b665328f2734777d42b9a2.0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [match_request, trans_table.cpp:99] DEBUG:  Matching INVITE request
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5060) to int (5060)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [parse, AmMimeBody.cpp:589] DEBUG:  saving single-part body
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [sip_msg2am_request, SipCtrlInterface.cpp:606] DEBUG:  MIME body successfully parsed
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [handle_sip_request, SipCtrlInterface.cpp:765] DEBUG:  Received new request from <127.0.0.1:5060/udp> on intf #1
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [handleSipMsg, AmSipDispatcher.cpp:105] DEBUG:  method: `INVITE' [6].
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [getActiveProfileMatch, SBC.cpp:278] DEBUG:  active profile = out
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [getActiveProfileMatch, SBC.cpp:290] DEBUG:  using call profile 'out' (from matching active_profile rule '$(paramhdr)')
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [AmSession, AmSession.cpp:86] DEBUG:  dlg = 0x7f192c0030f0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [setOAEnabled, AmSipDialog.cpp:210] DEBUG:  enabling offer_answer on SIP dialog ''
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [setRel100State, AmSipDialog.cpp:204] DEBUG:  setting 100rel state for '' to 3
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [setLocalTag, AmSession.cpp:222] DEBUG:  AmSession::setLocalTag() - session id set to 676F98ED-5BA3A432000A7364-09E1B700
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [startSessionUAS, AmSessionContainer.cpp:297] INFO:  Starting UAS session 676F98ED-5BA3A432000A7364-09E1B700
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1909e1b700] [handle_sip_request, SipCtrlInterface.cpp:788] DEBUG:  ^^ M [badc6355-fb93-4f8a-b0ea-f3bb4816730e|] Ru SIP request INVITE handled ^^
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (32AmSessionProcessorThreadAddEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (32AmSessionProcessorThreadAddEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:112] DEBUG:  starting up 1 sessions
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:119] DEBUG:  starting up [|676F98ED-5BA3A432000A7364-09E1B700]: [0x7f192c003710]
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [|676F98ED-5BA3A432000A7364-09E1B700] Disconnected, running, 0 UACTransPending, 0 usages vv
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (17AmSipRequestEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [process, AmSession.cpp:638] DEBUG:  AmSession processing event
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onRxRequest, AmBasicSipDialog.cpp:308] DEBUG:  AmBasicSipDialog::onRxRequest(req = INVITE)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setOutboundInterface, AmBasicSipDialog.cpp:152] DEBUG:  setting outbound interface to 1
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setStatus, AmBasicSipDialog.cpp:84] DEBUG:  setting SIP dialog status: Disconnected->Trying
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onRxSdp, AmOfferAnswer.cpp:215] DEBUG:  entering onRxSdp(), oa_state=None
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 10726, payloads: 8 0 101
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setState, AmOfferAnswer.cpp:69] DEBUG:  setting SIP dialog O/A status: None->OfferRecved
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onRxSdp, AmOfferAnswer.cpp:265] DEBUG:  oa_state: None -> OfferRecved
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipRequest, CallLeg.cpp:928] DEBUG:  676F98ED-5BA3A432000A7364-09E1B700: SIP request 4243 INVITE received in Disconnected state
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipRequest, CallLeg.cpp:937] DEBUG:  handling request INVITE in disconnected state
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipRequest, AmSession.cpp:694] DEBUG:  onSipRequest: method = INVITE
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [updateRefreshMethod, AmSession.cpp:1043] DEBUG:  remote allows UPDATE, using UPDATE for session refresh.
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onInvite, SBCCallLeg.cpp:833] DEBUG:  processing initial INVITE sip:01998@213.178.65.167:5060
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [reply, AmBasicSipDialog.cpp:597] DEBUG:  reply: transaction found!
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setStatus, AmBasicSipDialog.cpp:84] DEBUG:  setting SIP dialog status: Trying->Early
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_reply, trans_layer.cpp:413] DEBUG:  reply_len = 726
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_reply, trans_layer.cpp:588] DEBUG:  Sending to 127.0.0.1:5060 <SIP/2.0 100 Connecting..Record-Route: <sip:127.0.0...>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send, udp_trsp.cpp:259] DEBUG: send  msg to 127.0.0.1:5060.--++--.SIP/2.0 100 Connecting..Record-Route: <sip:127.0.0.1;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Record-Route: <sip:192.168.253.77;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK4b61.517adcacb8b665328f2734777d42b9a2.0..Via: SIP/2.0/UDP 192.168.253.60:5060;branch=z9hG4bKh46nbt00e0ae1k4u4tc0.1..Via: SIP/2.0/UDP 192.168.178.5:5070;received=217.70.195.35;branch=z9hG4bKPjaa13bc80-f80f-4a35-b4fa-9eea7a293ba6;rport=5070..To: <sip:01998@213.178.65.167>..Call-ID: badc6355-fb93-4f8a-b0ea-f3bb4816730e..CSeq: 4243 INVITE..From: <sip:04319089925448@sip-vip.tng.de>;tag=8aec53fc-2817-435a-b674-6a31b4600c90..Server: TNG Proxy SBC..Content-Length: 0....--++--
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [update_uas_reply, trans_layer.cpp:2139] DEBUG:  update_uas_reply(t=0x7f192c002150)
Sep 20 15:44:18 voip-lab-proxy02 /usr/sbin/kamailio[13026]: INFO: <script>: In Reply of Transaction INVITE Route bye_reason URI <null> Reason 100
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [evaluate, SBCCallProfile.cpp:787] DEBUG:  outbound_proxy = 'sip:192.168.253.60:5060'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [evaluate, SBCCallProfile.cpp:1659] DEBUG:  transcoder is disabled
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [evaluate, SBCCallProfile.cpp:792] DEBUG:  rtprelay_enabled = 'no'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [evaluate, SBCCallProfile.cpp:853] DEBUG:  set outbound_interface to 'lan'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [evaluate, SBCCallProfile.cpp:1769] DEBUG:  aleg.activity_str = ''
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [evaluate, SBCCallProfile.cpp:1773] DEBUG:  bleg.activity_str = ''
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [inplaceHeaderFilter, HeaderFilter.cpp:197] DEBUG:  applying 1 header filters
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-change-uri' by blacklist
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [filterSdp, SBCCallLeg.cpp:1423] DEBUG:  filtering body
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 10726, payloads: 8 0 101
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onInvite, SBCCallLeg.cpp:969] DEBUG:  SBC: connecting to 'sip:01998@213.178.65.167:5060'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onInvite, SBCCallLeg.cpp:970] DEBUG:       From:  '<sip:04319089925448@sip-vip.tng.de>'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onInvite, SBCCallLeg.cpp:971] DEBUG:       To:  '<sip:01998@213.178.65.167>'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [AmSession, AmSession.cpp:86] DEBUG:  dlg = (nil)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setOAEnabled, AmSipDialog.cpp:210] DEBUG:  enabling offer_answer on SIP dialog ''
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setRtpRelayMode, AmB2BSession.cpp:890] DEBUG:  enabled RTP relay mode for B2B call '2800E6F0-5BA3A432000AC5CA-49836700'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [addCall, SBCCallRegistry.cpp:37] DEBUG:  SBCCallRegistry: Added call '676F98ED-5BA3A432000A7364-09E1B700' - mapped to: '2800E6F0-5BA3A432000AC5CA-49836700'/''/'68033A0E-5BA3A432000AC5D0-49836700'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [addCall, SBCCallRegistry.cpp:37] DEBUG:  SBCCallRegistry: Added call '2800E6F0-5BA3A432000AC5CA-49836700' - mapped to: '676F98ED-5BA3A432000A7364-09E1B700'/'8aec53fc-2817-435a-b674-6a31b4600c90'/'badc6355-fb93-4f8a-b0ea-f3bb4816730e'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setRel100State, AmSipDialog.cpp:204] DEBUG:  setting 100rel state for '2800E6F0-5BA3A432000AC5CA-49836700' to 3
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [connectCallee, SBCCallLeg.cpp:1011] DEBUG:  Created B2BUA callee leg, From: <sip:04319089925448@sip-vip.tng.de>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setRtpRelayMode, AmB2BSession.cpp:890] DEBUG:  enabled RTP relay mode for B2B call '2800E6F0-5BA3A432000AC5CA-49836700'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [addNewCallee, CallLeg.cpp:1171] DEBUG:  Starting B2B callee session 2800E6F0-5BA3A432000AC5CA-49836700
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [addNewCallee, CallLeg.cpp:1188] DEBUG:  relaying connect leg event to the new leg
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [updateCallStatus, CallLeg.cpp:1229] DEBUG:  A leg 676F98ED-5BA3A432000A7364-09E1B700 changing status from Disconnected to NoReply
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (17AmSipRequestEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Early, running, 0 UACTransPending, 0 usages ^^
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (32AmSessionProcessorThreadAddEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (32AmSessionProcessorThreadAddEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:112] DEBUG:  starting up 1 sessions
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:119] DEBUG:  starting up [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700]: [0x7f1920002200]
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [applyBProfile, SBCCallLeg.cpp:377] DEBUG:  patch_ruri_next_hop = 0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [setOutboundInterface, AmBasicSipDialog.cpp:152] DEBUG:  setting outbound interface to 0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Disconnected, running, 0 UACTransPending, 0 usages vv
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (15ConnectLegEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 10726, payloads: 8 0 101
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [updateLocalSdp, CallLeg.cpp:1617] DEBUG:  2800E6F0-5BA3A432000AC5CA-49836700: updateLocalSdp (OA: 0)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse, AmMimeBody.cpp:589] DEBUG:  saving single-part body
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 10726, payloads: 8 0 101
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_attr, AmSdp.cpp:1158] DEBUG:  found unknown value for media attribute 'direction'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [setState, AmOfferAnswer.cpp:69] DEBUG:  setting SIP dialog O/A status: None->OfferSent
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [setStatus, AmBasicSipDialog.cpp:84] DEBUG:  setting SIP dialog status: Disconnected->Trying
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5060) to int (5060)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [set_next_hop, trans_layer.cpp:924] DEBUG:  no transport specified, setting default one (udp)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [set_next_hop, trans_layer.cpp:931] DEBUG:  next_hop:next_port is <192.168.253.60:5060/udp>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [resolve_targets, resolver.cpp:1080] DEBUG:  sip_destination: 192.168.253.60:5060/udp
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [set_destination_ip, resolver.cpp:1005] DEBUG:  checking whether '192.168.253.60' is IP address...
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [set_destination_ip, resolver.cpp:1063] DEBUG:  set destination to 192.168.253.60:5060
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [debug, resolver.cpp:794] DEBUG:  target list:
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [debug, resolver.cpp:801] DEBUG:  #011192.168.253.60:5060/udp to target list
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_request, trans_layer.cpp:1267] DEBUG:  send_request to R-URI <sip:01998@213.178.65.167:5060>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [patch_contact_transport, trans_layer.cpp:160] DEBUG:  contact: <<sip:192.168.253.77:5080>>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5080) to int (5080)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5060) to int (5060)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bKWA0rDaom
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 1
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_request, trans_layer.cpp:1303] DEBUG:  Sending to 192.168.253.60:5060 <INVITE sip:01998@213.178.65.167:5060 SIP/2.0..Via: SIP/2.0/UDP 192.168.253.77:5080;branch=z9hG4bKWA0rDaom;rport..From: <sip:04319089925448@sip-vip.tng.de>;tag=2800E6F0-5BA3A432000AC5CA-49836700..To: <sip:01998@213.178.65.167>..CSeq: 10 INVITE..Call-ID: 68033A0E-5BA3A432000AC5D0-49836700..Route: <sip:192.168.253.60:5060;lr>..Max-Forwards: 70..Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, REFER, MESSAGE..Session-Expires: 1800..Min-SE: 90..P-Preferred-Identity: <sip:04319089925448@sip-vip.tng.de;user=phone>..P-Asserted-Identity: <sip:043190899250@sip.tng.de;user=phone>..X-TNG-DOMAIN: 213.178.65.167..Content-Type: application/sdp..Contact: <sip:192.168.253.77:5080;transport=udp>..Content-Length: 283....v=0..o=- 1094331725 2083156140 IN IP4 192.168.253.60..s=Asterisk..c=IN IP4 192.168.253.60..t=0 0..m=audio 10726 RTP/AVP 8 0 101..a=rtpmap:8 PCMA/8000..a=rtpmap:0 PCMU/8000..a=rtpmap:101 telephone-event/8000..a=fmtp:101 0-16..a=sendrecv..a=maxptime:150..a=ptime:20..a=direction:both.....>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send, udp_trsp.cpp:259] DEBUG: send  msg to 192.168.253.60:5060.--++--.INVITE sip:01998@213.178.65.167:5060 SIP/2.0..Via: SIP/2.0/UDP 192.168.253.77:5080;branch=z9hG4bKWA0rDaom;rport..From: <sip:04319089925448@sip-vip.tng.de>;tag=2800E6F0-5BA3A432000AC5CA-49836700..To: <sip:01998@213.178.65.167>..CSeq: 10 INVITE..Call-ID: 68033A0E-5BA3A432000AC5D0-49836700..Route: <sip:192.168.253.60:5060;lr>..Max-Forwards: 70..Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, REFER, MESSAGE..Session-Expires: 1800..Min-SE: 90..P-Preferred-Identity: <sip:04319089925448@sip-vip.tng.de;user=phone>..P-Asserted-Identity: <sip:043190899250@sip.tng.de;user=phone>..X-TNG-DOMAIN: 213.178.65.167..Content-Type: application/sdp..Contact: <sip:192.168.253.77:5080;transport=udp>..Content-Length: 283....v=0..o=- 1094331725 2083156140 IN IP4 192.168.253.60..s=Asterisk..c=IN IP4 192.168.253.60..t=0 0..m=audio 10726 RTP/AVP 8 0 101..a=rtpmap:8 PCMA/8000..a=rtpmap:0 PCMU/8000..a=rtpmap:101 telephone-event/8000..a=fmtp:101 0-16..a=sendrecv..a=maxptime:150..a=ptime:20..a=direction:both..--++--
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_request, trans_layer.cpp:1330] DEBUG:  update_uac_request tt->_t =(nil)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [update_uac_request, trans_layer.cpp:2073] DEBUG:  update_uac_request(t=0x7f1918009260)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [update_uac_request, trans_layer.cpp:2109] DEBUG:  transport = 'udp'; is_reliable = 0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type A at time=637 (repeated=0)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type B at time=2212 (repeated=0)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_request, trans_layer.cpp:1352] DEBUG:  logger = (nil)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [updateCallStatus, CallLeg.cpp:1229] DEBUG:  B leg 2800E6F0-5BA3A432000AC5CA-49836700 changing status from Disconnected to NoReply
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [saveSessionDescription, AmB2BSession.cpp:662] DEBUG:  saving session description (application/sdp, v=0..o=- 1094331725 2083156140 IN IP4 192.168.253....)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (15ConnectLegEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Trying, running, 1 UACTransPending, 0 usages ^^
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1908a07700] [_start, AmThread.cpp:74] DEBUG:  Thread 139745495643904 is starting.
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [run, udp_trsp.cpp:352] DEBUG: vv M [|] u recvd msg via UDP from 192.168.253.60:5060 vv.--++--.SIP/2.0 100 Trying..Via: SIP/2.0/UDP 192.168.253.77:5080;received=192.168.253.77;branch=z9hG4bKWA0rDaom;rport=5080..From: <sip:04319089925448@sip-vip.tng.de>;tag=2800E6F0-5BA3A432000AC5CA-49836700..To: <sip:01998@213.178.65.167>..CSeq: 10 INVITE..Call-ID: 68033A0E-5BA3A432000AC5D0-49836700....--++--
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bKWA0rDaom
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 1
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [process_rcvd_msg, trans_layer.cpp:1727] DEBUG:  Reply matched an existing transaction
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [update_uac_reply, trans_layer.cpp:1785] DEBUG:  update_uac_reply(reply code = 100, trans=0x7f1918009260)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type C at time=9613 (repeated=0)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_reply, SipCtrlInterface.cpp:813] DEBUG:  Received reply: 100 Trying
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_reply, SipCtrlInterface.cpp:814] DEBUG:  reply.callid = <68033A0E-5BA3A432000AC5D0-49836700>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_reply, SipCtrlInterface.cpp:815] DEBUG:  reply.from_tag = <2800E6F0-5BA3A432000AC5CA-49836700>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_reply, SipCtrlInterface.cpp:816] DEBUG:  reply.to_tag = <>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_reply, SipCtrlInterface.cpp:817] DEBUG:  reply.contact = <>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_reply, SipCtrlInterface.cpp:818] DEBUG:  reply.to_uri = <>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_reply, SipCtrlInterface.cpp:819] DEBUG:  cseq = <10>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_reply, SipCtrlInterface.cpp:820] DEBUG:  reply.route = <>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_reply, SipCtrlInterface.cpp:821] DEBUG:  hdrs = <>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_reply, SipCtrlInterface.cpp:822] DEBUG:  body-ct = <>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_reply, SipCtrlInterface.cpp:828] DEBUG:  ^^ M [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] ru SIP reply 100 Trying handled ^^
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Trying, running, 1 UACTransPending, 0 usages vv
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (15AmSipReplyEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [process, AmSession.cpp:638] DEBUG:  AmSession processing event
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onRxReply, AmBasicSipDialog.cpp:462] DEBUG:  onRxReply(rep = 100 Trying): transaction found!
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [setStatus, AmBasicSipDialog.cpp:84] DEBUG:  setting SIP dialog status: Trying->Proceeding
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, SBCCallLeg.cpp:622] DEBUG:  onSipReply: 100 Trying (fwd=1)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, SBCCallLeg.cpp:623] DEBUG:  onSipReply: content-type =
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, CallLeg.cpp:979] DEBUG:  2800E6F0-5BA3A432000AC5CA-49836700: SIP reply 100/10 INVITE (to relayed request) received in NoReply state
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, AmB2BSession.cpp:466] DEBUG:  onSipReply: INVITE -> 100 Trying (fwd=false), c-t=
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, AmSession.cpp:763] DEBUG:  Dialog status changed Trying -> Proceeding (stopped=false)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, AmB2BSession.cpp:526] DEBUG:  relaying B2B SIP reply 100 Trying
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relayEvent, SBCCallLeg.cpp:484] DEBUG:  filtering body for reply 'INVITE' (c/t '')
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [filterSdp, SBCCallLeg.cpp:1423] DEBUG:  filtering body
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relayEvent, AmB2BSession.cpp:587] DEBUG:  AmB2BSession::relayEvent: to other_id='676F98ED-5BA3A432000A7364-09E1B700'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (15AmSipReplyEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Proceeding, running, 1 UACTransPending, 0 usages ^^
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Early, running, 0 UACTransPending, 0 usages vv
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (16B2BSipReplyEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onB2BReply, CallLeg.cpp:580] DEBUG:  676F98ED-5BA3A432000A7364-09E1B700: B2B SIP reply 100/4243 INVITE received in NoReply state
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onB2BReply, CallLeg.cpp:593] DEBUG:  established CSeq: 4243, forward: no
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (16B2BSipReplyEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Early, running, 0 UACTransPending, 0 usages ^^
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [run, udp_trsp.cpp:352] DEBUG: vv M [|] u recvd msg via UDP from 192.168.253.60:5060 vv.--++--.SIP/2.0 180 Ringing..Via: SIP/2.0/UDP 192.168.253.77:5080;received=192.168.253.77;branch=z9hG4bKWA0rDaom;rport=5080..From: <sip:04319089925448@sip-vip.tng.de>;tag=2800E6F0-5BA3A432000AC5CA-49836700..To: <sip:01998@213.178.65.167>;tag=00-08150-00f3f58d-56d546ad3..CSeq: 10 INVITE..Call-ID: 68033A0E-5BA3A432000AC5D0-49836700..Allow: REFER,INVITE,NOTIFY,ACK,OPTIONS,REGISTER,SUBSCRIBE..Contact: <sip:01998@192.168.253.60:5060;transport=udp>..Content-Length: 0..X-TNG-SBC-PeerIP: 213.178.65.167..X-TNG-SBC-ACCESS-IP: 82.97.159.90....--++--
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bKWA0rDaom
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 1
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [process_rcvd_msg, trans_layer.cpp:1727] DEBUG:  Reply matched an existing transaction
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [update_uac_reply, trans_layer.cpp:1785] DEBUG:  update_uac_reply(reply code = 180, trans=0x7f1918009260)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type C at time=9623 (repeated=0)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [reset_timer, sip_trans.cpp:189] DEBUG:  Clearing old timer of type C (this=0x12de900)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [handle_sip_reply, SipCtrlInterface.cpp:813] DEBUG:  Received reply: 180 Ringing
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [handle_sip_reply, SipCtrlInterface.cpp:814] DEBUG:  reply.callid = <68033A0E-5BA3A432000AC5D0-49836700>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [handle_sip_reply, SipCtrlInterface.cpp:815] DEBUG:  reply.from_tag = <2800E6F0-5BA3A432000AC5CA-49836700>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [handle_sip_reply, SipCtrlInterface.cpp:816] DEBUG:  reply.to_tag = <00-08150-00f3f58d-56d546ad3>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [handle_sip_reply, SipCtrlInterface.cpp:817] DEBUG:  reply.contact = <<sip:01998@192.168.253.60:5060;transport=udp>>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [handle_sip_reply, SipCtrlInterface.cpp:818] DEBUG:  reply.to_uri = <sip:01998@192.168.253.60:5060;transport=udp>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [handle_sip_reply, SipCtrlInterface.cpp:819] DEBUG:  cseq = <10>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [handle_sip_reply, SipCtrlInterface.cpp:820] DEBUG:  reply.route = <>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [handle_sip_reply, SipCtrlInterface.cpp:821] DEBUG:  hdrs = <Allow: REFER,INVITE,NOTIFY,ACK,OPTIONS,REGISTER,SUBSCRIBE..X-TNG-SBC-PeerIP: 213.178.65.167..X-TNG-SBC-ACCESS-IP: 82.97.159.90..>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [handle_sip_reply, SipCtrlInterface.cpp:822] DEBUG:  body-ct = <>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a421700] [handle_sip_reply, SipCtrlInterface.cpp:828] DEBUG:  ^^ M [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] ru SIP reply 180 Ringing handled ^^
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Proceeding, running, 1 UACTransPending, 0 usages vv
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (15AmSipReplyEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [process, AmSession.cpp:638] DEBUG:  AmSession processing event
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onRxReply, AmBasicSipDialog.cpp:462] DEBUG:  onRxReply(rep = 180 Ringing): transaction found!
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [setStatus, AmBasicSipDialog.cpp:84] DEBUG:  setting SIP dialog status: Proceeding->Early
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, SBCCallLeg.cpp:622] DEBUG:  onSipReply: 180 Ringing (fwd=1)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, SBCCallLeg.cpp:623] DEBUG:  onSipReply: content-type =
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, CallLeg.cpp:979] DEBUG:  2800E6F0-5BA3A432000AC5CA-49836700: SIP reply 180/10 INVITE (to relayed request) received in NoReply state
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, AmB2BSession.cpp:466] DEBUG:  onSipReply: INVITE -> 180 Ringing (fwd=true), c-t=
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, AmB2BSession.cpp:488] DEBUG:  relaying B2B SIP reply 180 Ringing
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:197] DEBUG:  applying 1 header filters
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-peerip' by blacklist
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-access-ip' by blacklist
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relayEvent, SBCCallLeg.cpp:484] DEBUG:  filtering body for reply 'INVITE' (c/t '')
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [filterSdp, SBCCallLeg.cpp:1423] DEBUG:  filtering body
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relayEvent, AmB2BSession.cpp:587] DEBUG:  AmB2BSession::relayEvent: to other_id='676F98ED-5BA3A432000A7364-09E1B700'
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [updateCallStatus, CallLeg.cpp:1229] DEBUG:  B leg 2800E6F0-5BA3A432000AC5CA-49836700 changing status from NoReply to Ringing
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (15AmSipReplyEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Early, running, 1 UACTransPending, 0 usages ^^
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Early, running, 0 UACTransPending, 0 usages vv
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (16B2BSipReplyEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onB2BReply, CallLeg.cpp:580] DEBUG:  676F98ED-5BA3A432000A7364-09E1B700: B2B SIP reply 180/4243 INVITE received in NoReply state
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onB2BReply, CallLeg.cpp:593] DEBUG:  established CSeq: 4243, forward: yes
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [b2bInitial1xx, CallLeg.cpp:478] DEBUG:  1xx reply with to-tag received in NoReply state, changing status to Ringing and remembering the other leg ID ()
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [updateCallStatus, CallLeg.cpp:1229] DEBUG:  A leg 676F98ED-5BA3A432000A7364-09E1B700 changing status from NoReply to Ringing
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [relaySip, AmB2BSession.cpp:864] DEBUG:  relaying SIP reply 180 Ringing
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [reply, AmBasicSipDialog.cpp:597] DEBUG:  reply: transaction found!
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setStatus, AmBasicSipDialog.cpp:84] DEBUG:  setting SIP dialog status: Early->Early
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [patch_contact_transport, trans_layer.cpp:160] DEBUG:  contact: <<sip:127.0.0.1:5080>>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5080) to int (5080)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_reply, trans_layer.cpp:413] DEBUG:  reply_len = 843
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_reply, trans_layer.cpp:588] DEBUG:  Sending to 127.0.0.1:5060 <SIP/2.0 180 Ringing..Record-Route: <sip:127.0.0.1;...>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send, udp_trsp.cpp:259] DEBUG: send  msg to 127.0.0.1:5060.--++--.SIP/2.0 180 Ringing..Record-Route: <sip:127.0.0.1;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Record-Route: <sip:192.168.253.77;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK4b61.517adcacb8b665328f2734777d42b9a2.0..Via: SIP/2.0/UDP 192.168.253.60:5060;branch=z9hG4bKh46nbt00e0ae1k4u4tc0.1..Via: SIP/2.0/UDP 192.168.178.5:5070;received=217.70.195.35;branch=z9hG4bKPjaa13bc80-f80f-4a35-b4fa-9eea7a293ba6;rport=5070..To: <sip:01998@213.178.65.167>;tag=676F98ED-5BA3A432000A7364-09E1B700..Call-ID: badc6355-fb93-4f8a-b0ea-f3bb4816730e..CSeq: 4243 INVITE..From: <sip:04319089925448@sip-vip.tng.de>;tag=8aec53fc-2817-435a-b674-6a31b4600c90..Allow: REFER,INVITE,NOTIFY,ACK,OPTIONS,REGISTER,SUBSCRIBE..Contact: <sip:127.0.0.1:5080;transport=udp>..Content-Length: 0....--++--
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [update_uas_reply, trans_layer.cpp:2139] DEBUG:  update_uas_reply(t=0x7f192c002150)
Sep 20 15:44:18 voip-lab-proxy02 /usr/sbin/kamailio[13027]: INFO: <script>: In Reply of Transaction INVITE Route bye_reason URI <sip:127.0.0.1:5080;transport=udp> Reason 180
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (16B2BSipReplyEvent)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Early, running, 0 UACTransPending, 0 usages ^^
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [run, udp_trsp.cpp:352] DEBUG: vv M [|] u recvd msg via UDP from 192.168.253.60:5060 vv.--++--.SIP/2.0 200 OK..Via: SIP/2.0/UDP 192.168.253.77:5080;received=192.168.253.77;branch=z9hG4bKWA0rDaom;rport=5080..From: <sip:04319089925448@sip-vip.tng.de>;tag=2800E6F0-5BA3A432000AC5CA-49836700..To: <sip:01998@213.178.65.167>;tag=00-08150-00f3f58d-56d546ad3..CSeq: 10 INVITE..Call-ID: 68033A0E-5BA3A432000AC5D0-49836700..Allow: REFER,INVITE,NOTIFY,ACK,OPTIONS,REGISTER,SUBSCRIBE..Contact: <sip:01998@192.168.253.60:5060;transport=udp>..Content-Type: application/sdp..Content-Length: 176..X-TNG-SBC-PeerIP: 213.178.65.167..X-TNG-SBC-ACCESS-IP: 82.97.159.90....v=0..o=cp10 3241819473 153745105848 IN IP4 192.168.253.60..s=SIP Call..c=IN IP4 192.168.253.60..t=0 0..m=audio 13732 RTP/AVP 8..a=rtpmap:8 PCMA/8000/1..a=sendrecv..a=ptime:20..--++--
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bKWA0rDaom
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 1
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [process_rcvd_msg, trans_layer.cpp:1727] DEBUG:  Reply matched an existing transaction
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [update_uac_reply, trans_layer.cpp:1785] DEBUG:  update_uac_reply(reply code = 200, trans=0x7f1918009260)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [update_uac_reply, trans_layer.cpp:1924] DEBUG:  Positive final reply to INVITE transaction (state=3)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type L at time=2226 (repeated=0)
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [parse, AmMimeBody.cpp:589] DEBUG:  saving single-part body
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [sip_msg2am_reply, SipCtrlInterface.cpp:673] DEBUG:  MIME body successfully parsed
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [handle_sip_reply, SipCtrlInterface.cpp:813] DEBUG:  Received reply: 200 OK
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [handle_sip_reply, SipCtrlInterface.cpp:814] DEBUG:  reply.callid = <68033A0E-5BA3A432000AC5D0-49836700>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [handle_sip_reply, SipCtrlInterface.cpp:815] DEBUG:  reply.from_tag = <2800E6F0-5BA3A432000AC5CA-49836700>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [handle_sip_reply, SipCtrlInterface.cpp:816] DEBUG:  reply.to_tag = <00-08150-00f3f58d-56d546ad3>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [handle_sip_reply, SipCtrlInterface.cpp:817] DEBUG:  reply.contact = <<sip:01998@192.168.253.60:5060;transport=udp>>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [handle_sip_reply, SipCtrlInterface.cpp:818] DEBUG:  reply.to_uri = <sip:01998@192.168.253.60:5060;transport=udp>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [handle_sip_reply, SipCtrlInterface.cpp:819] DEBUG:  cseq = <10>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [handle_sip_reply, SipCtrlInterface.cpp:820] DEBUG:  reply.route = <>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [handle_sip_reply, SipCtrlInterface.cpp:821] DEBUG:  hdrs = <Allow: REFER,INVITE,NOTIFY,ACK,OPTIONS,REGISTER,SUBSCRIBE..X-TNG-SBC-PeerIP: 213.178.65.167..X-TNG-SBC-ACCESS-IP: 82.97.159.90..>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [handle_sip_reply, SipCtrlInterface.cpp:822] DEBUG:  body-ct = <application/sdp>
Sep 20 15:44:18 voip-lab-proxy02 sems[13117]: [#7f190a522700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a522700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a522700] [handle_sip_reply, SipCtrlInterface.cpp:828] DEBUG:  ^^ M [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] ru SIP reply 200 OK handled ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Early, running, 1 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (15AmSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [process, AmSession.cpp:638] DEBUG:  AmSession processing event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onRxReply, AmBasicSipDialog.cpp:462] DEBUG:  onRxReply(rep = 200 OK): transaction found!
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [setStatus, AmBasicSipDialog.cpp:84] DEBUG:  setting SIP dialog status: Early->Connected
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onRxSdp, AmOfferAnswer.cpp:215] DEBUG:  entering onRxSdp(), oa_state=OfferSent
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [str2i, AmUtils.cpp:254] DEBUG:  str2i: too many letters in [153745105848]
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 13732, payloads: 8
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [setState, AmOfferAnswer.cpp:69] DEBUG:  setting SIP dialog O/A status: OfferSent->Completed
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onRxSdp, AmOfferAnswer.cpp:265] DEBUG:  oa_state: OfferSent -> Completed
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSdpCompleted, CallLeg.cpp:1681] DEBUG:  2800E6F0-5BA3A432000AC5CA-49836700: oaCompleted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onInvite2xx, AmB2BSession.cpp:558] DEBUG:  no 200 ACK now: waiting for the 200 ACK from the other side...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, SBCCallLeg.cpp:622] DEBUG:  onSipReply: 200 OK (fwd=1)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, SBCCallLeg.cpp:623] DEBUG:  onSipReply: content-type = application/sdp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, CallLeg.cpp:979] DEBUG:  2800E6F0-5BA3A432000AC5CA-49836700: SIP reply 200/10 INVITE (to relayed request) received in Ringing state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, AmB2BSession.cpp:466] DEBUG:  onSipReply: INVITE -> 200 OK (fwd=true), c-t=application/sdp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, AmB2BSession.cpp:488] DEBUG:  relaying B2B SIP reply 200 OK
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:197] DEBUG:  applying 1 header filters
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-peerip' by blacklist
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-access-ip' by blacklist
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relayEvent, SBCCallLeg.cpp:484] DEBUG:  filtering body for reply 'INVITE' (c/t 'application/sdp')
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [filterSdp, SBCCallLeg.cpp:1423] DEBUG:  filtering body
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [str2i, AmUtils.cpp:254] DEBUG:  str2i: too many letters in [153745105848]
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 13732, payloads: 8
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relayEvent, AmB2BSession.cpp:587] DEBUG:  AmB2BSession::relayEvent: to other_id='676F98ED-5BA3A432000A7364-09E1B700'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipReply, AmB2BSession.cpp:493] DEBUG:  not removing relayed INVITE transaction yet...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [updateCallStatus, CallLeg.cpp:1223] DEBUG:  B leg 2800E6F0-5BA3A432000AC5CA-49836700 changing status from Ringing to Connected with 676F98ED-5BA3A432000A7364-09E1B700
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [updateCall, SBCCallRegistry.cpp:50] DEBUG:  SBCCallRegistry: Updated call '676F98ED-5BA3A432000A7364-09E1B700' - rtag to: '00-08150-00f3f58d-56d546ad3'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (15AmSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Connected, running, 1 UACTransPending, 0 usages ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Early, running, 0 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (16B2BSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onB2BReply, CallLeg.cpp:580] DEBUG:  676F98ED-5BA3A432000A7364-09E1B700: B2B SIP reply 200/4243 INVITE received in Ringing state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onB2BReply, CallLeg.cpp:593] DEBUG:  established CSeq: 4243, forward: yes
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [b2bInitial2xx, CallLeg.cpp:506] DEBUG:  setting call status to connected with leg 2800E6F0-5BA3A432000AC5CA-49836700
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [logCallStart, SBCEventLog.cpp:102] DEBUG:  from-ua: ''
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [logCallStart, SBCEventLog.cpp:110] DEBUG:  to-ua: ''
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [str2i, AmUtils.cpp:254] DEBUG:  str2i: too many letters in [153745105848]
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 13732, payloads: 8
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [updateLocalSdp, CallLeg.cpp:1617] DEBUG:  676F98ED-5BA3A432000A7364-09E1B700: updateLocalSdp (OA: 1)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse, AmMimeBody.cpp:589] DEBUG:  saving single-part body
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [relaySip, AmB2BSession.cpp:864] DEBUG:  relaying SIP reply 200 OK
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [reply, AmBasicSipDialog.cpp:597] DEBUG:  reply: transaction found!
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 13732, payloads: 8
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_attr, AmSdp.cpp:1158] DEBUG:  found unknown value for media attribute 'direction'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setState, AmOfferAnswer.cpp:69] DEBUG:  setting SIP dialog O/A status: OfferRecved->Completed
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setStatus, AmBasicSipDialog.cpp:84] DEBUG:  setting SIP dialog status: Early->Connected
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [patch_contact_transport, trans_layer.cpp:160] DEBUG:  contact: <<sip:127.0.0.1:5080>>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5080) to int (5080)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_reply, trans_layer.cpp:413] DEBUG:  reply_len = 1058
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_reply, trans_layer.cpp:588] DEBUG:  Sending to 127.0.0.1:5060 <SIP/2.0 200 OK..Record-Route: <sip:127.0.0.1;r2=on...>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send, udp_trsp.cpp:259] DEBUG: send  msg to 127.0.0.1:5060.--++--.SIP/2.0 200 OK..Record-Route: <sip:127.0.0.1;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Record-Route: <sip:192.168.253.77;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK4b61.517adcacb8b665328f2734777d42b9a2.0..Via: SIP/2.0/UDP 192.168.253.60:5060;branch=z9hG4bKh46nbt00e0ae1k4u4tc0.1..Via: SIP/2.0/UDP 192.168.178.5:5070;received=217.70.195.35;branch=z9hG4bKPjaa13bc80-f80f-4a35-b4fa-9eea7a293ba6;rport=5070..To: <sip:01998@213.178.65.167>;tag=676F98ED-5BA3A432000A7364-09E1B700..Call-ID: badc6355-fb93-4f8a-b0ea-f3bb4816730e..CSeq: 4243 INVITE..From: <sip:04319089925448@sip-vip.tng.de>;tag=8aec53fc-2817-435a-b674-6a31b4600c90..Allow: REFER,INVITE,NOTIFY,ACK,OPTIONS,REGISTER,SUBSCRIBE..Contact: <sip:127.0.0.1:5080;transport=udp>..Content-Type: application/sdp..Content-Length: 187....v=0..o=cp10 3241819473 32537 IN IP4 192.168.253.60..s=SIP Call..c=IN IP4 192.168.253.60..t=0 0..m=audio 13732 RTP/AVP 8..a=rtpmap:8 PCMA/8000/1..a=sendrecv..a=ptime:20..a=direction:both..--++--
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [update_uas_reply, trans_layer.cpp:2139] DEBUG:  update_uas_reply(t=0x7f192c002150)
Sep 20 15:44:19 voip-lab-proxy02 /usr/sbin/kamailio[13026]: INFO: <script>: In Reply of Transaction INVITE Route bye_reason URI <sip:127.0.0.1:5080;transport=udp> Reason 200
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type G at time=652 (repeated=0)
Sep 20 15:44:19 voip-lab-proxy02 /usr/sbin/kamailio[13026]: INFO: <script>: Canceling other branches
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type H at time=2227 (repeated=0)
Sep 20 15:44:19 voip-lab-proxy02 /usr/sbin/kamailio[13026]: NOTICE: acc [acc.c:298]: acc_log_request(): ACC: transaction answered: timestamp=1537451059;time_attr=1537451059.026;method=INVITE;from_tag=8aec53fc-2817-435a-b674-6a31b4600c90;to_tag=676F98ED-5BA3A432000A7364-09E1B700;call_id=badc6355-fb93-4f8a-b0ea-f3bb4816730e;code=200;reason=OK
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onReplySent, AmB2BSession.cpp:543] DEBUG:  recvd_req.erase(<4243,INVITE>)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onTransFinished, CallLeg.cpp:1723] DEBUG:  UAC/UAS transaction finished
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSdpCompleted, CallLeg.cpp:1681] DEBUG:  676F98ED-5BA3A432000A7364-09E1B700: oaCompleted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [saveSessionDescription, AmB2BSession.cpp:662] DEBUG:  saving session description (application/sdp, v=0..o=cp10 3241819473 153745105848 IN IP4 192.168...)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [updateCallStatus, CallLeg.cpp:1223] DEBUG:  A leg 676F98ED-5BA3A432000A7364-09E1B700 changing status from Ringing to Connected with 2800E6F0-5BA3A432000AC5CA-49836700
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (16B2BSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Connected, running, 0 UACTransPending, 0 usages ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [run, udp_trsp.cpp:352] DEBUG: vv M [|] u recvd msg via UDP from 127.0.0.1:5060 vv.--++--.ACK sip:127.0.0.1:5080;transport=udp SIP/2.0..Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK4b61.e96d6be8e6bc1a39c721d22d453342de.0..Via: SIP/2.0/UDP 192.168.253.60:5060;branch=z9hG4bK0hauj330707q80odfg10.1..Via: SIP/2.0/UDP 192.168.178.5:5070;received=217.70.195.35;branch=z9hG4bKPj7edfb6bd-c164-44f9-a61d-379c06307a28;rport=5070..From: <sip:04319089925448@sip-vip.tng.de>;tag=8aec53fc-2817-435a-b674-6a31b4600c90..To: <sip:01998@213.178.65.167>;tag=676F98ED-5BA3A432000A7364-09E1B700..Call-ID: badc6355-fb93-4f8a-b0ea-f3bb4816730e..CSeq: 4243 ACK..Max-Forwards: 68..User-Agent: Asterisk LocaPhone..Content-Length: 0..X-TNG-SBC-PeerIP: 217.70.195.35..X-TNG-SBC-ACCESS-IP: 82.97.166.254....--++--
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5080) to int (5080)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bK4b61.e96d6be8e6bc1a39c721d22d453342de.0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [match_request, trans_table.cpp:99] DEBUG:  Matching ACK request
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [match_request, trans_table.cpp:118] DEBUG:  do_3261_match = 1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [process_rcvd_msg, trans_layer.cpp:1634] DEBUG:  ACK matched INVITE transaction 0x7f192c002150
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [update_uas_request, trans_layer.cpp:2216] DEBUG:  update_uas_request(t=0x7f192c002150)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [process_rcvd_msg, trans_layer.cpp:1637] DEBUG:  update_uas_request(bucket,t=0x7f192c002150,msg) = 10
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [process_rcvd_msg, trans_layer.cpp:1654] DEBUG:  Passing ACK to the UA.
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [handle_sip_request, SipCtrlInterface.cpp:765] DEBUG:  Received new request from <127.0.0.1:5060/udp> on intf #1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a01d700] [handle_sip_request, SipCtrlInterface.cpp:788] DEBUG:  ^^ M [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Ru SIP request ACK handled ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Connected, running, 0 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (17AmSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [process, AmSession.cpp:638] DEBUG:  AmSession processing event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onRxRequest, AmBasicSipDialog.cpp:308] DEBUG:  AmBasicSipDialog::onRxRequest(req = ACK)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onRequestIn, AmOfferAnswer.cpp:155] DEBUG:  200 ACK received: resetting OA state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipRequest, CallLeg.cpp:928] DEBUG:  676F98ED-5BA3A432000A7364-09E1B700: SIP request 4243 ACK received in Connected state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipRequest, AmB2BSession.cpp:352] DEBUG:  relaying B2B SIP request (fwd) ACK sip:127.0.0.1:5080;transport=udp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [inplaceHeaderFilter, HeaderFilter.cpp:197] DEBUG:  applying 1 header filters
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-peerip' by blacklist
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-access-ip' by blacklist
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [relayEvent, SBCCallLeg.cpp:438] DEBUG:  filtering body for request 'ACK' (c/t '')
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [filterSdp, SBCCallLeg.cpp:1423] DEBUG:  filtering body
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [relayEvent, AmB2BSession.cpp:587] DEBUG:  AmB2BSession::relayEvent: to other_id='2800E6F0-5BA3A432000AC5CA-49836700'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (17AmSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Connected, running, 0 UACTransPending, 0 usages ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Connected, running, 1 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (18B2BSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BEvent, AmB2BSession.cpp:176] DEBUG:  AmB2BSession::onB2BEvent
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BEvent, AmB2BSession.cpp:186] DEBUG:  B2BSipRequest: ACK (fwd=true)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relaySip, AmB2BSession.cpp:823] DEBUG:  sending relayed 200 ACK
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5060) to int (5060)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [set_next_hop, trans_layer.cpp:914] DEBUG:  setting next-hop based on request-URI
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [set_next_hop, trans_layer.cpp:931] DEBUG:  next_hop:next_port is <192.168.253.60:5060/udp>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [resolve_targets, resolver.cpp:1080] DEBUG:  sip_destination: 192.168.253.60:5060/udp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [set_destination_ip, resolver.cpp:1005] DEBUG:  checking whether '192.168.253.60' is IP address...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [set_destination_ip, resolver.cpp:1063] DEBUG:  set destination to 192.168.253.60:5060
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [debug, resolver.cpp:794] DEBUG:  target list:
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [debug, resolver.cpp:801] DEBUG:  #011192.168.253.60:5060/udp to target list
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_request, trans_layer.cpp:1267] DEBUG:  send_request to R-URI <sip:01998@192.168.253.60:5060;transport=udp>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [patch_contact_transport, trans_layer.cpp:160] DEBUG:  contact: <<sip:192.168.253.77:5080>>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5080) to int (5080)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5060) to int (5060)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bKEjIH6a0t
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_request, trans_layer.cpp:1303] DEBUG:  Sending to 192.168.253.60:5060 <ACK sip:01998@192.168.253.60:5060;transport=udp SIP/2.0..Via: SIP/2.0/UDP 192.168.253.77:5080;branch=z9hG4bKEjIH6a0t;rport..From: <sip:04319089925448@sip-vip.tng.de>;tag=2800E6F0-5BA3A432000AC5CA-49836700..To: <sip:01998@213.178.65.167>;tag=00-08150-00f3f58d-56d546ad3..CSeq: 10 ACK..Call-ID: 68033A0E-5BA3A432000AC5D0-49836700..Max-Forwards: 70..Contact: <sip:192.168.253.77:5080;transport=udp>..Content-Length: 0.......>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send, udp_trsp.cpp:259] DEBUG: send  msg to 192.168.253.60:5060.--++--.ACK sip:01998@192.168.253.60:5060;transport=udp SIP/2.0..Via: SIP/2.0/UDP 192.168.253.77:5080;branch=z9hG4bKEjIH6a0t;rport..From: <sip:04319089925448@sip-vip.tng.de>;tag=2800E6F0-5BA3A432000AC5CA-49836700..To: <sip:01998@213.178.65.167>;tag=00-08150-00f3f58d-56d546ad3..CSeq: 10 ACK..Call-ID: 68033A0E-5BA3A432000AC5D0-49836700..Max-Forwards: 70..Contact: <sip:192.168.253.77:5080;transport=udp>..Content-Length: 0....--++--
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_request, trans_layer.cpp:1330] DEBUG:  update_uac_request tt->_t =(nil)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [match_request, trans_table.cpp:99] DEBUG:  Matching ACK request
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [match_request, trans_table.cpp:118] DEBUG:  do_3261_match = 1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [update_uac_request, trans_layer.cpp:2083] DEBUG:  update_uac_request(200 ACK, t=0x7f1918009260)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_request, trans_layer.cpp:1352] DEBUG:  logger = (nil)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onTransFinished, CallLeg.cpp:1723] DEBUG:  UAC/UAS transaction finished
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onRequestSent, AmOfferAnswer.cpp:444] DEBUG:  200 ACK sent: resetting OA state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (18B2BSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Connected, running, 0 UACTransPending, 0 usages ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [run, udp_trsp.cpp:352] DEBUG: vv M [|] u recvd msg via UDP from 192.168.253.60:5060 vv.--++--.INVITE sip:192.168.253.77:5080;transport=udp SIP/2.0..Via: SIP/2.0/UDP 192.168.253.60:5060;branch=z9hG4bKhp7tv83070s0rni1fi20sb00cbs90.1..Allow: REFER,INVITE,NOTIFY,ACK,OPTIONS,REGISTER,SUBSCRIBE..Call-ID: 68033A0E-5BA3A432000AC5D0-49836700..Contact: <sip:01998@192.168.253.60:5060;transport=udp>..Content-Type: application/sdp..CSeq: 11584787 INVITE..From: <sip:01998@213.178.65.167>;tag=00-08150-00f3f58d-56d546ad3..To: <sip:04319089925448@sip-vip.tng.de>;tag=2800E6F0-5BA3A432000AC5CA-49836700..Content-Length: 211..X-TNG-SBC-PeerIP: 213.178.65.167..X-TNG-SBC-ACCESS-IP: 82.97.159.90..Max-Forwards: 70....v=0..o=cp10 3241819473 153745105849 IN IP4 192.168.253.60..s=SIP Call..c=IN IP4 192.168.253.60..t=0 0..m=audio 13732 RTP/AVP 8 0..b=AS:80..a=rtpmap:8 PCMA/8000/1..a=rtpmap:0 PCMU/8000/1..a=sendrecv..a=ptime:20..--++--
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5080) to int (5080)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bKhp7tv83070s0rni1fi20sb00cbs90.1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [match_request, trans_table.cpp:99] DEBUG:  Matching INVITE request
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5060) to int (5060)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [parse, AmMimeBody.cpp:589] DEBUG:  saving single-part body
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [sip_msg2am_request, SipCtrlInterface.cpp:606] DEBUG:  MIME body successfully parsed
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [handle_sip_request, SipCtrlInterface.cpp:765] DEBUG:  Received new request from <192.168.253.60:5060/udp> on intf #0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a320700] [handle_sip_request, SipCtrlInterface.cpp:788] DEBUG:  ^^ M [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Ru SIP request INVITE handled ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Connected, running, 0 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (17AmSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [process, AmSession.cpp:638] DEBUG:  AmSession processing event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onRxRequest, AmBasicSipDialog.cpp:308] DEBUG:  AmBasicSipDialog::onRxRequest(req = INVITE)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onRxSdp, AmOfferAnswer.cpp:215] DEBUG:  entering onRxSdp(), oa_state=Completed
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [str2i, AmUtils.cpp:254] DEBUG:  str2i: too many letters in [153745105849]
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 13732, payloads: 8 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [setState, AmOfferAnswer.cpp:69] DEBUG:  setting SIP dialog O/A status: Completed->OfferRecved
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onRxSdp, AmOfferAnswer.cpp:265] DEBUG:  oa_state: Completed -> OfferRecved
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipRequest, SBCCallLeg.cpp:591] DEBUG:  replying 100 Trying to INVITE to be fwd'ed
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [reply, AmBasicSipDialog.cpp:597] DEBUG:  reply: transaction found!
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_reply, trans_layer.cpp:413] DEBUG:  reply_len = 362
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_reply, trans_layer.cpp:588] DEBUG:  Sending to 192.168.253.60:5060 <SIP/2.0 100 Trying..Via: SIP/2.0/UDP 192.168.253.6...>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send, udp_trsp.cpp:259] DEBUG: send  msg to 192.168.253.60:5060.--++--.SIP/2.0 100 Trying..Via: SIP/2.0/UDP 192.168.253.60:5060;branch=z9hG4bKhp7tv83070s0rni1fi20sb00cbs90.1..Call-ID: 68033A0E-5BA3A432000AC5D0-49836700..CSeq: 11584787 INVITE..From: <sip:01998@213.178.65.167>;tag=00-08150-00f3f58d-56d546ad3..To: <sip:04319089925448@sip-vip.tng.de>;tag=2800E6F0-5BA3A432000AC5CA-49836700..Server: TNG Proxy SBC..Content-Length: 0....--++--
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [update_uas_reply, trans_layer.cpp:2139] DEBUG:  update_uas_reply(t=0x7f1934001880)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipRequest, CallLeg.cpp:928] DEBUG:  2800E6F0-5BA3A432000AC5CA-49836700: SIP request 11584787 INVITE received in Connected state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipRequest, AmB2BSession.cpp:352] DEBUG:  relaying B2B SIP request (fwd) INVITE sip:192.168.253.77:5080;transport=udp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:197] DEBUG:  applying 1 header filters
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-peerip' by blacklist
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-access-ip' by blacklist
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relayEvent, SBCCallLeg.cpp:438] DEBUG:  filtering body for request 'INVITE' (c/t 'application/sdp')
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [filterSdp, SBCCallLeg.cpp:1423] DEBUG:  filtering body
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [str2i, AmUtils.cpp:254] DEBUG:  str2i: too many letters in [153745105849]
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 13732, payloads: 8 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relayEvent, AmB2BSession.cpp:587] DEBUG:  AmB2BSession::relayEvent: to other_id='676F98ED-5BA3A432000A7364-09E1B700'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (17AmSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Connected, running, 0 UACTransPending, 0 usages ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Connected, running, 0 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (18B2BSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onB2BEvent, AmB2BSession.cpp:176] DEBUG:  AmB2BSession::onB2BEvent
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onB2BEvent, AmB2BSession.cpp:186] DEBUG:  B2BSipRequest: INVITE (fwd=true)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [str2i, AmUtils.cpp:254] DEBUG:  str2i: too many letters in [153745105849]
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 13732, payloads: 8 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [updateLocalSdp, CallLeg.cpp:1617] DEBUG:  676F98ED-5BA3A432000A7364-09E1B700: updateLocalSdp (OA: 3)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse, AmMimeBody.cpp:589] DEBUG:  saving single-part body
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [relaySip, AmB2BSession.cpp:795] DEBUG:  relaying SIP request INVITE sip:192.168.253.77:5080;transport=udp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 13732, payloads: 8 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_attr, AmSdp.cpp:1158] DEBUG:  found unknown value for media attribute 'direction'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setState, AmOfferAnswer.cpp:69] DEBUG:  setting SIP dialog O/A status: Completed->OfferSent
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port () to int (5060)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [set_next_hop, trans_layer.cpp:924] DEBUG:  no transport specified, setting default one (udp)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [set_next_hop, trans_layer.cpp:931] DEBUG:  next_hop:next_port is <127.0.0.1:0/udp>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [resolve_targets, resolver.cpp:1080] DEBUG:  sip_destination: 127.0.0.1:0/udp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [set_destination_ip, resolver.cpp:1005] DEBUG:  checking whether '127.0.0.1' is IP address...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [set_destination_ip, resolver.cpp:1063] DEBUG:  set destination to 127.0.0.1:5060
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [debug, resolver.cpp:794] DEBUG:  target list:
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [debug, resolver.cpp:801] DEBUG:  #011127.0.0.1:5060/udp to target list
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_request, trans_layer.cpp:1267] DEBUG:  send_request to R-URI <sip:43190899250-qrhsodhehkl28@192.168.253.60:5060;transport=udp>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [patch_contact_transport, trans_layer.cpp:160] DEBUG:  contact: <<sip:127.0.0.1:5080>>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5080) to int (5080)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5060) to int (5060)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bKVC4C3ast
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_request, trans_layer.cpp:1303] DEBUG:  Sending to 127.0.0.1:5060 <INVITE sip:43190899250-qrhsodhehkl28@192.168.253.60:5060;transport=udp SIP/2.0..Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKVC4C3ast;rport..From: <sip:01998@213.178.65.167>;tag=676F98ED-5BA3A432000A7364-09E1B700..To: <sip:04319089925448@sip-vip.tng.de>;tag=8aec53fc-2817-435a-b674-6a31b4600c90..CSeq: 10 INVITE..Call-ID: badc6355-fb93-4f8a-b0ea-f3bb4816730e..Route: <sip:127.0.0.1;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>, <sip:192.168.253.77;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Max-Forwards: 70..Allow: REFER,INVITE,NOTIFY,ACK,OPTIONS,REGISTER,SUBSCRIBE..Content-Type: application/sdp..Contact: <sip:127.0.0.1:5080;transport=udp>..Content-Length: 213....v=0..o=cp10 3241819473 32537 IN IP4 192.168.253.60..s=SIP Call..c=IN IP4 192.168.253.60..t=0 0..m=audio 13732 RTP/AVP 8 0..a=rtpmap:8 PCMA/8000/1..a=rtpmap:0 PCMU/8000/1..a=sendrecv..a=ptime:20..a=direction:both.....>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send, udp_trsp.cpp:259] DEBUG: send  msg to 127.0.0.1:5060.--++--.INVITE sip:43190899250-qrhsodhehkl28@192.168.253.60:5060;transport=udp SIP/2.0..Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKVC4C3ast;rport..From: <sip:01998@213.178.65.167>;tag=676F98ED-5BA3A432000A7364-09E1B700..To: <sip:04319089925448@sip-vip.tng.de>;tag=8aec53fc-2817-435a-b674-6a31b4600c90..CSeq: 10 INVITE..Call-ID: badc6355-fb93-4f8a-b0ea-f3bb4816730e..Route: <sip:127.0.0.1;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>, <sip:192.168.253.77;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Max-Forwards: 70..Allow: REFER,INVITE,NOTIFY,ACK,OPTIONS,REGISTER,SUBSCRIBE..Content-Type: application/sdp..Contact: <sip:127.0.0.1:5080;transport=udp>..Content-Length: 213....v=0..o=cp10 3241819473 32537 IN IP4 192.168.253.60..s=SIP Call..c=IN IP4 192.168.253.60..t=0 0..m=audio 13732 RTP/AVP 8 0..a=rtpmap:8 PCMA/8000/1..a=rtpmap:0 PCMU/8000/1..a=sendrecv..a=ptime:20..a=direction:both..--++--
Sep 20 15:44:19 voip-lab-proxy02 /usr/sbin/kamailio[13027]: INFO: <script>: =================== new branch at sip:43190899250-qrhsodhehkl28@192.168.253.60:5060;transport=udp From <null> ===================
Sep 20 15:44:19 voip-lab-proxy02 /usr/sbin/kamailio[13027]: INFO: <script>: Branch Serial Fork
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_request, trans_layer.cpp:1330] DEBUG:  update_uac_request tt->_t =(nil)
Sep 20 15:44:19 voip-lab-proxy02 /usr/sbin/kamailio[13027]: INFO: <script>: <null>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [update_uac_request, trans_layer.cpp:2073] DEBUG:  update_uac_request(t=0x7f1920005d40)
Sep 20 15:44:19 voip-lab-proxy02 /usr/sbin/kamailio[13027]: INFO: <script>: Branchroute is done. From User is <null>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [update_uac_request, trans_layer.cpp:2109] DEBUG:  transport = 'udp'; is_reliable = 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type A at time=656 (repeated=0)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type B at time=2231 (repeated=0)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_request, trans_layer.cpp:1352] DEBUG:  logger = (nil)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [saveSessionDescription, AmB2BSession.cpp:662] DEBUG:  saving session description (application/sdp, v=0..o=cp10 3241819473 153745105849 IN IP4 192.168...)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (18B2BSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Connected, running, 1 UACTransPending, 0 usages ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [run, udp_trsp.cpp:352] DEBUG: vv M [|] u recvd msg via UDP from 127.0.0.1:5060 vv.--++--.SIP/2.0 100 trying -- your call is important to us..Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKVC4C3ast;rport=5080;received=127.0.0.1..From: <sip:01998@213.178.65.167>;tag=676F98ED-5BA3A432000A7364-09E1B700..To: <sip:04319089925448@sip-vip.tng.de>;tag=8aec53fc-2817-435a-b674-6a31b4600c90..CSeq: 10 INVITE..Call-ID: badc6355-fb93-4f8a-b0ea-f3bb4816730e..Server: kamailio (4.3.7 (x86_64/linux))..Content-Length: 0....--++--
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bKVC4C3ast
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [process_rcvd_msg, trans_layer.cpp:1727] DEBUG:  Reply matched an existing transaction
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [update_uac_reply, trans_layer.cpp:1785] DEBUG:  update_uac_reply(reply code = 100, trans=0x7f1920005d40)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type C at time=9632 (repeated=0)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [handle_sip_reply, SipCtrlInterface.cpp:813] DEBUG:  Received reply: 100 trying -- your call is important to us
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [handle_sip_reply, SipCtrlInterface.cpp:814] DEBUG:  reply.callid = <badc6355-fb93-4f8a-b0ea-f3bb4816730e>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [handle_sip_reply, SipCtrlInterface.cpp:815] DEBUG:  reply.from_tag = <676F98ED-5BA3A432000A7364-09E1B700>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [handle_sip_reply, SipCtrlInterface.cpp:816] DEBUG:  reply.to_tag = <8aec53fc-2817-435a-b674-6a31b4600c90>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [handle_sip_reply, SipCtrlInterface.cpp:817] DEBUG:  reply.contact = <>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [handle_sip_reply, SipCtrlInterface.cpp:818] DEBUG:  reply.to_uri = <>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [handle_sip_reply, SipCtrlInterface.cpp:819] DEBUG:  cseq = <10>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [handle_sip_reply, SipCtrlInterface.cpp:820] DEBUG:  reply.route = <>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [handle_sip_reply, SipCtrlInterface.cpp:821] DEBUG:  hdrs = <Server: kamailio (4.3.7 (x86_64/linux))..>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [handle_sip_reply, SipCtrlInterface.cpp:822] DEBUG:  body-ct = <>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1909f1c700] [handle_sip_reply, SipCtrlInterface.cpp:828] DEBUG:  ^^ M [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] ru SIP reply 100 trying -- your call is important to us handled ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Connected, running, 1 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (15AmSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [process, AmSession.cpp:638] DEBUG:  AmSession processing event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onRxReply, AmBasicSipDialog.cpp:462] DEBUG:  onRxReply(rep = 100 trying -- your call is important to us): transaction found!
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, SBCCallLeg.cpp:622] DEBUG:  onSipReply: 100 trying -- your call is important to us (fwd=1)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, SBCCallLeg.cpp:623] DEBUG:  onSipReply: content-type =
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, CallLeg.cpp:979] DEBUG:  676F98ED-5BA3A432000A7364-09E1B700: SIP reply 100/10 INVITE (to relayed request) received in Connected state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, AmB2BSession.cpp:466] DEBUG:  onSipReply: INVITE -> 100 trying -- your call is important to us (fwd=false), c-t=
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, AmSession.cpp:767] DEBUG:  Dialog status stays Connected (stopped=false)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, AmB2BSession.cpp:526] DEBUG:  relaying B2B SIP reply 100 trying -- your call is important to us
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [inplaceHeaderFilter, HeaderFilter.cpp:197] DEBUG:  applying 1 header filters
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [relayEvent, SBCCallLeg.cpp:484] DEBUG:  filtering body for reply 'INVITE' (c/t '')
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [filterSdp, SBCCallLeg.cpp:1423] DEBUG:  filtering body
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [relayEvent, AmB2BSession.cpp:587] DEBUG:  AmB2BSession::relayEvent: to other_id='2800E6F0-5BA3A432000AC5CA-49836700'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (15AmSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Connected, running, 1 UACTransPending, 0 usages ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Connected, running, 0 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (16B2BSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BReply, CallLeg.cpp:580] DEBUG:  2800E6F0-5BA3A432000AC5CA-49836700: B2B SIP reply 100/11584787 INVITE received in Connected state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BReply, CallLeg.cpp:608] DEBUG:  handling reply via AmB2BSession
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BEvent, AmB2BSession.cpp:176] DEBUG:  AmB2BSession::onB2BEvent
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BEvent, AmB2BSession.cpp:240] DEBUG:  B2BSipReply: 100 trying -- your call is important to us (fwd=false)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BEvent, AmB2BSession.cpp:242] DEBUG:  B2BSipReply: content-type =
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (16B2BSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Connected, running, 0 UACTransPending, 0 usages ^^
Sep 20 15:44:19 voip-lab-proxy02 /usr/sbin/kamailio[13028]: INFO: <script>: In Reply of In-Dialolg-Transaction INVITE
Sep 20 15:44:19 voip-lab-proxy02 /usr/sbin/kamailio[13028]: INFO: <script>: Canceling other branches
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [run, udp_trsp.cpp:352] DEBUG: vv M [|] u recvd msg via UDP from 127.0.0.1:5060 vv.--++--.SIP/2.0 200 OK..Via: SIP/2.0/UDP 127.0.0.1:5080;received=127.0.0.1;branch=z9hG4bKVC4C3ast;rport=5080..From: <sip:01998@213.178.65.167>;tag=676F98ED-5BA3A432000A7364-09E1B700..To: <sip:04319089925448@sip-vip.tng.de>;tag=8aec53fc-2817-435a-b674-6a31b4600c90..CSeq: 10 INVITE..Call-ID: badc6355-fb93-4f8a-b0ea-f3bb4816730e..Record-Route: <sip:192.168.253.77;r2=on;lr;ftag=676F98ED-5BA3A432000A7364-09E1B700;did=767.2401>..Record-Route: <sip:127.0.0.1;r2=on;lr;ftag=676F98ED-5BA3A432000A7364-09E1B700;did=767.2401>..Contact: <sip:43190899250-qrhsodhehkl28@192.168.253.60:5060;transport=udp>..Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, REFER, MESSAGE..Supported: 100rel, timer, replaces, norefersub..Server: Asterisk LocaPhone..Content-Type: application/sdp..Content-Length: 214..X-TNG-SBC-PeerIP: 217.70.195.35..X-TNG-SBC-ACCESS-IP: 82.97.166.254....v=0..o=- 1094331725 2083156141 IN IP4 217.70.195.35..s=Asterisk..c=IN IP4 192.168.253.60..t=0 0..m=audio 10726 RTP/AVP 8 0..a=rtpmap:8 PCMA/8000/1..a=rtpmap:0 PCMU/8000/1..a=direction:both..a=ptime:20..a=sendrecv..--++--
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bKVC4C3ast
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [process_rcvd_msg, trans_layer.cpp:1727] DEBUG:  Reply matched an existing transaction
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [update_uac_reply, trans_layer.cpp:1785] DEBUG:  update_uac_reply(reply code = 200, trans=0x7f1920005d40)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [update_uac_reply, trans_layer.cpp:1924] DEBUG:  Positive final reply to INVITE transaction (state=3)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type L at time=2233 (repeated=0)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [parse, AmMimeBody.cpp:589] DEBUG:  saving single-part body
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [sip_msg2am_reply, SipCtrlInterface.cpp:673] DEBUG:  MIME body successfully parsed
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [prepare_routes_uac, SipCtrlInterface.cpp:916] DEBUG:  route_field = [<sip:127.0.0.1;r2=on;lr;ftag=676F98ED-5BA3A432000A7364-09E1B700;did=767.2401>, <sip:192.168.253.77;r2=on;lr;ftag=676F98ED-5BA3A432000A7364-09E1B700;did=767.2401>]
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [handle_sip_reply, SipCtrlInterface.cpp:813] DEBUG:  Received reply: 200 OK
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [handle_sip_reply, SipCtrlInterface.cpp:814] DEBUG:  reply.callid = <badc6355-fb93-4f8a-b0ea-f3bb4816730e>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [handle_sip_reply, SipCtrlInterface.cpp:815] DEBUG:  reply.from_tag = <676F98ED-5BA3A432000A7364-09E1B700>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [handle_sip_reply, SipCtrlInterface.cpp:816] DEBUG:  reply.to_tag = <8aec53fc-2817-435a-b674-6a31b4600c90>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [handle_sip_reply, SipCtrlInterface.cpp:817] DEBUG:  reply.contact = <<sip:43190899250-qrhsodhehkl28@192.168.253.60:5060;transport=udp>>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [handle_sip_reply, SipCtrlInterface.cpp:818] DEBUG:  reply.to_uri = <sip:43190899250-qrhsodhehkl28@192.168.253.60:5060;transport=udp>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [handle_sip_reply, SipCtrlInterface.cpp:819] DEBUG:  cseq = <10>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [handle_sip_reply, SipCtrlInterface.cpp:820] DEBUG:  reply.route = <<sip:127.0.0.1;r2=on;lr;ftag=676F98ED-5BA3A432000A7364-09E1B700;did=767.2401>, <sip:192.168.253.77;r2=on;lr;ftag=676F98ED-5BA3A432000A7364-09E1B700;did=767.2401>>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [handle_sip_reply, SipCtrlInterface.cpp:821] DEBUG:  hdrs = <Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, REFER, MESSAGE..Supported: 100rel, timer, replaces, norefersub..Server: Asterisk LocaPhone..X-TNG-SBC-PeerIP: 217.70.195.35..X-TNG-SBC-ACCESS-IP: 82.97.166.254..>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [handle_sip_reply, SipCtrlInterface.cpp:822] DEBUG:  body-ct = <application/sdp>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a11e700] [handle_sip_reply, SipCtrlInterface.cpp:828] DEBUG:  ^^ M [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] ru SIP reply 200 OK handled ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Connected, running, 1 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (15AmSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [process, AmSession.cpp:638] DEBUG:  AmSession processing event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onRxReply, AmBasicSipDialog.cpp:462] DEBUG:  onRxReply(rep = 200 OK): transaction found!
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onRxSdp, AmOfferAnswer.cpp:215] DEBUG:  entering onRxSdp(), oa_state=OfferSent
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 10726, payloads: 8 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_attr, AmSdp.cpp:1158] DEBUG:  found unknown value for media attribute 'direction'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [setState, AmOfferAnswer.cpp:69] DEBUG:  setting SIP dialog O/A status: OfferSent->Completed
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onRxSdp, AmOfferAnswer.cpp:265] DEBUG:  oa_state: OfferSent -> Completed
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSdpCompleted, CallLeg.cpp:1681] DEBUG:  676F98ED-5BA3A432000A7364-09E1B700: oaCompleted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onInvite2xx, AmB2BSession.cpp:558] DEBUG:  no 200 ACK now: waiting for the 200 ACK from the other side...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, SBCCallLeg.cpp:622] DEBUG:  onSipReply: 200 OK (fwd=1)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, SBCCallLeg.cpp:623] DEBUG:  onSipReply: content-type = application/sdp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, CallLeg.cpp:979] DEBUG:  676F98ED-5BA3A432000A7364-09E1B700: SIP reply 200/10 INVITE (to relayed request) received in Connected state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, AmB2BSession.cpp:466] DEBUG:  onSipReply: INVITE -> 200 OK (fwd=true), c-t=application/sdp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, AmB2BSession.cpp:488] DEBUG:  relaying B2B SIP reply 200 OK
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [inplaceHeaderFilter, HeaderFilter.cpp:197] DEBUG:  applying 1 header filters
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-peerip' by blacklist
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-access-ip' by blacklist
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [relayEvent, SBCCallLeg.cpp:484] DEBUG:  filtering body for reply 'INVITE' (c/t 'application/sdp')
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [filterSdp, SBCCallLeg.cpp:1423] DEBUG:  filtering body
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 10726, payloads: 8 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sdp_attr, AmSdp.cpp:1158] DEBUG:  found unknown value for media attribute 'direction'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [relayEvent, AmB2BSession.cpp:587] DEBUG:  AmB2BSession::relayEvent: to other_id='2800E6F0-5BA3A432000AC5CA-49836700'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onSipReply, AmB2BSession.cpp:493] DEBUG:  not removing relayed INVITE transaction yet...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [updateCall, SBCCallRegistry.cpp:50] DEBUG:  SBCCallRegistry: Updated call '2800E6F0-5BA3A432000AC5CA-49836700' - rtag to: '8aec53fc-2817-435a-b674-6a31b4600c90'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (15AmSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Connected, running, 1 UACTransPending, 0 usages ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Connected, running, 0 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (16B2BSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BReply, CallLeg.cpp:580] DEBUG:  2800E6F0-5BA3A432000AC5CA-49836700: B2B SIP reply 200/11584787 INVITE received in Connected state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BReply, CallLeg.cpp:608] DEBUG:  handling reply via AmB2BSession
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BEvent, AmB2BSession.cpp:176] DEBUG:  AmB2BSession::onB2BEvent
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BEvent, AmB2BSession.cpp:240] DEBUG:  B2BSipReply: 200 OK (fwd=true)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onB2BEvent, AmB2BSession.cpp:242] DEBUG:  B2BSipReply: content-type = application/sdp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 10726, payloads: 8 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_attr, AmSdp.cpp:1158] DEBUG:  found unknown value for media attribute 'direction'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [updateLocalSdp, CallLeg.cpp:1617] DEBUG:  2800E6F0-5BA3A432000AC5CA-49836700: updateLocalSdp (OA: 1)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse, AmMimeBody.cpp:589] DEBUG:  saving single-part body
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relaySip, AmB2BSession.cpp:864] DEBUG:  relaying SIP reply 200 OK
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [reply, AmBasicSipDialog.cpp:597] DEBUG:  reply: transaction found!
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_line_ex, AmSdp.cpp:570] DEBUG:  parsing SDP message...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_connection, AmSdp.cpp:802] DEBUG:  SDP: got session level connection: IP4 192.168.253.60
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_media, AmSdp.cpp:945] DEBUG:  SDP: got media: port 10726, payloads: 8 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sdp_attr, AmSdp.cpp:1158] DEBUG:  found unknown value for media attribute 'direction'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [setState, AmOfferAnswer.cpp:69] DEBUG:  setting SIP dialog O/A status: OfferRecved->Completed
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [patch_contact_transport, trans_layer.cpp:160] DEBUG:  contact: <<sip:192.168.253.77:5080>>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5080) to int (5080)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_reply, trans_layer.cpp:413] DEBUG:  reply_len = 819
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [is_opt_set, transport.cpp:76] DEBUG:  trsp_socket::socket_options = 0x0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send_reply, trans_layer.cpp:588] DEBUG:  Sending to 192.168.253.60:5060 <SIP/2.0 200 OK..Via: SIP/2.0/UDP 192.168.253.60:50...>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [send, udp_trsp.cpp:259] DEBUG: send  msg to 192.168.253.60:5060.--++--.SIP/2.0 200 OK..Via: SIP/2.0/UDP 192.168.253.60:5060;branch=z9hG4bKhp7tv83070s0rni1fi20sb00cbs90.1..Call-ID: 68033A0E-5BA3A432000AC5D0-49836700..CSeq: 11584787 INVITE..From: <sip:01998@213.178.65.167>;tag=00-08150-00f3f58d-56d546ad3..To: <sip:04319089925448@sip-vip.tng.de>;tag=2800E6F0-5BA3A432000AC5CA-49836700..Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, PRACK, REGISTER, REFER, MESSAGE..Supported: 100rel, timer, replaces, norefersub..Server: Asterisk LocaPhone..Contact: <sip:192.168.253.77:5080;transport=udp>..Content-Type: application/sdp..Content-Length: 214....v=0..o=- 1094331725 2083156141 IN IP4 217.70.195.35..s=Asterisk..c=IN IP4 192.168.253.60..t=0 0..m=audio 10726 RTP/AVP 8 0..a=rtpmap:8 PCMA/8000/1..a=rtpmap:0 PCMU/8000/1..a=sendrecv..a=ptime:20..a=direction:both..--++--
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [update_uas_reply, trans_layer.cpp:2139] DEBUG:  update_uas_reply(t=0x7f1934001880)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type G at time=659 (repeated=0)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [reset_timer, sip_trans.cpp:247] DEBUG:  New timer of type H at time=2234 (repeated=0)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onReplySent, AmB2BSession.cpp:543] DEBUG:  recvd_req.erase(<11584787,INVITE>)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onTransFinished, CallLeg.cpp:1723] DEBUG:  UAC/UAS transaction finished
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSdpCompleted, CallLeg.cpp:1681] DEBUG:  2800E6F0-5BA3A432000AC5CA-49836700: oaCompleted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [saveSessionDescription, AmB2BSession.cpp:662] DEBUG:  saving session description (application/sdp, v=0..o=- 1094331725 2083156141 IN IP4 217.70.195.3...)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (16B2BSipReplyEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Connected, running, 0 UACTransPending, 0 usages ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [run, udp_trsp.cpp:352] DEBUG: vv M [|] u recvd msg via UDP from 192.168.253.60:5060 vv.--++--.ACK sip:192.168.253.77:5080;transport=udp SIP/2.0..Via: SIP/2.0/UDP 192.168.253.60:5060;branch=z9hG4bK1scril00909q8gl7jif0.1..Call-ID: 68033A0E-5BA3A432000AC5D0-49836700..CSeq: 11584787 ACK..From: <sip:01998@213.178.65.167>;tag=00-08150-00f3f58d-56d546ad3..To: <sip:04319089925448@sip-vip.tng.de>;tag=2800E6F0-5BA3A432000AC5CA-49836700..Content-Length: 0..X-TNG-SBC-PeerIP: 213.178.65.167..X-TNG-SBC-ACCESS-IP: 82.97.159.90..Max-Forwards: 70....--++--
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5080) to int (5080)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bK1scril00909q8gl7jif0.1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [match_request, trans_table.cpp:99] DEBUG:  Matching ACK request
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [match_request, trans_table.cpp:118] DEBUG:  do_3261_match = 1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [process_rcvd_msg, trans_layer.cpp:1634] DEBUG:  ACK matched INVITE transaction 0x7f1934001880
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [update_uas_request, trans_layer.cpp:2216] DEBUG:  update_uas_request(t=0x7f1934001880)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [process_rcvd_msg, trans_layer.cpp:1637] DEBUG:  update_uas_request(bucket,t=0x7f1934001880,msg) = 10
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [process_rcvd_msg, trans_layer.cpp:1654] DEBUG:  Passing ACK to the UA.
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_request, SipCtrlInterface.cpp:765] DEBUG:  Received new request from <192.168.253.60:5060/udp> on intf #0
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f190a21f700] [handle_sip_request, SipCtrlInterface.cpp:788] DEBUG:  ^^ M [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Ru SIP request ACK handled ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Connected, running, 0 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (17AmSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [process, AmSession.cpp:638] DEBUG:  AmSession processing event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onRxRequest, AmBasicSipDialog.cpp:308] DEBUG:  AmBasicSipDialog::onRxRequest(req = ACK)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onRequestIn, AmOfferAnswer.cpp:155] DEBUG:  200 ACK received: resetting OA state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipRequest, CallLeg.cpp:928] DEBUG:  2800E6F0-5BA3A432000AC5CA-49836700: SIP request 11584787 ACK received in Connected state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [onSipRequest, AmB2BSession.cpp:352] DEBUG:  relaying B2B SIP request (fwd) ACK sip:192.168.253.77:5080;transport=udp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:197] DEBUG:  applying 1 header filters
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-peerip' by blacklist
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [inplaceHeaderFilter, HeaderFilter.cpp:226] DEBUG:  erasing header 'x-tng-sbc-access-ip' by blacklist
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relayEvent, SBCCallLeg.cpp:438] DEBUG:  filtering body for request 'ACK' (c/t '')
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [filterSdp, SBCCallLeg.cpp:1423] DEBUG:  filtering body
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [relayEvent, AmB2BSession.cpp:587] DEBUG:  AmB2BSession::relayEvent: to other_id='676F98ED-5BA3A432000A7364-09E1B700'
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [postEvent, AmEventQueue.cpp:54] DEBUG:  AmEventQueue: trying to post event
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [postEvent, AmEventQueue.cpp:70] DEBUG:  AmEventQueue: event posted
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (17AmSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949735700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [68033A0E-5BA3A432000AC5D0-49836700|2800E6F0-5BA3A432000AC5CA-49836700] Connected, running, 0 UACTransPending, 0 usages ^^
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:97] DEBUG:  running processing loop
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [run, AmSessionProcessor.cpp:133] DEBUG:  processing events for  up to 1 sessions
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:346] DEBUG:  vv S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Connected, running, 1 UACTransPending, 0 usages vv
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:85] DEBUG:  before processing event (18B2BSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onB2BEvent, AmB2BSession.cpp:176] DEBUG:  AmB2BSession::onB2BEvent
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onB2BEvent, AmB2BSession.cpp:186] DEBUG:  B2BSipRequest: ACK (fwd=true)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [relaySip, AmB2BSession.cpp:823] DEBUG:  sending relayed 200 ACK
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port () to int (5060)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [set_next_hop, trans_layer.cpp:924] DEBUG:  no transport specified, setting default one (udp)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [set_next_hop, trans_layer.cpp:931] DEBUG:  next_hop:next_port is <127.0.0.1:0/udp>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [resolve_targets, resolver.cpp:1080] DEBUG:  sip_destination: 127.0.0.1:0/udp
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [set_destination_ip, resolver.cpp:1005] DEBUG:  checking whether '127.0.0.1' is IP address...
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [set_destination_ip, resolver.cpp:1063] DEBUG:  set destination to 127.0.0.1:5060
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [debug, resolver.cpp:794] DEBUG:  target list:
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [debug, resolver.cpp:801] DEBUG:  #011127.0.0.1:5060/udp to target list
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_request, trans_layer.cpp:1267] DEBUG:  send_request to R-URI <sip:43190899250-qrhsodhehkl28@192.168.253.60:5060;transport=udp>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [patch_contact_transport, trans_layer.cpp:160] DEBUG:  contact: <<sip:127.0.0.1:5080>>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5080) to int (5080)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_sip_uri, parse_uri.cpp:338] DEBUG:  Converted URI port (5060) to int (5060)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_via_params, parse_via.cpp:521] DEBUG:  parsed branch: z9hG4bKRLfRva6.
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [parse_via_params, parse_via.cpp:544] DEBUG:  has_rport: 1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_request, trans_layer.cpp:1303] DEBUG:  Sending to 127.0.0.1:5060 <ACK sip:43190899250-qrhsodhehkl28@192.168.253.60:5060;transport=udp SIP/2.0..Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKRLfRva6.;rport..From: <sip:01998@213.178.65.167>;tag=676F98ED-5BA3A432000A7364-09E1B700..To: <sip:04319089925448@sip-vip.tng.de>;tag=8aec53fc-2817-435a-b674-6a31b4600c90..CSeq: 10 ACK..Call-ID: badc6355-fb93-4f8a-b0ea-f3bb4816730e..Route: <sip:127.0.0.1;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>, <sip:192.168.253.77;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Max-Forwards: 70..Contact: <sip:127.0.0.1:5080;transport=udp>..Content-Length: 0.......>
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send, udp_trsp.cpp:259] DEBUG: send  msg to 127.0.0.1:5060.--++--.ACK sip:43190899250-qrhsodhehkl28@192.168.253.60:5060;transport=udp SIP/2.0..Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKRLfRva6.;rport..From: <sip:01998@213.178.65.167>;tag=676F98ED-5BA3A432000A7364-09E1B700..To: <sip:04319089925448@sip-vip.tng.de>;tag=8aec53fc-2817-435a-b674-6a31b4600c90..CSeq: 10 ACK..Call-ID: badc6355-fb93-4f8a-b0ea-f3bb4816730e..Route: <sip:127.0.0.1;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>, <sip:192.168.253.77;r2=on;lr;ftag=8aec53fc-2817-435a-b674-6a31b4600c90;did=767.2401>..Max-Forwards: 70..Contact: <sip:127.0.0.1:5080;transport=udp>..Content-Length: 0....--++--
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_request, trans_layer.cpp:1330] DEBUG:  update_uac_request tt->_t =(nil)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [match_request, trans_table.cpp:99] DEBUG:  Matching ACK request
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [match_request, trans_table.cpp:118] DEBUG:  do_3261_match = 1
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [update_uac_request, trans_layer.cpp:2083] DEBUG:  update_uac_request(200 ACK, t=0x7f1920005d40)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [send_request, trans_layer.cpp:1352] DEBUG:  logger = (nil)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onTransFinished, CallLeg.cpp:1723] DEBUG:  UAC/UAS transaction finished
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [onRequestSent, AmOfferAnswer.cpp:444] DEBUG:  200 ACK sent: resetting OA state
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processEvents, AmEventQueue.cpp:89] DEBUG:  event processed (18B2BSipRequestEvent)
Sep 20 15:44:19 voip-lab-proxy02 sems[13117]: [#7f1949836700] [processingCycle, AmSession.cpp:365] DEBUG:  ^^ S [badc6355-fb93-4f8a-b0ea-f3bb4816730e|676F98ED-5BA3A432000A7364-09E1B700] Connected, running, 0 UACTransPending, 0 usages ^^