[Serusers] ser , rtpproxy and pstn gateway

mashudi mashudiflexi at telkom.co.id
Thu Jan 24 05:10:30 CET 2008


I have two separate network, for public and vpn , i have install ser and 
rtpproxy on different machine, all user from public network will 
register to proxy server on ip 10.44.9.18 and the rtp will be handle by 
another machine using ip 10.44.9.17 , all call comming from client on 
public ip will route to pstn gateway using cantata media gateway on ip 
10.177.107.90 (vpn ip).  When client call to pstn gateway, the 
signalling reach the callee, but after callee pickup the phone, the 
client using x-lite still in calling status, and rtpproxy not receive 
rtp from pstn gateway.

the rtpproxy have two nic using two ip for public and vpn, and ser as 
proxy using two nic public ip and vpn ip.
any one can help?

here is the log for rtpproxy and ser.
the rtpproxy log :

Starting rtpproxy: rtpproxy started, pid 25745
received command "2573_0 V"
sending reply "2573_0 20040107
"
received command "2574_0 V"
sending reply "2574_0 20040107
"
received command "2572_0 V"
sending reply "2572_0 20040107
"


received command "2572_6 U NjQzNmQzNzFjZTBmMzM5MDUxYjQwODFlOTFmMTdhMzI. 
10.11.11.152 30126 9d08dc55"
new session NjQzNmQzNzFjZTBmMzM5MDUxYjQwODFlOTFmMTdhMzI., tag 9d08dc55 
requested, type strong
new session on a port 35010 created, tag 9d08dc55
pre-filling caller's address with 10.11.11.152:30126
sending reply "2572_6 35010 10.44.9.17
"



the ser log:
0(2572) SIP Request:
 0(2572)  method:  <NOTIFY>
 0(2572)  uri:     <sip:02170743627 at 10.11.11.152:65100>
 0(2572)  version: <SIP/2.0>
 0(2572) parse_headers: flags=1
 0(2572) Found param type 232, <branch> = 
<z9hG4bK-d87543-9533d56650536c16-1--d87543->; state=6
 0(2572) Found param type 235, <rport> = <n/a>; state=17
 0(2572) end of header reached, state=5
 0(2572) parse_headers: Via found, flags=1
 0(2572) parse_headers: this is the first via
 0(2572) After parse_msg...
 0(2572) preparing to run routing scripts...
 0(2572) parse_headers: flags=128
 0(2572) DEBUG:maxfwd:is_maxfwd_present: value = 70
 0(2572) DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16
 0(2572) parse_headers: flags=8
 0(2572) DEBUG: add_param: tag=9e3f287c
 0(2572) end of header reached, state=29
 0(2572) DEBUG: get_hdr_field: <To> [56]; uri=[sip:02170743627 at 10.44.9.18]
 0(2572) DEBUG: to body ["02170743627"<sip:02170743627 at 10.44.9.18>]
 0(2572) DEBUG: add_param: tag=59420d70
 0(2572) end of header reached, state=29
 0(2572) parse_headers: flags=256
 0(2572) is_preloaded: No
 0(2572) grep_sock_info - checking if host==us: 12==10 &&  
[10.11.11.152] == [10.44.9.18]
 0(2572) grep_sock_info - checking if port 5060 matches port 65100
 0(2572) grep_sock_info - checking if host==us: 12==14 &&  
[10.11.11.152] == [10.177.107.124]
 0(2572) grep_sock_info - checking if port 5060 matches port 65100
 0(2572) grep_sock_info - checking if host==us: 12==10 &&  
[10.11.11.152] == [10.44.9.18]
 0(2572) grep_sock_info - checking if port 5060 matches port 65100
 0(2572) grep_sock_info - checking if host==us: 12==14 &&  
[10.11.11.152] == [10.177.107.124]
 0(2572) grep_sock_info - checking if port 5060 matches port 65100
 0(2572) check_self: host != me
 0(2572) grep_sock_info - checking if host==us: 10==10 &&  [10.44.9.18] 
== [10.44.9.18]
 0(2572) grep_sock_info - checking if port 5060 matches port 5060
 0(2572) after_loose: Topmost route URI: 
