1(21) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/525) [[INVITE sip:3228090000@172.32.0.6 SIP/2.0 0D  0A Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-]]
 1(21) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request:
 1(21) DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg():  method:  <INVITE>
 1(21) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg():  uri:     <sip:3228090000@172.32.0.6>
 1(21) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
 1(21) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-254-1-0>; state=16
 1(21) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 1(21) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
 1(21) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
 1(21) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
 1(21) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [41]; uri=[sip:3228090000@172.32.0.6]
 1(21) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [callee <sip:3228090000@172.32.0.6>
], to tag []
 1(21) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <INVITE>
 1(21) DEBUG: <core> [core/receive.c:246]: receive_msg(): --- received sip message - request - call-id: [T1_MYSER] - cseq: [1 INVITE]
 1(21) DEBUG: <core> [core/receive.c:296]: receive_msg(): preparing to run routing scripts...
 1(21) DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70 
 1(21) DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=144
 1(21) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
 1(21) INFO: <script>: route [INVITE sip:3228090000@172.32.0.6 SIP/2.0
Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-0
From:  <sip:caller@172.32.100.100:5055>;tag=1
To: callee <sip:3228090000@172.32.0.6>
Call-ID: T1_MYSER
CSeq: 1 INVITE
Contact: sip:caller@172.32.100.100:5055
Max-Forwards: 69
Subject: Performance Test
Content-Type: application/sdp
Content-Length:   144

v=0
o=caller 53655765 2353687637 IN IP4 172.32.100.100
s=-
c=IN IP4 172.32.100.100
t=0 0
m=audio 6000 RTP/AVP 0
a=rtpmap:0 PCMU/8000
]
 1(21) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1
 1(21) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
 1(21) DEBUG: siptrace [siptrace.c:501]: sip_trace_store_db(): database connection not initialized
 1(21) DEBUG: siptrace [siptrace_hep.c:498]: pipport2su(): the port string is 5055
 1(21) DEBUG: siptrace [siptrace_hep.c:498]: pipport2su(): the port string is 5060
 1(21) DEBUG: <core> [core/proxy.c:264]: mk_proxy(): doing DNS lookup...
 1(21) DEBUG: siptrace [siptrace_hep.c:183]: trace_send_hep3_duplicate(): setting up the socket_info
 1(21) DEBUG: sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered
 1(21) DEBUG: sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed
 1(21) DEBUG: sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered
 1(21) DEBUG: sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed
 1(21) DEBUG: sanity [sanity.c:305]: check_required_headers(): check_required_headers entered
 1(21) DEBUG: sanity [sanity.c:313]: check_required_headers(): check_required_headers passed
 1(21) DEBUG: sanity [sanity.c:479]: check_cseq_method(): check_cseq_method entered
 1(21) DEBUG: sanity [sanity.c:512]: check_cseq_method(): check_cseq_method passed
 1(21) DEBUG: sanity [sanity.c:521]: check_cseq_value(): check_cseq_value entered
 1(21) DEBUG: sanity [sanity.c:549]: check_cseq_value(): check_cseq_value passed
 1(21) DEBUG: sanity [sanity.c:558]: check_cl(): check_cl entered
 1(21) DEBUG: sanity [sanity.c:583]: check_cl(): check_cl passed
 1(21) DEBUG: sanity [sanity.c:595]: check_expires_value(): check_expires_value entered
 1(21) DEBUG: sanity [sanity.c:632]: check_expires_value(): no expires header found
 1(21) DEBUG: sanity [sanity.c:728]: check_parse_uris(): check_parse_uris entered
 1(21) DEBUG: sanity [sanity.c:732]: check_parse_uris(): parsing ruri
 1(21) DEBUG: sanity [sanity.c:746]: check_parse_uris(): looking up From header
 1(21) DEBUG: sanity [sanity.c:786]: check_parse_uris(): parsing From URI
 1(21) DEBUG: sanity [sanity.c:804]: check_parse_uris(): looking up To header
 1(21) DEBUG: sanity [sanity.c:826]: check_parse_uris(): check_parse_uris(): parsing To URI
 1(21) DEBUG: sanity [sanity.c:871]: check_parse_uris(): check_parse_uris passed
 1(21) DEBUG: sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1
 1(21) DEBUG: siputils [checks.c:120]: has_totag(): no totag
 1(21) DEBUG: tm [t_lookup.c:1043]: t_check_msg(): msg (0x7fdebe9530d8) id=1/21 global id=0/0 T start=0xffffffffffffffff
 1(21) DEBUG: tm [t_lookup.c:500]: t_lookup_request(): start searching: hash=43121, isACK=0
 1(21) DEBUG: tm [t_lookup.c:458]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK-254-1-0]
 1(21) DEBUG: tm [t_lookup.c:682]: t_lookup_request(): no transaction found
 1(21) DEBUG: tm [t_lookup.c:1113]: t_check_msg(): msg (0x7fdebe9530d8) id=1/21 global id=1/21 T end=(nil)
 1(21) DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 10==10 && [172.32.0.6] == [172.32.0.6]
 1(21) DEBUG: <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
 1(21) DEBUG: tm [t_lookup.c:1346]: t_newtran(): msg (0x7fdebe9530d8) id=1/21 global id=1/21 T start=(nil)
 1(21) DEBUG: tm [t_lookup.c:500]: t_lookup_request(): start searching: hash=43121, isACK=0
 1(21) DEBUG: tm [t_lookup.c:458]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK-254-1-0]
 1(21) DEBUG: tm [t_lookup.c:682]: t_lookup_request(): no transaction found
 1(21) DEBUG: tm [t_hooks.c:349]: run_reqin_callbacks_internal(): trans=0x7fdeb786ebe8, callback type 1, id 0 entered
 1(21) DEBUG: siptrace [siptrace.c:982]: trace_onreq_in(): trace off...
 1(21) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 calculated: 79cddb135aabfc42736fd9e9fd826ba8
 1(21) DEBUG: tm [t_lookup.c:1043]: t_check_msg(): msg (0x7fdebe9530d8) id=1/21 global id=1/21 T start=0x7fdeb786ebe8
 1(21) DEBUG: tm [t_lookup.c:1116]: t_check_msg(): T (0x7fdeb786ebe8) already found for msg (0x7fdebe9530d8)!
 1(21) DEBUG: <core> [core/msg_translator.c:162]: check_via_address(): (172.32.100.100, 172.32.100.100, 0)
 1(21) DEBUG: tm [t_reply.c:597]: _reply_light(): reply sent out. buf=0x7fdebe91b390: SIP/2.0 100 Trying t..., shmem=0x7fdeb78713d0: SIP/2.0 100 Trying t
 1(21) DEBUG: tm [t_reply.c:607]: _reply_light(): finished
 1(21) DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 10==10 && [172.32.0.6] == [172.32.0.6]
 1(21) DEBUG: <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
 1(21) DEBUG: app_perl [perlfunc.c:63]: perl_exec_simple(): running perl function "on_new_invite" 1(21) DEBUG: rr [loose.c:1226]: is_direction(): param ftag not found
 1(21) DEBUG: tm [t_lookup.c:1346]: t_newtran(): msg (0x7fdebe9530d8) id=1/21 global id=1/21 T start=0x7fdeb786ebe8
 1(21) DEBUG: tm [t_lookup.c:1354]: t_newtran(): transaction already in process 0x7fdeb786ebe8
 1(21) DEBUG: <core> [core/msg_translator.c:162]: check_via_address(): (172.32.100.100, 172.32.100.100, 0)
 1(21) DEBUG: tm [t_funcs.c:375]: t_relay_to(): new transaction forwarded
 1(21) DEBUG: <core> [core/receive.c:354]: receive_msg(): request-route executed in: 22747 usec
 1(21) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(21) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(21) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(21) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(21) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(21) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(21) DEBUG: <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil)
 1(21) DEBUG: <core> [core/receive.c:458]: receive_msg(): cleaning up
 2(22) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/417) [[SIP/2.0 100 Trying 0D  0A Via: SIP/2.0/UDP 172.32.0.6;rport=5060;received=172.32.0.6;branch=z9hG4bK178a.79]]
 2(22) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): SIP Reply  (status):
 2(22) DEBUG: <core> [core/parser/msg_parser.c:622]: parse_msg():  version: <SIP/2.0>
 2(22) DEBUG: <core> [core/parser/msg_parser.c:624]: parse_msg():  status:  <100>
 2(22) DEBUG: <core> [core/parser/msg_parser.c:626]: parse_msg():  reason:  <Trying>
 2(22) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
 2(22) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 234, <received> = <172.32.0.6>; state=6
 2(22) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK178a.79cddb135aabfc42736fd9e9fd826ba8.0>; state=16
 2(22) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 2(22) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
 2(22) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
 2(22) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-254-1-0>; state=16
 2(22) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 2(22) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=78
 2(22) DEBUG: <core> [core/parser/msg_parser.c:511]: parse_headers(): this is the second via
 2(22) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
 2(22) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [43]; uri=[sip:3228090000@172.32.0.6]
 2(22) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body ["callee" <sip:3228090000@172.32.0.6>
], to tag []
 2(22) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <INVITE>
 2(22) DEBUG: <core> [core/receive.c:246]: receive_msg(): --- received sip message - reply - call-id: [T1_MYSER] - cseq: [1 INVITE]
 2(22) DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0
 2(22) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
 2(22) INFO: <script>: on_reply_route [SIP/2.0 100 Trying
Via: SIP/2.0/UDP 172.32.0.6;rport=5060;received=172.32.0.6;branch=z9hG4bK178a.79cddb135aabfc42736fd9e9fd826ba8.0
Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-0
Record-Route: <sip:172.32.0.6:5060;lr;ftag=1>
Call-ID: T1_MYSER
From: <sip:caller@172.32.100.100>;tag=1
To: "callee" <sip:3228090000@172.32.0.6>
CSeq: 1 INVITE
Server: MYX Callcontrol
Content-Length:  0

]
 2(22) DEBUG: tm [t_lookup.c:1043]: t_check_msg(): msg (0x7fdebe9530d8) id=1/22 global id=0/0 T start=0xffffffffffffffff
 2(22) DEBUG: tm [t_lookup.c:920]: t_reply_matching(): t_reply_matching: hash 43121 label 0 branch 0
 2(22) DEBUG: tm [t_lookup.c:974]: t_reply_matching(): reply (0x7fdebe9530d8) matched an active transaction (T=0x7fdeb786ebe8)!
 2(22) DEBUG: tm [t_lookup.c:1113]: t_check_msg(): msg (0x7fdebe9530d8) id=1/22 global id=1/22 T end=0x7fdeb786ebe8
 2(22) DEBUG: tm [t_reply.c:2243]: reply_received(): transaction found - T:0x7fdeb786ebe8 branch:0
 2(22) DEBUG: tm [t_reply.c:2258]: reply_received(): org. status uas=100, uac[0]=0 local=0 is_invite=1)
 2(22) DEBUG: <core> [core/action.c:1555]: run_actions(): null action list (rec_level=1)
 2(22) DEBUG: tm [t_reply.c:1266]: t_should_relay_response(): ->>>>>>>>> T_code=100, new_code=100
 2(22) DEBUG: tm [t_reply.c:1521]: t_should_relay_response(): rps provisional - uas status: 100
 2(22) DEBUG: tm [t_reply.c:1824]: relay_reply(): reply status=5 branch=0, save=0, relay=-1 icode=0 msg status=100
 2(22) DEBUG: <core> [core/receive.c:442]: receive_msg(): reply-route executed in: 107 usec
 2(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 2(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 2(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 2(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 2(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 2(22) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 2(22) DEBUG: <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil)
 2(22) DEBUG: <core> [core/receive.c:458]: receive_msg(): cleaning up
 3(23) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/903) [[SIP/2.0 200 OK 0D  0A Via: SIP/2.0/UDP 172.32.0.6;rport=5060;received=172.32.0.6;branch=z9hG4bK178a.79cddb]]
 3(23) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): SIP Reply  (status):
 3(23) DEBUG: <core> [core/parser/msg_parser.c:622]: parse_msg():  version: <SIP/2.0>
 3(23) DEBUG: <core> [core/parser/msg_parser.c:624]: parse_msg():  status:  <200>
 3(23) DEBUG: <core> [core/parser/msg_parser.c:626]: parse_msg():  reason:  <OK>
 3(23) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
 3(23) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 234, <received> = <172.32.0.6>; state=6
 3(23) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK178a.79cddb135aabfc42736fd9e9fd826ba8.0>; state=16
 3(23) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 3(23) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
 3(23) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
 3(23) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-254-1-0>; state=16
 3(23) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 3(23) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=78
 3(23) DEBUG: <core> [core/parser/msg_parser.c:511]: parse_headers(): this is the second via
 3(23) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=6fb31703-d630-4140-a41b-7270cdcae85b
 3(23) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
 3(23) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [84]; uri=[sip:3228090000@172.32.0.6]
 3(23) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body ["callee" <sip:3228090000@172.32.0.6>], to tag [6fb31703-d630-4140-a41b-7270cdcae85b]
 3(23) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <INVITE>
 3(23) DEBUG: <core> [core/receive.c:246]: receive_msg(): --- received sip message - reply - call-id: [T1_MYSER] - cseq: [1 INVITE]
 3(23) DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=178
 3(23) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
 3(23) INFO: <script>: on_reply_route [SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.32.0.6;rport=5060;received=172.32.0.6;branch=z9hG4bK178a.79cddb135aabfc42736fd9e9fd826ba8.0
Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-0
Record-Route: <sip:172.32.0.6:5060;lr;ftag=1>
Call-ID: T1_MYSER
From: <sip:caller@172.32.100.100>;tag=1
To: "callee" <sip:3228090000@172.32.0.6>;tag=6fb31703-d630-4140-a41b-7270cdcae85b
CSeq: 1 INVITE
Server: MYX Callcontrol
Contact: <sip:172.32.10.70:5060>
Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, REGISTER, MESSAGE, REFER
Supported: timer, replaces, norefersub
Remote-Party-ID: <sip:s@172.32.0.6>;privacy=off;screen=no
Content-Type: application/sdp
Content-Length:   178

v=0
o=- 53655765 2353687639 IN IP4 172.32.10.70
s=session
c=IN IP4 172.32.10.70
t=0 0
m=audio 10006 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=ptime:20
a=maxptime:150
a=sendrecv
]
 3(23) DEBUG: tm [t_lookup.c:1043]: t_check_msg(): msg (0x7fdebe9530d8) id=1/23 global id=0/0 T start=0xffffffffffffffff
 3(23) DEBUG: tm [t_lookup.c:920]: t_reply_matching(): t_reply_matching: hash 43121 label 0 branch 0
 3(23) DEBUG: tm [t_lookup.c:974]: t_reply_matching(): reply (0x7fdebe9530d8) matched an active transaction (T=0x7fdeb786ebe8)!
 3(23) DEBUG: tm [t_lookup.c:1113]: t_check_msg(): msg (0x7fdebe9530d8) id=1/23 global id=1/23 T end=0x7fdeb786ebe8
 3(23) DEBUG: tm [t_reply.c:2243]: reply_received(): transaction found - T:0x7fdeb786ebe8 branch:0
 3(23) DEBUG: tm [t_reply.c:2258]: reply_received(): org. status uas=100, uac[0]=100 local=0 is_invite=1)
 3(23) DEBUG: <core> [core/action.c:1555]: run_actions(): null action list (rec_level=1)
 3(23) DEBUG: tm [t_reply.c:1266]: t_should_relay_response(): ->>>>>>>>> T_code=100, new_code=200
 3(23) DEBUG: tm [t_reply.c:1518]: t_should_relay_response(): rps completed - uas status: 100
 3(23) DEBUG: tm [t_reply.c:1824]: relay_reply(): reply status=4 branch=0, save=0, relay=0 icode=0 msg status=200
 3(23) DEBUG: <core> [core/msg_translator.c:2288]: generate_res_buf_from_sip_res(): old size: 903, new size: 789

+++++++++++++++++++++++++++++++++   We need to log this following sip message from a routing block +++++++++++++++++++++++++++++++++++++
 
 3(23) DEBUG: <core> [core/msg_translator.c:2306]: generate_res_buf_from_sip_res(): copied size: orig:130, new: 16, rest: 773 msg=
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-0
Record-Route: <sip:172.32.0.6:5060;lr;ftag=1>
Call-ID: T1_MYSER
From: <sip:caller@172.32.100.100>;tag=1
To: "callee" <sip:3228090000@172.32.0.6>;tag=6fb31703-d630-4140-a41b-7270cdcae85b
CSeq: 1 INVITE
Server: MYX Callcontrol
Contact: <sip:172.32.10.70:5060>
Allow: OPTIONS, SUBSCRIBE, NOTIFY, PUBLISH, INVITE, ACK, BYE, CANCEL, UPDATE, REGISTER, MESSAGE, REFER
Supported: timer, replaces, norefersub
Remote-Party-ID: <sip:s@172.32.0.6>;privacy=off;screen=no
Content-Type: application/sdp
Content-Length:   178

v=0
o=- 53655765 2353687639 IN IP4 172.32.10.70
s=session
c=IN IP4 172.32.10.70
t=0 0
m=audio 10006 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=ptime:20
a=maxptime:150
a=sendrecv

++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++

 3(23) DEBUG: tm [t_reply.c:2016]: relay_reply(): reply buffer sent out
 3(23) DEBUG: tm [t_reply.c:1667]: cleanup_uac_timers(): RETR/FR timers reset
 3(23) DEBUG: <core> [core/receive.c:442]: receive_msg(): reply-route executed in: 308 usec
 3(23) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(23) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(23) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(23) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(23) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(23) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(23) DEBUG: <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil)
 3(23) DEBUG: <core> [core/receive.c:458]: receive_msg(): cleaning up
 4(24) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (112/100/432) [[ACK sip:172.32.10.70:5060 SIP/2.0 0D  0A Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-4 0D  0A From]]
 4(24) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request:
 4(24) DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg():  method:  <ACK>
 4(24) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg():  uri:     <sip:172.32.10.70:5060>
 4(24) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
 4(24) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-254-1-4>; state=16
 4(24) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 4(24) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
 4(24) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
 4(24) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=6fb31703-d630-4140-a41b-7270cdcae85b
 4(24) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
 4(24) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [87]; uri=[sip:3228090000@172.32.0.6:5060]
 4(24) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [callee <sip:3228090000@172.32.0.6:5060>], to tag [6fb31703-d630-4140-a41b-7270cdcae85b]
 4(24) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <ACK>
 4(24) DEBUG: <core> [core/receive.c:246]: receive_msg(): --- received sip message - request - call-id: [T1_MYSER] - cseq: [1 ACK]
 4(24) DEBUG: <core> [core/receive.c:296]: receive_msg(): preparing to run routing scripts...
 4(24) DEBUG: sl [sl_funcs.c:397]: sl_filter_ACK(): too late to be a local ACK!
 4(24) DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70 
 4(24) DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0
 4(24) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
 4(24) INFO: <script>: route [ACK sip:172.32.10.70:5060 SIP/2.0
Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-4
From: caller <sip:caller@172.32.100.100:5055>;tag=1
To: callee <sip:3228090000@172.32.0.6:5060>;tag=6fb31703-d630-4140-a41b-7270cdcae85b
Call-ID: T1_MYSER
CSeq: 1 ACK
Contact: sip:caller@172.32.100.100:5055
Max-Forwards: 69
Subject: Performance Test
Route: <sip:172.32.0.6:5060;lr;ftag=1>
Content-Length: 0

]
 4(24) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1
 4(24) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
 4(24) DEBUG: siptrace [siptrace.c:501]: sip_trace_store_db(): database connection not initialized
 4(24) DEBUG: siptrace [siptrace_hep.c:498]: pipport2su(): the port string is 5055
 4(24) DEBUG: siptrace [siptrace_hep.c:498]: pipport2su(): the port string is 5060
 4(24) DEBUG: <core> [core/proxy.c:264]: mk_proxy(): doing DNS lookup...
 4(24) DEBUG: siptrace [siptrace_hep.c:183]: trace_send_hep3_duplicate(): setting up the socket_info
 4(24) DEBUG: sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered
 4(24) DEBUG: sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed
 4(24) DEBUG: sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered
 4(24) DEBUG: sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed
 4(24) DEBUG: sanity [sanity.c:305]: check_required_headers(): check_required_headers entered
 4(24) DEBUG: sanity [sanity.c:313]: check_required_headers(): check_required_headers passed
 4(24) DEBUG: sanity [sanity.c:479]: check_cseq_method(): check_cseq_method entered
 4(24) DEBUG: sanity [sanity.c:512]: check_cseq_method(): check_cseq_method passed
 4(24) DEBUG: sanity [sanity.c:521]: check_cseq_value(): check_cseq_value entered
 4(24) DEBUG: sanity [sanity.c:549]: check_cseq_value(): check_cseq_value passed
 4(24) DEBUG: sanity [sanity.c:558]: check_cl(): check_cl entered
 4(24) DEBUG: sanity [sanity.c:583]: check_cl(): check_cl passed
 4(24) DEBUG: sanity [sanity.c:595]: check_expires_value(): check_expires_value entered
 4(24) DEBUG: sanity [sanity.c:632]: check_expires_value(): no expires header found
 4(24) DEBUG: sanity [sanity.c:728]: check_parse_uris(): check_parse_uris entered
 4(24) DEBUG: sanity [sanity.c:732]: check_parse_uris(): parsing ruri
 4(24) DEBUG: sanity [sanity.c:746]: check_parse_uris(): looking up From header
 4(24) DEBUG: sanity [sanity.c:786]: check_parse_uris(): parsing From URI
 4(24) DEBUG: sanity [sanity.c:804]: check_parse_uris(): looking up To header
 4(24) DEBUG: sanity [sanity.c:826]: check_parse_uris(): check_parse_uris(): parsing To URI
 4(24) DEBUG: sanity [sanity.c:871]: check_parse_uris(): check_parse_uris passed
 4(24) DEBUG: sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1
 4(24) DEBUG: siputils [checks.c:123]: has_totag(): totag found
 4(24) DEBUG: rr [loose.c:91]: is_preloaded(): is_preloaded: No
 4(24) DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 12==10 && [172.32.10.70] == [172.32.0.6]
 4(24) DEBUG: <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
 4(24) DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 12==10 && [172.32.10.70] == [172.32.0.6]
 4(24) DEBUG: <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
 4(24) DEBUG: <core> [core/forward.c:412]: check_self(): host != me
 4(24) DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 10==10 && [172.32.0.6] == [172.32.0.6]
 4(24) DEBUG: <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
 4(24) DEBUG: rr [loose.c:813]: after_loose(): Topmost route URI: 'sip:172.32.0.6:5060;lr;ftag=1' is me
 4(24) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
 4(24) DEBUG: rr [loose.c:182]: find_next_route(): No next Route HF found
 4(24) DEBUG: rr [loose.c:843]: after_loose(): No next URI found
 4(24) DEBUG: tm [t_lookup.c:1346]: t_newtran(): msg (0x7fdebe9530d8) id=1/24 global id=0/0 T start=0xffffffffffffffff
 4(24) DEBUG: tm [t_lookup.c:500]: t_lookup_request(): start searching: hash=43121, isACK=1
 4(24) DEBUG: tm [t_lookup.c:458]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK-254-1-4]
 4(24) DEBUG: tm [t_lookup.c:682]: t_lookup_request(): no transaction found
 4(24) DEBUG: tm [t_funcs.c:287]: t_relay_to(): forwarding ACK statelessly
 4(24) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 calculated: 91c51b26440bcf821361c13776c84017
 4(24) DEBUG: <core> [core/msg_translator.c:162]: check_via_address(): (172.32.100.100, 172.32.100.100, 0)
 4(24) DEBUG: <core> [core/forward.c:557]: forward_request(): Sending:
ACK sip:172.32.10.70:5060 SIP/2.0
Record-Route: <sip:172.32.0.6:5060;ftag=1;lr>
Via: SIP/2.0/UDP 172.32.0.6;branch=z9hG4bK178a.91c51b26440bcf821361c13776c84017.0
Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-4
From: caller <sip:caller@172.32.100.100:5055>;tag=1
To: callee <sip:3228090000@172.32.0.6:5060>;tag=6fb31703-d630-4140-a41b-7270cdcae85b
Call-ID: T1_MYSER
CSeq: 1 ACK
Contact: sip:caller@172.32.100.100:5055
Max-Forwards: 68
Subject: Performance Test
Content-Length: 0

.
 4(24) DEBUG: <core> [core/forward.c:559]: forward_request(): orig. len=432, new_len=522, proto=1
 4(24) DEBUG: <core> [core/receive.c:354]: receive_msg(): request-route executed in: 568 usec
 4(24) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 4(24) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 4(24) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 4(24) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 4(24) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 4(24) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 4(24) DEBUG: <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil)
 4(24) DEBUG: <core> [core/receive.c:458]: receive_msg(): cleaning up
 5(25) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (112/100/432) [[BYE sip:172.32.10.70:5060 SIP/2.0 0D  0A Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-6 0D  0A From]]
 5(25) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request:
 5(25) DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg():  method:  <BYE>
 5(25) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg():  uri:     <sip:172.32.10.70:5060>
 5(25) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
 5(25) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-254-1-6>; state=16
 5(25) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 5(25) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
 5(25) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
 5(25) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=6fb31703-d630-4140-a41b-7270cdcae85b
 5(25) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
 5(25) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [87]; uri=[sip:3228090000@172.32.0.6:5060]
 5(25) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [callee <sip:3228090000@172.32.0.6:5060>], to tag [6fb31703-d630-4140-a41b-7270cdcae85b]
 5(25) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <BYE>
 5(25) DEBUG: <core> [core/receive.c:246]: receive_msg(): --- received sip message - request - call-id: [T1_MYSER] - cseq: [2 BYE]
 5(25) DEBUG: <core> [core/receive.c:296]: receive_msg(): preparing to run routing scripts...
 5(25) DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70 
 5(25) DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0
 5(25) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
 5(25) INFO: <script>: route [BYE sip:172.32.10.70:5060 SIP/2.0
Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-6
From: caller <sip:caller@172.32.100.100:5055>;tag=1
To: callee <sip:3228090000@172.32.0.6:5060>;tag=6fb31703-d630-4140-a41b-7270cdcae85b
Call-ID: T1_MYSER
CSeq: 2 BYE
Contact: sip:caller@172.32.100.100:5055
Max-Forwards: 69
Subject: Performance Test
Content-Length: 0
Route: <sip:172.32.0.6:5060;lr;ftag=1>

]
 5(25) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1
 5(25) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
 5(25) DEBUG: siptrace [siptrace.c:501]: sip_trace_store_db(): database connection not initialized
 5(25) DEBUG: siptrace [siptrace_hep.c:498]: pipport2su(): the port string is 5055
 5(25) DEBUG: siptrace [siptrace_hep.c:498]: pipport2su(): the port string is 5060
 5(25) DEBUG: <core> [core/proxy.c:264]: mk_proxy(): doing DNS lookup...
 5(25) DEBUG: siptrace [siptrace_hep.c:183]: trace_send_hep3_duplicate(): setting up the socket_info
 5(25) DEBUG: sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered
 5(25) DEBUG: sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed
 5(25) DEBUG: sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered
 5(25) DEBUG: sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed
 5(25) DEBUG: sanity [sanity.c:305]: check_required_headers(): check_required_headers entered
 5(25) DEBUG: sanity [sanity.c:313]: check_required_headers(): check_required_headers passed
 5(25) DEBUG: sanity [sanity.c:479]: check_cseq_method(): check_cseq_method entered
 5(25) DEBUG: sanity [sanity.c:512]: check_cseq_method(): check_cseq_method passed
 5(25) DEBUG: sanity [sanity.c:521]: check_cseq_value(): check_cseq_value entered
 5(25) DEBUG: sanity [sanity.c:549]: check_cseq_value(): check_cseq_value passed
 5(25) DEBUG: sanity [sanity.c:558]: check_cl(): check_cl entered
 5(25) DEBUG: sanity [sanity.c:583]: check_cl(): check_cl passed
 5(25) DEBUG: sanity [sanity.c:595]: check_expires_value(): check_expires_value entered
 5(25) DEBUG: sanity [sanity.c:632]: check_expires_value(): no expires header found
 5(25) DEBUG: sanity [sanity.c:728]: check_parse_uris(): check_parse_uris entered
 5(25) DEBUG: sanity [sanity.c:732]: check_parse_uris(): parsing ruri
 5(25) DEBUG: sanity [sanity.c:746]: check_parse_uris(): looking up From header
 5(25) DEBUG: sanity [sanity.c:786]: check_parse_uris(): parsing From URI
 5(25) DEBUG: sanity [sanity.c:804]: check_parse_uris(): looking up To header
 5(25) DEBUG: sanity [sanity.c:826]: check_parse_uris(): check_parse_uris(): parsing To URI
 5(25) DEBUG: sanity [sanity.c:871]: check_parse_uris(): check_parse_uris passed
 5(25) DEBUG: sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1
 5(25) DEBUG: siputils [checks.c:123]: has_totag(): totag found
 5(25) DEBUG: rr [loose.c:91]: is_preloaded(): is_preloaded: No
 5(25) DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 12==10 && [172.32.10.70] == [172.32.0.6]
 5(25) DEBUG: <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
 5(25) DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 12==10 && [172.32.10.70] == [172.32.0.6]
 5(25) DEBUG: <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
 5(25) DEBUG: <core> [core/forward.c:412]: check_self(): host != me
 5(25) DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 10==10 && [172.32.0.6] == [172.32.0.6]
 5(25) DEBUG: <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
 5(25) DEBUG: rr [loose.c:813]: after_loose(): Topmost route URI: 'sip:172.32.0.6:5060;lr;ftag=1' is me
 5(25) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
 5(25) DEBUG: rr [loose.c:182]: find_next_route(): No next Route HF found
 5(25) DEBUG: rr [loose.c:843]: after_loose(): No next URI found
 5(25) DEBUG: tm [t_lookup.c:1346]: t_newtran(): msg (0x7fdebe9530d8) id=1/25 global id=0/0 T start=0xffffffffffffffff
 5(25) DEBUG: tm [t_lookup.c:500]: t_lookup_request(): start searching: hash=43118, isACK=0
 5(25) DEBUG: tm [t_lookup.c:458]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK-254-1-6]
 5(25) DEBUG: tm [t_lookup.c:682]: t_lookup_request(): no transaction found
 5(25) DEBUG: tm [t_hooks.c:349]: run_reqin_callbacks_internal(): trans=0x7fdeb7872b40, callback type 1, id 0 entered
 5(25) DEBUG: siptrace [siptrace.c:982]: trace_onreq_in(): trace off...
 5(25) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 calculated: 99dc492fe74dcfe1017828521a5fa362
 5(25) DEBUG: <core> [core/msg_translator.c:162]: check_via_address(): (172.32.100.100, 172.32.100.100, 0)
 5(25) DEBUG: tm [t_funcs.c:375]: t_relay_to(): new transaction forwarded
 5(25) DEBUG: <core> [core/receive.c:354]: receive_msg(): request-route executed in: 539 usec
 5(25) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 5(25) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 5(25) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 5(25) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 5(25) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 5(25) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 5(25) DEBUG: <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil)
 5(25) DEBUG: <core> [core/receive.c:458]: receive_msg(): cleaning up
 6(26) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (106/100/464) [[SIP/2.0 200 OK 0D  0A Via: SIP/2.0/UDP 172.32.0.6;rport=5060;received=172.32.0.6;branch=z9hG4bKe68a.99dc49]]
 6(26) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): SIP Reply  (status):
 6(26) DEBUG: <core> [core/parser/msg_parser.c:622]: parse_msg():  version: <SIP/2.0>
 6(26) DEBUG: <core> [core/parser/msg_parser.c:624]: parse_msg():  status:  <200>
 6(26) DEBUG: <core> [core/parser/msg_parser.c:626]: parse_msg():  reason:  <OK>
 6(26) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <5060>; state=6
 6(26) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 234, <received> = <172.32.0.6>; state=6
 6(26) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKe68a.99dc492fe74dcfe1017828521a5fa362.0>; state=16
 6(26) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 6(26) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
 6(26) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
 6(26) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-254-1-6>; state=16
 6(26) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 6(26) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=78
 6(26) DEBUG: <core> [core/parser/msg_parser.c:511]: parse_headers(): this is the second via
 6(26) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=6fb31703-d630-4140-a41b-7270cdcae85b
 6(26) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
 6(26) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [84]; uri=[sip:3228090000@172.32.0.6]
 6(26) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body ["callee" <sip:3228090000@172.32.0.6>], to tag [6fb31703-d630-4140-a41b-7270cdcae85b]
 6(26) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <2> <BYE>
 6(26) DEBUG: <core> [core/receive.c:246]: receive_msg(): --- received sip message - reply - call-id: [T1_MYSER] - cseq: [2 BYE]
 6(26) DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0
 6(26) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
 6(26) INFO: <script>: on_reply_route [SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.32.0.6;rport=5060;received=172.32.0.6;branch=z9hG4bKe68a.99dc492fe74dcfe1017828521a5fa362.0
Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-6
Record-Route: <sip:172.32.0.6:5060;lr;ftag=1>
Call-ID: T1_MYSER
From: "caller" <sip:caller@172.32.100.100>;tag=1
To: "callee" <sip:3228090000@172.32.0.6>;tag=6fb31703-d630-4140-a41b-7270cdcae85b
CSeq: 2 BYE
Server: MYX Callcontrol
Content-Length:  0

]
 6(26) DEBUG: tm [t_lookup.c:1043]: t_check_msg(): msg (0x7fdebe9530d8) id=1/26 global id=0/0 T start=0xffffffffffffffff
 6(26) DEBUG: tm [t_lookup.c:920]: t_reply_matching(): t_reply_matching: hash 43118 label 0 branch 0
 6(26) DEBUG: tm [t_lookup.c:974]: t_reply_matching(): reply (0x7fdebe9530d8) matched an active transaction (T=0x7fdeb7872b40)!
 6(26) DEBUG: tm [t_lookup.c:1113]: t_check_msg(): msg (0x7fdebe9530d8) id=1/26 global id=1/26 T end=0x7fdeb7872b40
 6(26) DEBUG: tm [t_reply.c:2243]: reply_received(): transaction found - T:0x7fdeb7872b40 branch:0
 6(26) DEBUG: tm [t_reply.c:2258]: reply_received(): org. status uas=0, uac[0]=0 local=0 is_invite=0)
 6(26) DEBUG: <core> [core/action.c:1555]: run_actions(): null action list (rec_level=1)
 6(26) DEBUG: tm [t_reply.c:1266]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=200
 6(26) DEBUG: tm [t_reply.c:1518]: t_should_relay_response(): rps completed - uas status: 0
 6(26) DEBUG: tm [t_reply.c:1824]: relay_reply(): reply status=4 branch=0, save=0, relay=0 icode=0 msg status=200
 6(26) DEBUG: <core> [core/msg_translator.c:2288]: generate_res_buf_from_sip_res(): old size: 464, new size: 350
 6(26) DEBUG: <core> [core/msg_translator.c:2306]: generate_res_buf_from_sip_res(): copied size: orig:130, new: 16, rest: 334 msg=
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.32.100.100:5055;branch=z9hG4bK-254-1-6
Record-Route: <sip:172.32.0.6:5060;lr;ftag=1>
Call-ID: T1_MYSER
From: "caller" <sip:caller@172.32.100.100>;tag=1
To: "callee" <sip:3228090000@172.32.0.6>;tag=6fb31703-d630-4140-a41b-7270cdcae85b
CSeq: 2 BYE
Server: MYX Callcontrol
Content-Length:  0


 6(26) DEBUG: tm [t_reply.c:2016]: relay_reply(): reply buffer sent out
 6(26) DEBUG: tm [t_reply.c:1667]: cleanup_uac_timers(): RETR/FR timers reset
 6(26) DEBUG: <core> [core/receive.c:442]: receive_msg(): reply-route executed in: 178 usec
 6(26) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 6(26) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 6(26) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 6(26) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 6(26) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 6(26) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 6(26) DEBUG: <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil)
 6(26) DEBUG: <core> [core/receive.c:458]: receive_msg(): cleaning up