'sip:10.44.9.18;lr;ftag=9e3f287c' is me
 0(2572) parse_headers: flags=256
 0(2572) get_hdr_field: cseq <CSeq>: <13> <NOTIFY>
 0(2572) DEBUG: get_hdr_body : content_length=461
 0(2572) found end of header
 0(2572) find_next_route: No next Route HF found
 0(2572) after_loose: No next URI found
 0(2572) DEBUG: t_newtran: msg id=55 , global msg id=54 , T on 
entrance=0xffffffffffffffff
 0(2572) parse_headers: flags=-1
 0(2572) parse_headers: flags=60
 0(2572) t_lookup_request: start searching: hash=24011, isACK=0
 0(2572) DEBUG: RFC3261 transaction matching failed
 0(2572) DEBUG: t_lookup_request: no transaction found
 0(2572) DEBUG: mk_proxy: doing DNS lookup...
 0(2572) DEBUG: get_out_socket: socket determined: 0x6be9c8
 0(2572) check_via_address(10.11.11.152, 10.11.11.152, 0)
 0(2572) DEBUG: add_to_tail_of_timer[4]: 0x2ab57bba4208
 0(2572) DEBUG: add_to_tail_of_timer[0]: 0x2ab57bba4228
 0(2572) SER: new transaction fwd'ed
 0(2572) DEBUG:destroy_avp_list: destroying list (nil)
 0(2572) receive_msg: cleaning up
 0(2572) SIP Reply  (status):
 0(2572)  version: <SIP/2.0>
 0(2572)  status:  <200>
 0(2572)  reason:  <OK>
 0(2572) parse_headers: flags=1
 0(2572) Found param type 232, <branch> = <z9hG4bKbcd5.79134365.0>; state=16
 0(2572) end of header reached, state=5
 0(2572) parse_headers: Via found, flags=1
 0(2572) parse_headers: this is the first via
 0(2572) After parse_msg...
 0(2572) forward_reply: found module tm, passing reply to it
 0(2572) DEBUG: t_check: msg id=56 global id=55 T start=0xffffffffffffffff
 0(2572) parse_headers: flags=17
 0(2572) Found param type 232, <branch> = 
<z9hG4bK-d87543-9533d56650536c16-1--d87543->; state=6
 0(2572) Found param type 235, <rport> = <65100>; state=16
 0(2572) end of header reached, state=5
 0(2572) parse_headers: Via found, flags=17
 0(2572) parse_headers: this is the second via
 0(2572) DEBUG: add_param: tag=9e3f287c
 0(2572) end of header reached, state=29
 0(2572) DEBUG: get_hdr_field: <To> [56]; uri=[sip:02170743627 at 10.44.9.18]
 0(2572) DEBUG: to body ["02170743627"<sip:02170743627 at 10.44.9.18>]
 0(2572) get_hdr_field: cseq <CSeq>: <13> <NOTIFY>
 0(2572) DEBUG: t_reply_matching: hash 24011 label 1446261143 branch 0
 0(2572) DEBUG: t_reply_matching: reply matched (T=0x2ab57bba4030)!
 0(2572) DEBUG: t_check: msg id=56 global id=56 T end=0x2ab57bba4030
 0(2572) DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 
is_invite=0)
 0(2572) parse_headers: flags=64
 0(2572) parse_headers: flags=64
 0(2572) ->>>>>>>>> T_code=0, new_code=200
 0(2572) DEBUG: relay_reply: branch=0, save=0, relay=0
 0(2572)  old size: 531, new size: 472
 0(2572) build_res_from_sip_res: copied size: orig:267, new: 208, rest: 
264 msg=
SIP/2.0 200 OK

Via: SIP/2.0/UDP 
10.11.11.152:65100;branch=z9hG4bK-d87543-9533d56650536c16-1--d87543-;rport=65100

Record-Route: <sip:10.44.9.18;lr;ftag=59420d70>

Contact: <sip:02170743627 at 10.11.11.152:65100>

To: "02170743627"<sip:02170743627 at 10.44.9.18>;tag=9e3f287c

From: "02170743627"<sip:02170743627 at 10.44.9.18>;tag=59420d70

Call-ID: MWNiZWE5ODMyN2U0MTJmMWMyNjQzMTNiNGJjZmRjYjA.

CSeq: 13 NOTIFY

User-Agent: X-Lite release 1011s stamp 41150

Content-Length: 0




 0(2572) WARNING:vqm_resize: resize(0) called
 0(2572) DEBUG: add_to_tail_of_timer[2]: 0x2ab57bba40b0
 0(2572) DEBUG: reply relayed. buf=0x6c9930: SIP/2.0 2..., 
shmem=0x2ab57bba6b10: SIP/2.0 2
 0(2572) DEBUG:destroy_avp_list: destroying list (nil)
 0(2572) receive_msg: cleaning up
 1(2573) DEBUG: timer routine:4,tl=0x2ab57bba4208 next=(nil)
 1(2573) DEBUG: timer routine:2,tl=0x2ab57bba40b0 next=(nil)
 1(2573) DEBUG: wait_handler : removing 0x2ab57bba4030 from table
 1(2573) DEBUG: delete transaction 0x2ab57bba4030
 1(2573) DEBUG: wait_handler : done
 0(2572) SIP Request:
 0(2572)  method:  <INVITE>
 0(2572)  uri:     <sip:02170890010 at 10.44.9.18>
 0(2572)  version: <SIP/2.0>
 0(2572) parse_headers: flags=1
 0(2572) Found param type 232, <branch> = 
<z9hG4bK-d87543-2623ee4d6908a453-1--d87543->; state=6
 0(2572) Found param type 235, <rport> = <n/a>; state=17
 0(2572) end of header reached, state=5
 0(2572) parse_headers: Via found, flags=1
 0(2572) parse_headers: this is the first via
 0(2572) After parse_msg...
 0(2572) preparing to run routing scripts...
 0(2572) parse_headers: flags=128
 0(2572) DEBUG:maxfwd:is_maxfwd_present: value = 70
 0(2572) DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16
 0(2572) parse_headers: flags=8
 0(2572) end of header reached, state=9
 0(2572) DEBUG: get_hdr_field: <To> [43]; uri=[sip:02170890010 at 10.44.9.18]
 0(2572) DEBUG: to body ["02170890010"<sip:02170890010 at 10.44.9.18>

]
 0(2572) DEBUG: add_param: tag=9d08dc55
 0(2572) end of header reached, state=29
 0(2572) parse_headers: flags=256
 0(2572) get_hdr_field: cseq <CSeq>: <1> <INVITE>
 0(2572) DEBUG: get_hdr_body : content_length=420
 0(2572) found end of header
 0(2572) find_first_route: No Route headers found
 0(2572) loose_route: There is no Route HF
 0(2572) grep_sock_info - checking if host==us: 10==10 &&  [10.44.9.18] 
== [10.44.9.18]
 0(2572) grep_sock_info - checking if port 5060 matches port 5060
 0(2572) parse_headers: flags=16384
 0(2572) pre_auth(): Credentials with given realm not found
 0(2572) build_auth_hf(): 'Proxy-Authenticate: Digest 
realm="10.44.9.18", nonce="4798817c850ce0e3c233a35804d9be1afe7fe2a3"

'
 0(2572) parse_headers: flags=-1
 0(2572) check_via_address(10.11.11.152, 10.11.11.152, 0)
 0(2572) DEBUG:destroy_avp_list: destroying list (nil)
 0(2572) receive_msg: cleaning up
 0(2572) SIP Request:
 0(2572)  method:  <ACK>
 0(2572)  uri:     <sip:02170890010 at 10.44.9.18>
 0(2572)  version: <SIP/2.0>
 0(2572) parse_headers: flags=1
 0(2572) Found param type 232, <branch> = 
<z9hG4bK-d87543-2623ee4d6908a453-1--d87543->; state=6
 0(2572) Found param type 235, <rport> = <n/a>; state=17
 0(2572) end of header reached, state=5
 0(2572) parse_headers: Via found, flags=1
 0(2572) parse_headers: this is the first via
 0(2572) After parse_msg...
 0(2572) preparing to run routing scripts...
 0(2572) parse_headers: flags=4
 0(2572) DEBUG: add_param: tag=a3f1a545ddce5205bb83afef24613e34.78aa
 0(2572) end of header reached, state=29
 0(2572) DEBUG: get_hdr_field: <To> [85]; uri=[sip:02170890010 at 10.44.9.18]
 0(2572) DEBUG: to body ["02170890010"<sip:02170890010 at 10.44.9.18>]
 0(2572) DEBUG: sl_filter_ACK : local ACK found -> dropping it!
 0(2572) DEBUG:destroy_avp_list: destroying list (nil)
 0(2572) receive_msg: cleaning up
 0(2572) SIP Request:
 0(2572)  method:  <INVITE>
 0(2572)  uri:     <sip:02170890010 at 10.44.9.18>
 0(2572)  version: <SIP/2.0>
 0(2572) parse_headers: flags=1
 0(2572) Found param type 232, <branch> = 
<z9hG4bK-d87543-363a1c17b37ac509-1--d87543->; state=6
 0(2572) Found param type 235, <rport> = <n/a>; state=17
 0(2572) end of header reached, state=5
 0(2572) parse_headers: Via found, flags=1
 0(2572) parse_headers: this is the first via
 0(2572) After parse_msg...
 0(2572) preparing to run routing scripts...
 0(2572) parse_headers: flags=128
 0(2572) DEBUG:maxfwd:is_maxfwd_present: value = 70
 0(2572) DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16
 0(2572) parse_headers: flags=8
 0(2572) end of header reached, state=9
 0(2572) DEBUG: get_hdr_field: <To> [43]; uri=[sip:02170890010 at 10.44.9.18]
 0(2572) DEBUG: to body ["02170890010"<sip:02170890010 at 10.44.9.18>

]
 0(2572) DEBUG: add_param: tag=9d08dc55
 0(2572) end of header reached, state=29
 0(2572) parse_headers: flags=256
 0(2572) get_hdr_field: cseq <CSeq>: <2> <INVITE>
 0(2572) DEBUG: get_hdr_body : content_length=420
 0(2572) found end of header
 0(2572) find_first_route: No Route headers found
 0(2572) loose_route: There is no Route HF
 0(2572) grep_sock_info - checking if host==us: 10==10 &&  [10.44.9.18] 
== [10.44.9.18]
 0(2572) grep_sock_info - checking if port 5060 matches port 5060
 0(2572) check_nonce(): comparing 
[4798817c850ce0e3c233a35804d9be1afe7fe2a3] and 
[4798817c850ce0e3c233a35804d9be1afe7fe2a3]
 0(2572) HA1 string calculated: 0f7e2f302e87dfe46c5ca6566ad32b47
 0(2572) check_response(): Our result = '82c47bef0adf71299b8fb157a15e0131'
 0(2572) check_response(): Authorization is OK
 0(2572) save_rpid(): rpid value is ''
 0(2572) check_username(): Digest username and URI username match
 0(2572) check_via_address(10.11.11.152, 10.11.11.152, 0)
 0(2572) parse_headers: flags=64
 0(2572) lookup(): '02170890010' Not found in usrloc
 0(2572) grep_sock_info - checking if host==us: 10==10 &&  [10.44.9.18] 
== [10.44.9.18]
 0(2572) grep_sock_info - checking if port 5060 matches port 5060
 0(2572) parse_headers: flags=64
 0(2572) parse_headers: flags=-1
 0(2572) DEBUG:check_content_type: type <application/sdp> found valid
 0(2572) parse_headers: flags=32
 0(2572) ERROR: extract_mediaip: no `c=' in SDP
 0(2572) DEBUG: t_newtran: msg id=59 , global msg id=56 , T on 
entrance=0xffffffffffffffff
 0(2572) parse_headers: flags=-1
 0(2572) parse_headers: flags=60
 0(2572) t_lookup_request: start searching: hash=48512, isACK=0
 0(2572) DEBUG: RFC3261 transaction matching failed
 0(2572) DEBUG: t_lookup_request: no transaction found
 0(2572) SER: new INVITE
 0(2572) parse_headers: flags=-1
 0(2572) check_via_address(10.11.11.152, 10.11.11.152, 0)
 0(2572) WARNING:vqm_resize: resize(0) called
 0(2572) DEBUG: reply sent out. buf=0x6c9930: SIP/2.0 1..., 
shmem=0x2ab57bba3ad8: SIP/2.0 1
 0(2572) DEBUG: _reply_light: finished
 0(2572) DEBUG: mk_proxy: doing DNS lookup...
 0(2572) DEBUG: get_out_socket: socket determined: 0x6bebb8
 0(2572) WARNING: get_send_socket: not listening on the requested 
socket, no fork mode?
 0(2572) parse_headers: flags=2048
 0(2572) parse_headers: flags=-1
 0(2572) clen_builder: content-length: 436 (436)
 0(2572) check_via_address(10.11.11.152, 10.11.11.152, 0)
 0(2572) DEBUG: add_to_tail_of_timer[4]: 0x2ab57bba4208
 0(2572) DEBUG: add_to_tail_of_timer[0]: 0x2ab57bba4228
 0(2572) SER: new transaction fwd'ed
 0(2572) DEBUG:destroy_avp_list: destroying list (nil)
 0(2572) receive_msg: cleaning up
 1(2573) DEBUG: timer routine:4,tl=0x2ab57bba4208 next=(nil)
 1(2573) DEBUG: retransmission_handler : request resending 
(t=0x2ab57bba4030, INVITE si ... )
 1(2573) DEBUG: add_to_tail_of_timer[5]: 0x2ab57bba4208
 1(2573) DEBUG: retransmission_handler : done
 1(2573) DEBUG: timer routine:5,tl=0x2ab57bba4208 next=(nil)
 1(2573) DEBUG: retransmission_handler : request resending 
(t=0x2ab57bba4030, INVITE si ... )
 1(2573) DEBUG: add_to_tail_of_timer[6]: 0x2ab57bba4208
 1(2573) DEBUG: retransmission_handler : done
 1(2573) DEBUG: timer routine:6,tl=0x2ab57bba4208 next=(nil)
 1(2573) DEBUG: retransmission_handler : request resending 
(t=0x2ab57bba4030, INVITE si ... )
 1(2573) DEBUG: add_to_tail_of_timer[7]: 0x2ab57bba4208
 1(2573) DEBUG: retransmission_handler : done
 1(2573) DEBUG: timer routine:7,tl=0x2ab57bba4208 next=(nil)
 1(2573) DEBUG: retransmission_handler : request resending 
(t=0x2ab57bba4030, INVITE si ... )
 1(2573) DEBUG: add_to_tail_of_timer[7]: 0x2ab57bba4208
 1(2573) DEBUG: retransmission_handler : done
 1(2573) DEBUG: get_out_socket: socket determined: 0x6be9c8
 0(2572) udp_rcv_loop: probing packet received from 10.11.11.152 19710
 1(2573) DEBUG: timer routine:7,tl=0x2ab57bba4208 next=(nil)
 1(2573) DEBUG: retransmission_handler : request resending 
(t=0x2ab57bba4030, INVITE si ... )
 1(2573) DEBUG: add_to_tail_of_timer[7]: 0x2ab57bba4208
 1(2573) DEBUG: retransmission_handler : done
 1(2573) DEBUG: timer routine:7,tl=0x2ab57bba4208 next=(nil)
 1(2573) DEBUG: retransmission_handler : request resending 
(t=0x2ab57bba4030, INVITE si ... )
 1(2573) DEBUG: add_to_tail_of_timer[7]: 0x2ab57bba4208
 1(2573) DEBUG: retransmission_handler : done
 1(2573) DEBUG: timer routine:7,tl=0x2ab57bba4208 next=(nil)
 1(2573) DEBUG: retransmission_handler : request resending 
(t=0x2ab57bba4030, INVITE si ... )
 1(2573) DEBUG: add_to_tail_of_timer[7]: 0x2ab57bba4208
 1(2573) DEBUG: retransmission_handler : done
 1(2573) DEBUG: timer routine:7,tl=0x2ab57bba4208 next=(nil)
 1(2573) DEBUG: retransmission_handler : request resending 
(t=0x2ab57bba4030, INVITE si ... )
 1(2573) DEBUG: add_to_tail_of_timer[7]: 0x2ab57bba4208
 1(2573) DEBUG: retransmission_handler : done
 1(2573) DEBUG: timer routine:0,tl=0x2ab57bba4228 next=(nil)
 1(2573) DEBUG: final_response_handler:stop retr. and send CANCEL 
(0x2ab57bba4030)
 1(2573) ->>>>>>>>> T_code=100, new_code=408
 1(2573) DEBUG: relay_reply: branch=0, save=0, relay=0
 1(2573) parse_headers: flags=-1
 1(2573) check_via_address(10.11.11.152, 10.11.11.152, 0)
 1(2573) DEBUG: add_to_tail_of_timer[4]: 0x2ab57bba4150
 1(2573) DEBUG: add_to_tail_of_timer[0]: 0x2ab57bba4170
 1(2573) DEBUG: reply relayed. buf=0x6c84d0: SIP/2.0 4..., 
shmem=0x2ab57bba3ad8: SIP/2.0 4
 1(2573) DEBUG: final_response_handler : done
 1(2573) DEBUG: timer routine:7,tl=0x2ab57bba4208 next=(nil)
 0(2572) SIP Request:
 0(2572)  method:  <ACK>
 0(2572)  uri:     <sip:02170890010 at 10.44.9.18>
 0(2572)  version: <SIP/2.0>
 0(2572) parse_headers: flags=1
 0(2572) Found param type 232, <branch> = 
<z9hG4bK-d87543-363a1c17b37ac509-1--d87543->; state=6
 0(2572) Found param type 235, <rport> = <n/a>; state=17
 0(2572) end of header reached, state=5
 0(2572) parse_headers: Via found, flags=1
 0(2572) parse_headers: this is the first via
 0(2572) After parse_msg...
 0(2572) preparing to run routing scripts...
 0(2572) DEBUG : sl_filter_ACK: to late to be a local ACK!
 0(2572) parse_headers: flags=128
 0(2572) DEBUG: add_param: tag=d548cf07be509c4dc64b42f06e6fb880-a911
 0(2572) end of header reached, state=29
 0(2572) DEBUG: get_hdr_field: <To> [85]; uri=[sip:02170890010 at 10.44.9.18]
 0(2572) DEBUG: to body ["02170890010"<sip:02170890010 at 10.44.9.18>]
 0(2572) get_hdr_field: cseq <CSeq>: <2> <ACK>
 0(2572) DEBUG: get_hdr_body : content_length=0
 0(2572) found end of header
 0(2572) DEBUG: is_maxfwd_present: max_forwards header not found!
 0(2572) DEBUG: add_param: tag=9d08dc55
 0(2572) end of header reached, state=29
 0(2572) parse_headers: flags=256
 0(2572) find_first_route: No Route headers found
 0(2572) loose_route: There is no Route HF
 0(2572) grep_sock_info - checking if host==us: 10==10 &&  [10.44.9.18] 
== [10.44.9.18]
 0(2572) grep_sock_info - checking if port 5060 matches port 5060
 0(2572) DEBUG: t_newtran: msg id=60 , global msg id=59 , T on 
entrance=0xffffffffffffffff
 0(2572) parse_headers: flags=-1
 0(2572) parse_headers: flags=60
 0(2572) t_lookup_request: start searching: hash=48512, isACK=1
 0(2572) DEBUG: RFC3261 transaction matched, 
tid=-d87543-363a1c17b37ac509-1--d87543-
 0(2572) DEBUG: t_lookup_request: transaction found (T=0x2ab57bba4030)
 0(2572) DEBUG: add_to_tail_of_timer[2]: 0x2ab57bba40b0
 0(2572) DEBUG:destroy_avp_list: destroying list (nil)
 0(2572) receive_msg: cleaning up
 1(2573) DEBUG: timer routine:4,tl=0x2ab57bba4150 next=(nil)
 1(2573) DEBUG: timer routine:2,tl=0x2ab57bba40b0 next=(nil)
 1(2573) DEBUG: wait_handler : removing 0x2ab57bba4030 from table
 1(2573) DEBUG: delete transaction 0x2ab57bba4030
 1(2573) DEBUG: wait_handler : done
 0(2572) SIP Request:
 0(2572)  method:  <NOTIFY>
 0(2572)  uri:     <sip:02170743627 at 10.11.11.152:65100>
 0(2572)  version: <SIP/2.0>
 0(2572) parse_headers: flags=1
 0(2572) Found param type 232, <branch> = 
<z9hG4bK-d87543-3217dc739e312401-1--d87543->; state=6
 0(2572) Found param type 235, <rport> = <n/a>; state=17
 0(2572) end of header reached, state=5
 0(2572) parse_headers: Via found, flags=1
 0(2572) parse_headers: this is the first via
 0(2572) After parse_msg...
 0(2572) preparing to run routing scripts...
 0(2572) parse_headers: flags=128
 0(2572) DEBUG:maxfwd:is_maxfwd_present: value = 70
 0(2572) DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16
 0(2572) parse_headers: flags=8
 0(2572) DEBUG: add_param: tag=9e3f287c
 0(2572) end of header reached, state=29
 0(2572) DEBUG: get_hdr_field: <To> [56]; uri=[sip:02170743627 at 10.44.9.18]
 0(2572) DEBUG: to body ["02170743627"<sip:02170743627 at 10.44.9.18>]
 0(2572) DEBUG: add_param: tag=59420d70
 0(2572) end of header reached, state=29
 0(2572) parse_headers: flags=256
 0(2572) is_preloaded: No
 0(2572) grep_sock_info - checking if host==us: 12==10 &&  
[10.11.11.152] == [10.44.9.18]
 0(2572) grep_sock_info - checking if port 5060 matches port 65100
 0(2572) grep_sock_info - checking if host==us: 12==14 &&  
[10.11.11.152] == [10.177.107.124]
 0(2572) grep_sock_info - checking if port 5060 matches port 65100
 0(2572) grep_sock_info - checking if host==us: 12==10 &&  
[10.11.11.152] == [10.44.9.18]
 0(2572) grep_sock_info - checking if port 5060 matches port 65100
 0(2572) grep_sock_info - checking if host==us: 12==14 &&  
[10.11.11.152] == [10.177.107.124]
 0(2572) grep_sock_info - checking if port 5060 matches port 65100
 0(2572) check_self: host != me
 0(2572) grep_sock_info - checking if host==us: 10==10 &&  [10.44.9.18] 
== [10.44.9.18]
 0(2572) grep_sock_info - checking if port 5060 matches port 5060
 0(2572) after_loose: Topmost route URI: 
'sip:10.44.9.18;lr;ftag=9e3f287c' is me
 0(2572) parse_headers: flags=256
 0(2572) get_hdr_field: cseq <CSeq>: <14> <NOTIFY>
 0(2572) DEBUG: get_hdr_body : content_length=425
 0(2572) found end of header
 0(2572) find_next_route: No next Route HF found
 0(2572) after_loose: No next URI found
 0(2572) DEBUG: t_newtran: msg id=61 , global msg id=60 , T on 
entrance=0xffffffffffffffff
 0(2572) parse_headers: flags=-1
 0(2572) parse_headers: flags=60
 0(2572) t_lookup_request: start searching: hash=24006, isACK=0
 0(2572) DEBUG: RFC3261 transaction matching failed
 0(2572) DEBUG: t_lookup_request: no transaction found
 0(2572) DEBUG: mk_proxy: doing DNS lookup...
 0(2572) DEBUG: get_out_socket: socket determined: 0x6be9c8
 0(2572) check_via_address(10.11.11.152, 10.11.11.152, 0)
 0(2572) DEBUG: add_to_tail_of_timer[4]: 0x2ab57bba4208
 0(2572) DEBUG: add_to_tail_of_timer[0]: 0x2ab57bba4228
 0(2572) SER: new transaction fwd'ed
 0(2572) DEBUG:destroy_avp_list: destroying list (nil)
 0(2572) receive_msg: cleaning up
 1(2573) DEBUG: timer routine:4,tl=0x2ab57bba4208 next=(nil)
 1(2573) DEBUG: retransmission_handler : request resending 
(t=0x2ab57bba4030, NOTIFY si ... )
 1(2573) DEBUG: add_to_tail_of_timer[5]: 0x2ab57bba4208
 1(2573) DEBUG: retransmission_handler : done
 0(2572) SIP Reply  (status):
 0(2572)  version: <SIP/2.0>
 0(2572)  status:  <200>
 0(2572)  reason:  <OK>
 0(2572) parse_headers: flags=1
 0(2572) Found param type 232, <branch> = <z9hG4bK6cd5.c487f5f5.0>; state=16
 0(2572) end of header reached, state=5
 0(2572) parse_headers: Via found, flags=1
 0(2572) parse_headers: this is the first via
 0(2572) After parse_msg...
 0(2572) forward_reply: found module tm, passing reply to it
 0(2572) DEBUG: t_check: msg id=62 global id=61 T start=0xffffffffffffffff
 0(2572) parse_headers: flags=17
 0(2572) Found param type 232, <branch> = 
<z9hG4bK-d87543-3217dc739e312401-1--d87543->; state=6
 0(2572) Found param type 235, <rport> = <65100>; state=16
 0(2572) end of header reached, state=5
 0(2572) parse_headers: Via found, flags=17
 0(2572) parse_headers: this is the second via
 0(2572) DEBUG: add_param: tag=9e3f287c
 0(2572) end of header reached, state=29
 0(2572) DEBUG: get_hdr_field: <To> [56]; uri=[sip:02170743627 at 10.44.9.18]
 0(2572) DEBUG: to body ["02170743627"<sip:02170743627 at 10.44.9.18>]
 0(2572) get_hdr_field: cseq <CSeq>: <14> <NOTIFY>
 0(2572) DEBUG: t_reply_matching: hash 24006 label 1600092236 branch 0
 0(2572) DEBUG: t_reply_matching: reply matched (T=0x2ab57bba4030)!
 0(2572) DEBUG: t_check: msg id=62 global id=62 T end=0x2ab57bba4030
 0(2572) DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 
is_invite=0)
 0(2572) parse_headers: flags=64
 0(2572) parse_headers: flags=64
 0(2572) ->>>>>>>>> T_code=0, new_code=200
 0(2572) DEBUG: relay_reply: branch=0, save=0, relay=0
 0(2572)  old size: 531, new size: 472
 0(2572) build_res_from_sip_res: copied size: orig:267, new: 208, rest: 
264 msg=
SIP/2.0 200 OK

Via: SIP/2.0/UDP 
10.11.11.152:65100;branch=z9hG4bK-d87543-3217dc739e312401-1--d87543-;rport=65100

Record-Route: <sip:10.44.9.18;lr;ftag=59420d70>

Contact: <sip:02170743627 at 10.11.11.152:65100>

To: "02170743627"<sip:02170743627 at 10.44.9.18>;tag=9e3f287c

From: "02170743627"<sip:02170743627 at 10.44.9.18>;tag=59420d70

Call-ID: MWNiZWE5ODMyN2U0MTJmMWMyNjQzMTNiNGJjZmRjYjA.

CSeq: 14 NOTIFY

User-Agent: X-Lite release 1011s stamp 41150

Content-Length: 0




 0(2572) WARNING:vqm_resize: resize(0) called
 0(2572) DEBUG: add_to_tail_of_timer[2]: 0x2ab57bba40b0
 0(2572) DEBUG: reply relayed. buf=0x6c9930: SIP/2.0 2..., 
shmem=0x2ab57bba6b10: SIP/2.0 2
 0(2572) DEBUG:destroy_avp_list: destroying list (nil)
 0(2572) receive_msg: cleaning up

-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: ser.cfg
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20080124/d02d27a1/attachment.txt>


More information about the sr-users mailing list