Hi all I have been looking at the debugs in order to try to figure out
If I'm doing something wrong at my SER.CFG
I have the following:
UA ----> SER -----> B2BUA -----> SER ------> PSTN-GW
1. The user agent place a call to the SER proxy.
2. SER Proxy receives the call and forwads to B2BUA (VOCAL at the same
server using UDP port 5065)
3. B2BUA receives the calls activates the Billing supervision and Sends
an invite for a new call to the SER.
4. SER receives the call from the B2BUA and rewrite host and port to the
PSTN-GW.
5. PSTN-GW receives the invite from the SER and sends back the ACK.
6. Inmediatly from some reason SER is sending a BYE to the call.
I'm attaching a debug from the SER and my SER.CFG file
Could anybody help me please?
Regards
Alberto Cruz
Jun 25 08:43:31 sipsrv ser[1936]: SIP Request:
Jun 25 08:43:31 sipsrv ser[1936]: method: <INVITE>
Jun 25 08:43:31 sipsrv ser[1936]: uri: <sip:018183324166@sipsrv.conecta-te.com>
Jun 25 08:43:31 sipsrv ser[1936]: version: <SIP/2.0>
Jun 25 08:43:31 sipsrv ser[1936]: parse_headers: flags=1
Jun 25 08:43:31 sipsrv ser[1936]: Found param type 232, <branch> =
<z9hG4bK-46d68929>; state=16
Jun 25 08:43:31 sipsrv ser[1936]: end of header reached, state=5
Jun 25 08:43:31 sipsrv ser[1936]: parse_headers: Via found, flags=1
Jun 25 08:43:31 sipsrv ser[1936]: parse_headers: this is the first via
Jun 25 08:43:31 sipsrv ser[1936]: After parse_msg...
Jun 25 08:43:31 sipsrv ser[1936]: preparing to run routing scripts...
Jun 25 08:43:31 sipsrv ser[1936]: parse_headers: flags=128
Jun 25 08:43:31 sipsrv ser[1936]: end of header reached, state=9
Jun 25 08:43:31 sipsrv ser[1936]: DEBUG: get_hdr_field: <To> [42];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:31 sipsrv ser[1936]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>^M ]
Jun 25 08:43:31 sipsrv ser[1936]: get_hdr_field: cseq <CSeq>: <101>
<INVITE>
Jun 25 08:43:31 sipsrv ser[1936]: DEBUG:maxfwd:is_maxfwd_present: value = 70
Jun 25 08:43:31 sipsrv ser[1936]: DBG:maxfwd:process_maxfwd_header: value 70 decreased to
16
Jun 25 08:43:31 sipsrv ser[1936]: parse_headers: flags=64
Jun 25 08:43:31 sipsrv ser[1936]: DEBUG: add_param: tag=7a83401cfe54b69o0
Jun 25 08:43:31 sipsrv ser[1936]: end of header reached, state=29
Jun 25 08:43:31 sipsrv ser[1936]: parse_headers: flags=256
Jun 25 08:43:31 sipsrv ser[1936]: DEBUG: get_hdr_body : content_length=316
Jun 25 08:43:31 sipsrv ser[1936]: found end of header
Jun 25 08:43:31 sipsrv ser[1936]: find_first_route: No Route headers found
Jun 25 08:43:31 sipsrv ser[1936]: loose_route: There is no Route HF
Jun 25 08:43:31 sipsrv ser[1936]: grep_sock_info - checking if host==us: 21==11 &&
[
sipsrv.conecta-te.com] == [200.94.75.6]
Jun 25 08:43:31 sipsrv ser[1936]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:31 sipsrv ser[1936]: grep_sock_info - checking if host==us: 21==11 &&
[
sipsrv.conecta-te.com] == [200.94.75.6]
Jun 25 08:43:31 sipsrv ser[1936]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:31 sipsrv ser[1936]: grep_sock_info - checking if host==us: 21==11 &&
[
sipsrv.conecta-te.com] == [200.94.75.6]
Jun 25 08:43:31 sipsrv ser[1936]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:31 sipsrv ser[1936]: grep_sock_info - checking if host==us: 21==11 &&
[
sipsrv.conecta-te.com] == [200.94.75.6]
Jun 25 08:43:31 sipsrv ser[1936]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:31 sipsrv ser[1936]: Hey this request is NOT from B2BUA
Jun 25 08:43:31 sipsrv ser[1936]: FORWARDING TO B2BUA
Jun 25 08:43:31 sipsrv ser[1936]: parse_headers: flags=-1
Jun 25 08:43:31 sipsrv ser[1936]: parse_headers: flags=64
Jun 25 08:43:31 sipsrv ser[1936]: parse_headers: flags=64
Jun 25 08:43:31 sipsrv ser[1936]: parse_headers: flags=-1
Jun 25 08:43:31 sipsrv ser[1936]: check_via_address(200.67.33.247, 172.31.253.127, 0)
Jun 25 08:43:31 sipsrv ser[1936]: Sending: INVITE sip:018183324166@sipsrv.conecta-te.com
SIP/2.0^M Record-Route:
<sip:018183324166@200.94.75.6:5060;nat=yes;ftag=7a83401cfe54b69o0;lr=on>^M Via:
SIP/2.0/UDP 200.94.75.6;branch=0^M Via: SIP/2.0/UDP
172.31.253.127:5060;rport=60425;received=200.67.33.247;branch=z9hG4bK-46d68929^M From:
8183651723 <sip:8183651723@sipsrv.conecta-te.com>;tag=7a83401cfe54b69o0^M To:
<sip:018183324166@sipsrv.conecta-te.com>^M Call-ID:
b5fcf1e1-baf4a709(a)172.31.253.127^M CSeq: 101 INVITE^M Max-Forwards: 16^M Contact:
8183651723 <sip:8183651723@200.67.33.247:60425>^M Expires: 240^M User-Agent:
Linksys/PAP2-2.0.12(LS)^M Content-Length: 316^M Allow: ACK, BYE, CANCEL, INFO, INVITE,
NOTIFY, OPTIONS, REFER^M Supported: x-sipura^M Content-Type: application/sdp^M P-hint:
PASANDO POR EL B2BUA^M P-hint: APLICO NAT AL B2BUA^M ^M v=0^M o=- 23012599 23012599 IN IP4
172.31.253.127^M s=-^M c=IN IP4 172.31.253.127^M t=0 0^M m=audio 16458 RTP/AVP 18 0 4 8
100 101^M a=rtpmap:18 G729a/8000^M a=rtpmap:0 PCMU/800
Jun 25 08:43:31 sipsrv ser[1936]: orig. len=884, new_len=1105, proto=1
Jun 25 08:43:31 sipsrv ser[1936]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:31 sipsrv ser[1936]: receive_msg: cleaning up
Jun 25 08:43:31 sipsrv ser[1929]: SIP Request:
Jun 25 08:43:31 sipsrv ser[1929]: method: <INVITE>
Jun 25 08:43:31 sipsrv ser[1929]: uri: <sip:018183324166@200.94.75.6:5060>
Jun 25 08:43:31 sipsrv ser[1929]: version: <SIP/2.0>
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: flags=1
Jun 25 08:43:31 sipsrv ser[1929]: end of header reached, state=5
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: Via found, flags=1
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: this is the first via
Jun 25 08:43:31 sipsrv ser[1929]: After parse_msg...
Jun 25 08:43:31 sipsrv ser[1929]: preparing to run routing scripts...
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: flags=128
Jun 25 08:43:31 sipsrv ser[1929]: end of header reached, state=9
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: get_hdr_field: <To> [42];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>^M ]
Jun 25 08:43:31 sipsrv ser[1929]: get_hdr_field: cseq <CSeq>: <101>
<INVITE>
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG:maxfwd:is_maxfwd_present: value = 16
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: flags=64
Jun 25 08:43:31 sipsrv ser[1929]: check_via_address(200.94.75.6, 200.94.75.6, 0)
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: flags=33554432
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: add_param: tag=7a83401cfe54b69o0
Jun 25 08:43:31 sipsrv ser[1929]: end of header reached, state=29
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: flags=256
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: get_hdr_body : content_length=316
Jun 25 08:43:31 sipsrv ser[1929]: found end of header
Jun 25 08:43:31 sipsrv ser[1929]: find_first_route: No Route headers found
Jun 25 08:43:31 sipsrv ser[1929]: loose_route: There is no Route HF
Jun 25 08:43:31 sipsrv ser[1929]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:31 sipsrv ser[1929]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:31 sipsrv ser[1929]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:31 sipsrv ser[1929]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: flags=64
Jun 25 08:43:31 sipsrv ser[1929]: check_via_address(200.94.75.6, 200.94.75.6, 0)
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: flags=33554432
Jun 25 08:43:31 sipsrv ser[1929]: lookup(): '018183324166' Not found in usrloc
Jun 25 08:43:31 sipsrv ser[1929]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:31 sipsrv ser[1929]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:31 sipsrv ser[1929]: lookup(): '018183324166' Not found in usrloc
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: t_newtran: msg id=9 , global msg id=1 , T on
entrance=0xffffffff
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: flags=-1
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: flags=60
Jun 25 08:43:31 sipsrv ser[1929]: t_lookup_request: start searching: hash=21902, isACK=0
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: proceeding to pre-RFC3261 transaction matching
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: t_lookup_request: no transaction found
Jun 25 08:43:31 sipsrv ser[1929]: DBG: trans=0x4057c048, callback type 1, id 0 entered
Jun 25 08:43:31 sipsrv ser[1929]: SER: new INVITE
Jun 25 08:43:31 sipsrv ser[1929]: parse_headers: flags=-1
Jun 25 08:43:31 sipsrv ser[1929]: check_via_address(200.94.75.6, 200.94.75.6, 0)
Jun 25 08:43:31 sipsrv ser[1929]: WARNING:vqm_resize: resize(0) called
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: reply sent out. buf=0x810fe78: SIP/2.0 1...,
shmem=0x4057bcd8: SIP/2.0 1
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: _reply_light: finished
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: mk_proxy: doing DNS lookup...
Jun 25 08:43:31 sipsrv ser[1929]: check_via_address(200.94.75.6, 200.94.75.6, 0)
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: add_to_tail_of_timer[4]: 0x4057c160
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG: add_to_tail_of_timer[0]: 0x4057c170
Jun 25 08:43:31 sipsrv ser[1929]: SER: new transaction fwd'ed
Jun 25 08:43:31 sipsrv ser[1929]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:31 sipsrv ser[1929]: receive_msg: cleaning up
Jun 25 08:43:31 sipsrv ser[1931]: SIP Reply (status):
Jun 25 08:43:31 sipsrv ser[1931]: version: <SIP/2.0>
Jun 25 08:43:31 sipsrv ser[1931]: status: <100>
Jun 25 08:43:31 sipsrv ser[1931]: reason: <Trying>
Jun 25 08:43:31 sipsrv ser[1931]: parse_headers: flags=1
Jun 25 08:43:31 sipsrv ser[1931]: Found param type 232, <branch> =
<z9hG4bKe855.757a9ce3.0>; state=9
Jun 25 08:43:31 sipsrv ser[1931]: parse_via: next_via
Jun 25 08:43:31 sipsrv ser[1931]: end of header reached, state=5
Jun 25 08:43:31 sipsrv ser[1931]: parse_headers: Via found, flags=1
Jun 25 08:43:31 sipsrv ser[1931]: parse_headers: this is the first via
Jun 25 08:43:31 sipsrv ser[1931]: After parse_msg...
Jun 25 08:43:31 sipsrv ser[1931]: forward_reply: found module tm, passing reply to it
Jun 25 08:43:31 sipsrv ser[1931]: DEBUG: t_check: msg id=12 global id=2 T start=(nil)
Jun 25 08:43:31 sipsrv ser[1931]: parse_headers: flags=17
Jun 25 08:43:31 sipsrv ser[1931]: DEBUG: add_param: tag=2BBC1008-1340
Jun 25 08:43:31 sipsrv ser[1931]: end of header reached, state=29
Jun 25 08:43:31 sipsrv ser[1931]: DEBUG: get_hdr_field: <To> [60];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:31 sipsrv ser[1931]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>]
Jun 25 08:43:31 sipsrv ser[1931]: get_hdr_field: cseq <CSeq>: <101>
<INVITE>
Jun 25 08:43:31 sipsrv ser[1931]: parse_headers: flags=4
Jun 25 08:43:31 sipsrv ser[1931]: DEBUG: t_reply_matching: hash 21902 label 1053402967
branch 0
Jun 25 08:43:31 sipsrv ser[1931]: DEBUG: t_reply_matching: reply matched (T=0x4057c048)!
Jun 25 08:43:31 sipsrv ser[1931]: DEBUG: t_check: msg id=12 global id=12 T end=0x4057c048
Jun 25 08:43:31 sipsrv ser[1931]: DEBUG: reply_received: org. status uas=100, uac[0]=0
local=0 is_invite=1)
Jun 25 08:43:31 sipsrv ser[1931]: ->>>>>>>>> T_code=100,
new_code=100
Jun 25 08:43:31 sipsrv ser[1931]: DEBUG: relay_reply: branch=0, save=0, relay=-1
Jun 25 08:43:31 sipsrv ser[1931]: DEBUG: add_to_tail_of_timer[1]: 0x4057c170
Jun 25 08:43:31 sipsrv ser[1931]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:31 sipsrv ser[1931]: receive_msg: cleaning up
Jun 25 08:43:32 sipsrv ser[1943]: DEBUG: timer routine:4,tl=0x4057c160 next=(nil)
Jun 25 08:43:36 sipsrv ser[1930]: SIP Reply (status):
Jun 25 08:43:36 sipsrv ser[1930]: version: <SIP/2.0>
Jun 25 08:43:36 sipsrv ser[1930]: status: <183>
Jun 25 08:43:36 sipsrv ser[1930]: reason: <Session Progress>
Jun 25 08:43:36 sipsrv ser[1930]: parse_headers: flags=1
Jun 25 08:43:36 sipsrv ser[1930]: Found param type 232, <branch> =
<z9hG4bKe855.757a9ce3.0>; state=9
Jun 25 08:43:36 sipsrv ser[1930]: parse_via: next_via
Jun 25 08:43:36 sipsrv ser[1930]: end of header reached, state=5
Jun 25 08:43:36 sipsrv ser[1930]: parse_headers: Via found, flags=1
Jun 25 08:43:36 sipsrv ser[1930]: parse_headers: this is the first via
Jun 25 08:43:36 sipsrv ser[1930]: After parse_msg...
Jun 25 08:43:36 sipsrv ser[1930]: forward_reply: found module tm, passing reply to it
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG: t_check: msg id=6 global id=2 T start=0xffffffff
Jun 25 08:43:36 sipsrv ser[1930]: parse_headers: flags=17
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG: add_param: tag=2BBC1008-1340
Jun 25 08:43:36 sipsrv ser[1930]: end of header reached, state=29
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG: get_hdr_field: <To> [60];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>]
Jun 25 08:43:36 sipsrv ser[1930]: get_hdr_field: cseq <CSeq>: <101>
<INVITE>
Jun 25 08:43:36 sipsrv ser[1930]: parse_headers: flags=4
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG: t_reply_matching: hash 21902 label 1053402967
branch 0
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG: t_reply_matching: reply matched (T=0x4057c048)!
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG: t_check: msg id=6 global id=6 T end=0x4057c048
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG: reply_received: org. status uas=100, uac[0]=100
local=0 is_invite=1)
Jun 25 08:43:36 sipsrv ser[1930]: ->>>>>>>>> T_code=100,
new_code=183
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG: relay_reply: branch=0, save=0, relay=0
Jun 25 08:43:36 sipsrv ser[1930]: old size: 752, new size: 698
Jun 25 08:43:36 sipsrv ser[1930]: build_res_from_sip_res: copied size: orig:89, new: 35,
rest: 663 msg= SIP/2.0 183 Session Progress^M Via: SIP/2.0/UDP 200.94.75.6:5065^M From:
8183651723 <sip:8183651723@sipsrv.conecta-te.com>;tag=7a83401cfe54b69o0^M To:
<sip:018183324166@sipsrv.conecta-te.com>;tag=2BBC1008-1340^M Date: Sat, 25 Jun 2005
13:43:56 GMT^M Call-ID: 5c2d7341271e8b55e0cb066402224168(a)200.94.75.6^M Server:
Cisco-SIPGateway/IOS-12.x^M CSeq: 101 INVITE^M Allow-Events: telephone-event^M
Content-Type: application/sdp^M Content-Disposition: session;handling=required^M
Content-Length: 212^M ^M v=0^M o=CiscoSystemsSIP-GW-UserAgent 375 1794 IN IP4
200.94.75.1^M s=SIP Call^M c=IN IP4 200.94.27.30^M t=0 0^M m=audio 16960 RTP/AVP 18^M c=IN
IP4 200.94.27.30^M a=rtpmap:18 G729/8000^M a=fmtp:18 annexb=no^M a=ptime:20^M
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG: reply relayed. buf=0x810f708: SIP/2.0 1...,
shmem=0x4057bcd8: SIP/2.0 1
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG: add_to_tail_of_timer[1]: 0x4057c170
Jun 25 08:43:36 sipsrv ser[1930]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:36 sipsrv ser[1930]: receive_msg: cleaning up
Jun 25 08:43:41 sipsrv ser[1935]: SIP Reply (status):
Jun 25 08:43:41 sipsrv ser[1935]: version: <SIP/2.0>
Jun 25 08:43:41 sipsrv ser[1935]: status: <200>
Jun 25 08:43:41 sipsrv ser[1935]: reason: <OK>
Jun 25 08:43:41 sipsrv ser[1935]: parse_headers: flags=1
Jun 25 08:43:41 sipsrv ser[1935]: Found param type 232, <branch> =
<z9hG4bKe855.757a9ce3.0>; state=9
Jun 25 08:43:41 sipsrv ser[1935]: parse_via: next_via
Jun 25 08:43:41 sipsrv ser[1935]: end of header reached, state=5
Jun 25 08:43:41 sipsrv ser[1935]: parse_headers: Via found, flags=1
Jun 25 08:43:41 sipsrv ser[1935]: parse_headers: this is the first via
Jun 25 08:43:41 sipsrv ser[1935]: After parse_msg...
Jun 25 08:43:41 sipsrv ser[1935]: forward_reply: found module tm, passing reply to it
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: t_check: msg id=11 global id=0 T start=0xffffffff
Jun 25 08:43:41 sipsrv ser[1935]: parse_headers: flags=17
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: add_param: tag=2BBC1008-1340
Jun 25 08:43:41 sipsrv ser[1935]: end of header reached, state=29
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: get_hdr_field: <To> [60];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>]
Jun 25 08:43:41 sipsrv ser[1935]: get_hdr_field: cseq <CSeq>: <101>
<INVITE>
Jun 25 08:43:41 sipsrv ser[1935]: parse_headers: flags=4
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: t_reply_matching: hash 21902 label 1053402967
branch 0
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: t_reply_matching: reply matched (T=0x4057c048)!
Jun 25 08:43:41 sipsrv ser[1935]: parse_headers: flags=4
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: t_check: msg id=11 global id=11 T end=0x4057c048
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: reply_received: org. status uas=183, uac[0]=183
local=0 is_invite=1)
Jun 25 08:43:41 sipsrv ser[1935]: ->>>>>>>>> T_code=183,
new_code=200
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: relay_reply: branch=0, save=0, relay=0
Jun 25 08:43:41 sipsrv ser[1935]: old size: 886, new size: 832
Jun 25 08:43:41 sipsrv ser[1935]: build_res_from_sip_res: copied size: orig:75, new: 21,
rest: 811 msg= SIP/2.0 200 OK^M Via: SIP/2.0/UDP 200.94.75.6:5065^M From: 8183651723
<sip:8183651723@sipsrv.conecta-te.com>;tag=7a83401cfe54b69o0^M To:
<sip:018183324166@sipsrv.conecta-te.com>;tag=2BBC1008-1340^M Date: Sat, 25 Jun 2005
13:43:56 GMT^M Call-ID: 5c2d7341271e8b55e0cb066402224168(a)200.94.75.6^M Server:
Cisco-SIPGateway/IOS-12.x^M CSeq: 101 INVITE^M Allow: INVITE, OPTIONS, BYE, CANCEL, ACK,
PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO^M Allow-Events: telephone-event^M Contact:
<sip:018183324166@200.94.75.1:5060>^M Record-Route:
<sip:200.94.75.6;ftag=7a83401cfe54b69o0;lr=on>^M Content-Type: application/sdp^M
Content-Length: 212^M ^M v=0^M o=CiscoSystemsSIP-GW-UserAgent 375 1794 IN IP4
200.94.75.1^M s=SIP Call^M c=IN IP4 200.94.27.30^M t=0 0^M m=audio 16960 RTP/AVP 18^M c=IN
IP4 200.94.27.30^M a=rtpmap:18 G729/8000^M a=fmtp:18 annexb=no^M a=ptime:20^M
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: update_totag_set: new totag
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: add_to_tail_of_timer[2]: 0x4057c090
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: reply relayed. buf=0x8110388: SIP/2.0 2...,
shmem=0x4057bcd8: SIP/2.0 2
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Jun 25 08:43:41 sipsrv ser[1935]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:41 sipsrv ser[1935]: receive_msg: cleaning up
Jun 25 08:43:41 sipsrv ser[1924]: SIP Request:
Jun 25 08:43:41 sipsrv ser[1924]: method: <ACK>
Jun 25 08:43:41 sipsrv ser[1924]: uri: <sip:018183324166@200.94.75.6:5060>
Jun 25 08:43:41 sipsrv ser[1924]: version: <SIP/2.0>
Jun 25 08:43:41 sipsrv ser[1924]: parse_headers: flags=1
Jun 25 08:43:41 sipsrv ser[1924]: Found param type 232, <branch> =
<z9hG4bK-76d2bc25>; state=16
Jun 25 08:43:41 sipsrv ser[1924]: end of header reached, state=5
Jun 25 08:43:41 sipsrv ser[1924]: parse_headers: Via found, flags=1
Jun 25 08:43:41 sipsrv ser[1924]: parse_headers: this is the first via
Jun 25 08:43:41 sipsrv ser[1924]: After parse_msg...
Jun 25 08:43:41 sipsrv ser[1924]: preparing to run routing scripts...
Jun 25 08:43:41 sipsrv ser[1924]: DEBUG : sl_filter_ACK: to late to be a local ACK!
Jun 25 08:43:41 sipsrv ser[1924]: parse_headers: flags=128
Jun 25 08:43:41 sipsrv ser[1924]: DEBUG: add_param: tag=2cbe59e2
Jun 25 08:43:41 sipsrv ser[1924]: end of header reached, state=29
Jun 25 08:43:41 sipsrv ser[1924]: DEBUG: get_hdr_field: <To> [55];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:41 sipsrv ser[1924]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>]
Jun 25 08:43:41 sipsrv ser[1924]: get_hdr_field: cseq <CSeq>: <101>
<ACK>
Jun 25 08:43:41 sipsrv ser[1924]: DEBUG:maxfwd:is_maxfwd_present: value = 70
Jun 25 08:43:41 sipsrv ser[1924]: DBG:maxfwd:process_maxfwd_header: value 70 decreased to
16
Jun 25 08:43:41 sipsrv ser[1924]: DEBUG: add_param: tag=7a83401cfe54b69o0
Jun 25 08:43:41 sipsrv ser[1924]: end of header reached, state=29
Jun 25 08:43:41 sipsrv ser[1924]: parse_headers: flags=256
Jun 25 08:43:41 sipsrv ser[1924]: is_preloaded: No
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if port 5060 matches port 5065
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if port 5060 matches port 5065
Jun 25 08:43:41 sipsrv ser[1924]: parse_headers: flags=256
Jun 25 08:43:41 sipsrv ser[1924]: DEBUG: get_hdr_body : content_length=0
Jun 25 08:43:41 sipsrv ser[1924]: found end of header
Jun 25 08:43:41 sipsrv ser[1924]: find_next_route: No next Route HF found
Jun 25 08:43:41 sipsrv ser[1924]: after_strict: No next URI found
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:41 sipsrv ser[1924]: lookup(): '018183324166' Not found in usrloc
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:41 sipsrv ser[1924]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:41 sipsrv ser[1924]: PASE POR AQUI POR QUE NO SOY CANCEL, INVITE O REGISTER
Jun 25 08:43:41 sipsrv ser[1924]: parse_headers: flags=-1
Jun 25 08:43:41 sipsrv ser[1924]: lookup(): '018183324166' Not found in usrloc
Jun 25 08:43:41 sipsrv ser[1924]: LOOKUP LOCATION PARA CUALQUIER COSA
Jun 25 08:43:41 sipsrv ser[1924]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:41 sipsrv ser[1924]: receive_msg: cleaning up
Jun 25 08:43:41 sipsrv ser[1943]: DEBUG: timer routine:1,tl=0x4057c170 next=(nil)
Jun 25 08:43:41 sipsrv ser[1942]: SIP Reply (status):
Jun 25 08:43:41 sipsrv ser[1942]: version: <SIP/2.0>
Jun 25 08:43:41 sipsrv ser[1942]: status: <200>
Jun 25 08:43:41 sipsrv ser[1942]: reason: <OK>
Jun 25 08:43:41 sipsrv ser[1942]: parse_headers: flags=1
Jun 25 08:43:41 sipsrv ser[1942]: Found param type 232, <branch> =
<z9hG4bKe855.757a9ce3.0>; state=9
Jun 25 08:43:41 sipsrv ser[1942]: parse_via: next_via
Jun 25 08:43:41 sipsrv ser[1942]: end of header reached, state=5
Jun 25 08:43:41 sipsrv ser[1942]: parse_headers: Via found, flags=1
Jun 25 08:43:41 sipsrv ser[1942]: parse_headers: this is the first via
Jun 25 08:43:41 sipsrv ser[1942]: After parse_msg...
Jun 25 08:43:41 sipsrv ser[1942]: forward_reply: found module tm, passing reply to it
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG: t_check: msg id=14 global id=2 T start=0xffffffff
Jun 25 08:43:41 sipsrv ser[1942]: parse_headers: flags=17
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG: add_param: tag=2BBC1008-1340
Jun 25 08:43:41 sipsrv ser[1942]: end of header reached, state=29
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG: get_hdr_field: <To> [60];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>]
Jun 25 08:43:41 sipsrv ser[1942]: get_hdr_field: cseq <CSeq>: <101>
<INVITE>
Jun 25 08:43:41 sipsrv ser[1942]: parse_headers: flags=4
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG: t_reply_matching: hash 21902 label 1053402967
branch 0
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG: t_reply_matching: reply matched (T=0x4057c048)!
Jun 25 08:43:41 sipsrv ser[1942]: parse_headers: flags=4
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG: t_check: msg id=14 global id=14 T end=0x4057c048
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG: reply_received: org. status uas=200, uac[0]=200
local=0 is_invite=1)
Jun 25 08:43:41 sipsrv ser[1942]: ->>>>>>>>> T_code=200,
new_code=200
Jun 25 08:43:41 sipsrv ser[1942]: DBG: t_should_relay_response: 200 INV after final sent
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG: relay_reply: branch=0, save=0, relay=0
Jun 25 08:43:41 sipsrv ser[1942]: old size: 886, new size: 832
Jun 25 08:43:41 sipsrv ser[1942]: build_res_from_sip_res: copied size: orig:75, new: 21,
rest: 811 msg= SIP/2.0 200 OK^M Via: SIP/2.0/UDP 200.94.75.6:5065^M From: 8183651723
<sip:8183651723@sipsrv.conecta-te.com>;tag=7a83401cfe54b69o0^M To:
<sip:018183324166@sipsrv.conecta-te.com>;tag=2BBC1008-1340^M Date: Sat, 25 Jun 2005
13:43:56 GMT^M Call-ID: 5c2d7341271e8b55e0cb066402224168(a)200.94.75.6^M Server:
Cisco-SIPGateway/IOS-12.x^M CSeq: 101 INVITE^M Allow: INVITE, OPTIONS, BYE, CANCEL, ACK,
PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO^M Allow-Events: telephone-event^M Contact:
<sip:018183324166@200.94.75.1:5060>^M Record-Route:
<sip:200.94.75.6;ftag=7a83401cfe54b69o0;lr=on>^M Content-Type: application/sdp^M
Content-Length: 212^M ^M v=0^M o=CiscoSystemsSIP-GW-UserAgent 375 1794 IN IP4
200.94.75.1^M s=SIP Call^M c=IN IP4 200.94.27.30^M t=0 0^M m=audio 16960 RTP/AVP 18^M c=IN
IP4 200.94.27.30^M a=rtpmap:18 G729/8000^M a=fmtp:18 annexb=no^M a=ptime:20^M
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG: update_totag_set: totag retransmission
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG: reply relayed. buf=0x8110218: SIP/2.0 2...,
shmem=0x4057bcd8: SIP/2.0 2
Jun 25 08:43:41 sipsrv ser[1942]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:41 sipsrv ser[1942]: receive_msg: cleaning up
Jun 25 08:43:42 sipsrv ser[1931]: SIP Reply (status):
Jun 25 08:43:42 sipsrv ser[1931]: version: <SIP/2.0>
Jun 25 08:43:42 sipsrv ser[1931]: status: <200>
Jun 25 08:43:42 sipsrv ser[1931]: reason: <OK>
Jun 25 08:43:42 sipsrv ser[1931]: parse_headers: flags=1
Jun 25 08:43:42 sipsrv ser[1931]: Found param type 232, <branch> =
<z9hG4bKe855.757a9ce3.0>; state=9
Jun 25 08:43:42 sipsrv ser[1931]: parse_via: next_via
Jun 25 08:43:42 sipsrv ser[1931]: end of header reached, state=5
Jun 25 08:43:42 sipsrv ser[1931]: parse_headers: Via found, flags=1
Jun 25 08:43:42 sipsrv ser[1931]: parse_headers: this is the first via
Jun 25 08:43:42 sipsrv ser[1931]: After parse_msg...
Jun 25 08:43:42 sipsrv ser[1931]: forward_reply: found module tm, passing reply to it
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG: t_check: msg id=13 global id=12 T
start=0xffffffff
Jun 25 08:43:42 sipsrv ser[1931]: parse_headers: flags=17
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG: add_param: tag=2BBC1008-1340
Jun 25 08:43:42 sipsrv ser[1931]: end of header reached, state=29
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG: get_hdr_field: <To> [60];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>]
Jun 25 08:43:42 sipsrv ser[1931]: get_hdr_field: cseq <CSeq>: <101>
<INVITE>
Jun 25 08:43:42 sipsrv ser[1931]: parse_headers: flags=4
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG: t_reply_matching: hash 21902 label 1053402967
branch 0
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG: t_reply_matching: reply matched (T=0x4057c048)!
Jun 25 08:43:42 sipsrv ser[1931]: parse_headers: flags=4
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG: t_check: msg id=13 global id=13 T end=0x4057c048
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG: reply_received: org. status uas=200, uac[0]=200
local=0 is_invite=1)
Jun 25 08:43:42 sipsrv ser[1931]: ->>>>>>>>> T_code=200,
new_code=200
Jun 25 08:43:42 sipsrv ser[1931]: DBG: t_should_relay_response: 200 INV after final sent
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG: relay_reply: branch=0, save=0, relay=0
Jun 25 08:43:42 sipsrv ser[1931]: old size: 886, new size: 832
Jun 25 08:43:42 sipsrv ser[1931]: build_res_from_sip_res: copied size: orig:75, new: 21,
rest: 811 msg= SIP/2.0 200 OK^M Via: SIP/2.0/UDP 200.94.75.6:5065^M From: 8183651723
<sip:8183651723@sipsrv.conecta-te.com>;tag=7a83401cfe54b69o0^M To:
<sip:018183324166@sipsrv.conecta-te.com>;tag=2BBC1008-1340^M Date: Sat, 25 Jun 2005
13:43:56 GMT^M Call-ID: 5c2d7341271e8b55e0cb066402224168(a)200.94.75.6^M Server:
Cisco-SIPGateway/IOS-12.x^M CSeq: 101 INVITE^M Allow: INVITE, OPTIONS, BYE, CANCEL, ACK,
PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO^M Allow-Events: telephone-event^M Contact:
<sip:018183324166@200.94.75.1:5060>^M Record-Route:
<sip:200.94.75.6;ftag=7a83401cfe54b69o0;lr=on>^M Content-Type: application/sdp^M
Content-Length: 212^M ^M v=0^M o=CiscoSystemsSIP-GW-UserAgent 375 1794 IN IP4
200.94.75.1^M s=SIP Call^M c=IN IP4 200.94.27.30^M t=0 0^M m=audio 16960 RTP/AVP 18^M c=IN
IP4 200.94.27.30^M a=rtpmap:18 G729/8000^M a=fmtp:18 annexb=no^M a=ptime:20^M
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG: update_totag_set: totag retransmission
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG: reply relayed. buf=0x81102a8: SIP/2.0 2...,
shmem=0x4057bcd8: SIP/2.0 2
Jun 25 08:43:42 sipsrv ser[1931]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:42 sipsrv ser[1931]: receive_msg: cleaning up
Jun 25 08:43:50 sipsrv ser[1936]: SIP Request:
Jun 25 08:43:50 sipsrv ser[1936]: method: <BYE>
Jun 25 08:43:50 sipsrv ser[1936]: uri: <sip:018183324166@200.94.75.6:5060>
Jun 25 08:43:50 sipsrv ser[1936]: version: <SIP/2.0>
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: flags=1
Jun 25 08:43:50 sipsrv ser[1936]: Found param type 232, <branch> =
<z9hG4bK-c79dc8ef>; state=16
Jun 25 08:43:50 sipsrv ser[1936]: end of header reached, state=5
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: Via found, flags=1
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: this is the first via
Jun 25 08:43:50 sipsrv ser[1936]: After parse_msg...
Jun 25 08:43:50 sipsrv ser[1936]: preparing to run routing scripts...
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: flags=128
Jun 25 08:43:50 sipsrv ser[1936]: DEBUG: add_param: tag=2cbe59e2
Jun 25 08:43:50 sipsrv ser[1936]: end of header reached, state=29
Jun 25 08:43:50 sipsrv ser[1936]: DEBUG: get_hdr_field: <To> [55];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:50 sipsrv ser[1936]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>]
Jun 25 08:43:50 sipsrv ser[1936]: get_hdr_field: cseq <CSeq>: <102>
<BYE>
Jun 25 08:43:50 sipsrv ser[1936]: DEBUG:maxfwd:is_maxfwd_present: value = 70
Jun 25 08:43:50 sipsrv ser[1936]: DBG:maxfwd:process_maxfwd_header: value 70 decreased to
16
Jun 25 08:43:50 sipsrv ser[1936]: DEBUG: add_param: tag=7a83401cfe54b69o0
Jun 25 08:43:50 sipsrv ser[1936]: end of header reached, state=29
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: flags=-1
Jun 25 08:43:50 sipsrv ser[1936]: DEBUG: get_hdr_body : content_length=0
Jun 25 08:43:50 sipsrv ser[1936]: found end of header
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: flags=256
Jun 25 08:43:50 sipsrv ser[1936]: is_preloaded: No
Jun 25 08:43:50 sipsrv ser[1936]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:50 sipsrv ser[1936]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:50 sipsrv ser[1936]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:50 sipsrv ser[1936]: grep_sock_info - checking if port 5060 matches port 5065
Jun 25 08:43:50 sipsrv ser[1936]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:50 sipsrv ser[1936]: grep_sock_info - checking if port 5060 matches port 5065
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: flags=256
Jun 25 08:43:50 sipsrv ser[1936]: found end of header
Jun 25 08:43:50 sipsrv ser[1936]: find_next_route: No next Route HF found
Jun 25 08:43:50 sipsrv ser[1936]: after_strict: No next URI found
Jun 25 08:43:50 sipsrv ser[1936]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:50 sipsrv ser[1936]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:50 sipsrv ser[1936]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:50 sipsrv ser[1936]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:50 sipsrv ser[1936]: Hey this request is NOT from B2BUA
Jun 25 08:43:50 sipsrv ser[1936]: FORWARDING TO B2BUA
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: flags=-1
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: flags=64
Jun 25 08:43:50 sipsrv ser[1936]: check_via_address(200.67.33.247, 172.31.253.127, 0)
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: flags=33554432
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: flags=64
Jun 25 08:43:50 sipsrv ser[1936]: parse_headers: flags=-1
Jun 25 08:43:50 sipsrv ser[1936]: check_via_address(200.67.33.247, 172.31.253.127, 0)
Jun 25 08:43:50 sipsrv ser[1936]: Sending: BYE sip:018183324166@200.94.75.6:5060 SIP/2.0^M
Record-Route: <sip:200.94.75.6;ftag=7a83401cfe54b69o0;lr=on>^M Via: SIP/2.0/UDP
200.94.75.6;branch=0^M Via: SIP/2.0/UDP
172.31.253.127:5060;rport=60425;received=200.67.33.247;branch=z9hG4bK-c79dc8ef^M From:
8183651723 <sip:8183651723@sipsrv.conecta-te.com>;tag=7a83401cfe54b69o0^M To:
<sip:018183324166@sipsrv.conecta-te.com>;tag=2cbe59e2^M Call-ID:
b5fcf1e1-baf4a709(a)172.31.253.127^M CSeq: 102 BYE^M Max-Forwards: 16^M User-Agent:
Linksys/PAP2-2.0.12(LS)^M Content-Length: 0^M P-hint: finishing call^M P-hint: PASANDO POR
EL B2BUA^M P-hint: APLICO NAT AL B2BUA^M ^M .
Jun 25 08:43:50 sipsrv ser[1936]: orig. len=425, new_len=600, proto=1
Jun 25 08:43:50 sipsrv ser[1936]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:50 sipsrv ser[1936]: receive_msg: cleaning up
Jun 25 08:43:50 sipsrv ser[1924]: SIP Reply (status):
Jun 25 08:43:50 sipsrv ser[1924]: version: <SIP/2.0>
Jun 25 08:43:50 sipsrv ser[1924]: status: <200>
Jun 25 08:43:50 sipsrv ser[1924]: reason: <OK>
Jun 25 08:43:50 sipsrv ser[1924]: parse_headers: flags=1
Jun 25 08:43:50 sipsrv ser[1924]: Found param type 232, <branch> = <0>;
state=16
Jun 25 08:43:50 sipsrv ser[1924]: end of header reached, state=5
Jun 25 08:43:50 sipsrv ser[1924]: parse_headers: Via found, flags=1
Jun 25 08:43:50 sipsrv ser[1924]: parse_headers: this is the first via
Jun 25 08:43:50 sipsrv ser[1924]: After parse_msg...
Jun 25 08:43:50 sipsrv ser[1924]: forward_reply: found module tm, passing reply to it
Jun 25 08:43:50 sipsrv ser[1924]: DEBUG: t_check: msg id=8 global id=2 T start=0xffffffff
Jun 25 08:43:50 sipsrv ser[1924]: parse_headers: flags=17
Jun 25 08:43:50 sipsrv ser[1924]: Found param type 235, <rport> = <60425>;
state=6
Jun 25 08:43:50 sipsrv ser[1924]: Found param type 234, <received> =
<200.67.33.247>; state=6
Jun 25 08:43:50 sipsrv ser[1924]: Found param type 232, <branch> =
<z9hG4bK-c79dc8ef>; state=16
Jun 25 08:43:50 sipsrv ser[1924]: end of header reached, state=5
Jun 25 08:43:50 sipsrv ser[1924]: parse_headers: Via found, flags=17
Jun 25 08:43:50 sipsrv ser[1924]: parse_headers: this is the second via
Jun 25 08:43:50 sipsrv ser[1924]: DEBUG: add_param: tag=2cbe59e2
Jun 25 08:43:50 sipsrv ser[1924]: end of header reached, state=29
Jun 25 08:43:50 sipsrv ser[1924]: DEBUG: get_hdr_field: <To> [55];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:50 sipsrv ser[1924]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>]
Jun 25 08:43:50 sipsrv ser[1924]: get_hdr_field: cseq <CSeq>: <102>
<BYE>
Jun 25 08:43:50 sipsrv ser[1924]: DEBUG: t_reply_matching: failure to match a transaction
Jun 25 08:43:50 sipsrv ser[1924]: DEBUG: t_check: msg id=8 global id=8 T end=(nil)
Jun 25 08:43:50 sipsrv ser[1924]: parse_headers: flags=2
Jun 25 08:43:50 sipsrv ser[1924]: old size: 436, new size: 392
Jun 25 08:43:50 sipsrv ser[1924]: build_res_from_sip_res: copied size: orig:60, new: 16,
rest: 376 msg= SIP/2.0 200 OK^M Via: SIP/2.0/UDP
172.31.253.127:5060;rport=60425;received=200.67.33.247;branch=z9hG4bK-c79dc8ef^M To:
<sip:018183324166@sipsrv.conecta-te.com>;tag=2cbe59e2^M From: 8183651723
<sip:8183651723@sipsrv.conecta-te.com>;tag=7a83401cfe54b69o0^M Call-ID:
b5fcf1e1-baf4a709(a)172.31.253.127^M CSeq: 102 BYE^M Record-Route:
<sip:200.94.75.6;ftag=7a83401cfe54b69o0;lr=on>^M Content-Length: 0^M ^M
Jun 25 08:43:50 sipsrv ser[1924]: update_sock_struct_from_via: using 'rport'
Jun 25 08:43:50 sipsrv ser[1924]: update_sock_struct_from_via: using 'received'
Jun 25 08:43:50 sipsrv ser[1924]: update_sock_struct_from_via: trying SRV lookup
Jun 25 08:43:50 sipsrv ser[1924]: reply forwarded to 172.31.253.127:5060
Jun 25 08:43:50 sipsrv ser[1924]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:50 sipsrv ser[1924]: receive_msg: cleaning up
Jun 25 08:43:50 sipsrv ser[1942]: SIP Request:
Jun 25 08:43:50 sipsrv ser[1942]: method: <BYE>
Jun 25 08:43:50 sipsrv ser[1942]: uri: <sip:200.94.75.6;lr=on>
Jun 25 08:43:50 sipsrv ser[1942]: version: <SIP/2.0>
Jun 25 08:43:50 sipsrv ser[1942]: parse_headers: flags=1
Jun 25 08:43:50 sipsrv ser[1942]: end of header reached, state=5
Jun 25 08:43:50 sipsrv ser[1942]: parse_headers: Via found, flags=1
Jun 25 08:43:50 sipsrv ser[1942]: parse_headers: this is the first via
Jun 25 08:43:50 sipsrv ser[1942]: After parse_msg...
Jun 25 08:43:50 sipsrv ser[1942]: preparing to run routing scripts...
Jun 25 08:43:50 sipsrv ser[1942]: parse_headers: flags=128
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: add_param: tag=2BBC1008-1340
Jun 25 08:43:50 sipsrv ser[1942]: end of header reached, state=29
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: get_hdr_field: <To> [60];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>]
Jun 25 08:43:50 sipsrv ser[1942]: get_hdr_field: cseq <CSeq>: <102>
<BYE>
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG:maxfwd:is_maxfwd_present: value = 70
Jun 25 08:43:50 sipsrv ser[1942]: DBG:maxfwd:process_maxfwd_header: value 70 decreased to
16
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: add_param: tag=7a83401cfe54b69o0
Jun 25 08:43:50 sipsrv ser[1942]: end of header reached, state=29
Jun 25 08:43:50 sipsrv ser[1942]: parse_headers: flags=-1
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: get_hdr_body : content_length=0
Jun 25 08:43:50 sipsrv ser[1942]: found end of header
Jun 25 08:43:50 sipsrv ser[1942]: parse_headers: flags=256
Jun 25 08:43:50 sipsrv ser[1942]: is_preloaded: No
Jun 25 08:43:50 sipsrv ser[1942]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.6] == [200.94.75.6]
Jun 25 08:43:50 sipsrv ser[1942]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:50 sipsrv ser[1942]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.1] == [200.94.75.6]
Jun 25 08:43:50 sipsrv ser[1942]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:50 sipsrv ser[1942]: grep_sock_info - checking if host==us: 11==11 &&
[200.94.75.1] == [200.94.75.6]
Jun 25 08:43:50 sipsrv ser[1942]: grep_sock_info - checking if port 5060 matches port 5060
Jun 25 08:43:50 sipsrv ser[1942]: check_self: host != me
Jun 25 08:43:50 sipsrv ser[1942]: after_strict: Next hop:
'sip:018183324166@200.94.75.1:5060' is strict router
Jun 25 08:43:50 sipsrv ser[1942]: TOI: rewrite_uri: Rewriting Request-URI with
'sip:018183324166@200.94.75.1:5060'
Jun 25 08:43:50 sipsrv ser[1942]: parse_headers: flags=-1
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: has_totag: totag found
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: t_newtran: msg id=15 , global msg id=14 , T on
entrance=0xffffffff
Jun 25 08:43:50 sipsrv ser[1942]: parse_headers: flags=-1
Jun 25 08:43:50 sipsrv ser[1942]: parse_headers: flags=60
Jun 25 08:43:50 sipsrv ser[1942]: t_lookup_request: start searching: hash=21899, isACK=0
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: proceeding to pre-RFC3261 transaction matching
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: t_lookup_request: no transaction found
Jun 25 08:43:50 sipsrv ser[1942]: DBG: trans=0x40579e98, callback type 1, id 0 entered
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: mk_proxy: doing DNS lookup...
Jun 25 08:43:50 sipsrv ser[1942]: check_via_address(200.94.75.6, 200.94.75.6, 0)
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: add_to_tail_of_timer[4]: 0x40579fb0
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG: add_to_tail_of_timer[0]: 0x40579fc0
Jun 25 08:43:50 sipsrv ser[1942]: SER: new transaction fwd'ed
Jun 25 08:43:50 sipsrv ser[1942]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:50 sipsrv ser[1942]: receive_msg: cleaning up
Jun 25 08:43:50 sipsrv ser[1931]: SIP Reply (status):
Jun 25 08:43:50 sipsrv ser[1931]: version: <SIP/2.0>
Jun 25 08:43:50 sipsrv ser[1931]: status: <481>
Jun 25 08:43:50 sipsrv ser[1931]: reason: <Call Leg/Transaction Does Not Exist>
Jun 25 08:43:50 sipsrv ser[1931]: parse_headers: flags=1
Jun 25 08:43:50 sipsrv ser[1931]: Found param type 232, <branch> =
<z9hG4bKb855.107310d2.0>; state=9
Jun 25 08:43:50 sipsrv ser[1931]: parse_via: next_via
Jun 25 08:43:50 sipsrv ser[1931]: end of header reached, state=5
Jun 25 08:43:50 sipsrv ser[1931]: parse_headers: Via found, flags=1
Jun 25 08:43:50 sipsrv ser[1931]: parse_headers: this is the first via
Jun 25 08:43:50 sipsrv ser[1931]: After parse_msg...
Jun 25 08:43:50 sipsrv ser[1931]: forward_reply: found module tm, passing reply to it
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: t_check: msg id=14 global id=13 T
start=0xffffffff
Jun 25 08:43:50 sipsrv ser[1931]: parse_headers: flags=17
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: add_param: tag=2BBC1008-1340
Jun 25 08:43:50 sipsrv ser[1931]: end of header reached, state=29
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: get_hdr_field: <To> [60];
uri=[sip:018183324166@sipsrv.conecta-te.com]
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: to body
[<sip:018183324166@sipsrv.conecta-te.com>]
Jun 25 08:43:50 sipsrv ser[1931]: get_hdr_field: cseq <CSeq>: <102>
<BYE>
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: t_reply_matching: hash 21899 label 755054337
branch 0
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: t_reply_matching: reply matched (T=0x40579e98)!
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: t_check: msg id=14 global id=14 T end=0x40579e98
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: reply_received: org. status uas=0, uac[0]=0
local=0 is_invite=0)
Jun 25 08:43:50 sipsrv ser[1931]: ->>>>>>>>> T_code=0,
new_code=481
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: relay_reply: branch=0, save=0, relay=0
Jun 25 08:43:50 sipsrv ser[1931]: old size: 372, new size: 318
Jun 25 08:43:50 sipsrv ser[1931]: build_res_from_sip_res: copied size: orig:108, new: 54,
rest: 264 msg= SIP/2.0 481 Call Leg/Transaction Does Not Exist^M Via: SIP/2.0/UDP
200.94.75.6:5065^M From: 8183651723
<sip:8183651723@sipsrv.conecta-te.com>;tag=7a83401cfe54b69o0^M To:
<sip:018183324166@sipsrv.conecta-te.com>;tag=2BBC1008-1340^M Call-ID:
5c2d7341271e8b55e0cb066402224168(a)200.94.75.6^M CSeq: 102 BYE^M Content-Length: 0^M ^M
Jun 25 08:43:50 sipsrv ser[1931]: WARNING:vqm_resize: resize(0) called
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: add_to_tail_of_timer[2]: 0x40579ee0
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: reply relayed. buf=0x810f708: SIP/2.0 4...,
shmem=0x4057d8d8: SIP/2.0 4
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Jun 25 08:43:50 sipsrv ser[1931]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 25 08:43:50 sipsrv ser[1931]: receive_msg: cleaning up
Jun 25 08:43:51 sipsrv ser[1943]: DEBUG: timer routine:0,tl=0x40579fc0 next=(nil)
Jun 25 08:43:51 sipsrv ser[1943]: DEBUG: timer routine:4,tl=0x40579fb0 next=(nil)
Jun 25 08:44:00 sipsrv ser[1943]: DEBUG: timer routine:2,tl=0x4057c090 next=(nil)
Jun 25 08:44:00 sipsrv ser[1943]: DEBUG: wait_handler : removing 0x4057c048 from table
Jun 25 08:44:00 sipsrv ser[1943]: DEBUG: delete transaction 0x4057c048
Jun 25 08:44:00 sipsrv ser[1943]: DEBUG: wait_handler : done
Jun 25 08:44:10 sipsrv ser[1943]: DEBUG: timer routine:2,tl=0x40579ee0 next=(nil)
Jun 25 08:44:10 sipsrv ser[1943]: DEBUG: wait_handler : removing 0x40579e98 from table
Jun 25 08:44:10 sipsrv ser[1943]: DEBUG: delete transaction 0x40579e98
Jun 25 08:44:10 sipsrv ser[1943]: DEBUG: wait_handler : done
#
# $Id: ser.cfg,v 1.25.2.1 2005/02/18 14:30:44 andrei Exp $
#
# simple quick-start config script
#
# ----------- global configuration parameters ------------------------
debug=5 # debug level (cmd line: -ddddd)
fork=yes
log_stderror=no
/* Uncomment these lines to enter debugging mode
fork=no
log_stderror=yes # (cmd line: -E)
debug=7
*/
check_via=no # (cmd. line: -v)
dns=no # (cmd. line: -r)
rev_dns=no # (cmd. line: -R)
listen=200.94.75.6
port=5060
alias=200.94.75.6
alias=sipsrv.conecta-te.com
fifo_mode=0666
fifo="/tmp/ser_fifo"
fifo_db_url="mysql://ser:heslo@localhost/ser"
# ------------------ module loading ----------------------------------
# Uncomment this if you want to use SQL database
loadmodule "/usr/local/lib/ser/modules/mysql.so"
loadmodule "/usr/local/lib/ser/modules/sl.so"
loadmodule "/usr/local/lib/ser/modules/tm.so"
loadmodule "/usr/local/lib/ser/modules/rr.so"
loadmodule "/usr/local/lib/ser/modules/maxfwd.so"
loadmodule "/usr/local/lib/ser/modules/usrloc.so"
loadmodule "/usr/local/lib/ser/modules/registrar.so"
loadmodule "/usr/local/lib/ser/modules/auth.so"
loadmodule "/usr/local/lib/ser/modules/auth_radius.so"
loadmodule "/usr/local/lib/ser/modules/auth_db.so"
loadmodule "/usr/local/lib/ser/modules/uri.so"
loadmodule "/usr/local/lib/ser/modules/uri_db.so"
loadmodule "/usr/local/lib/ser/modules/uri_radius.so"
loadmodule "/usr/local/lib/ser/modules/group.so"
loadmodule "/usr/local/lib/ser/modules/group_radius.so"
loadmodule "/usr/local/lib/ser/modules/mediaproxy.so"
loadmodule "/usr/local/lib/ser/modules/nathelper.so"
loadmodule "/usr/local/lib/ser/modules/textops.so"
loadmodule "/usr/local/lib/ser/modules/acc.so"
loadmodule "/usr/local/lib/ser/modules/domain.so"
# ----------------- setting module-specific parameters ---------------
# -- usrloc params --
# modparam("usrloc", "db_mode", 0)
# Uncomment this if you want to use SQL database
# for persistent storage and comment the previous line
modparam("usrloc", "db_mode", 2)
modparam("domain", "db_mode", 1)
modparam("usrloc|domain", "db_url",
"mysql://ser:heslo@localhost/ser")
# -- auth params --
# Uncomment if you are using auth module
#modparam("auth_db", "calculate_ha1", yes)
#
# If you set "calculate_ha1" parameter to yes (which true in this config),
# uncomment also the following parameter)
#modparam("auth_db", "password_column", "password")
# -- Radius Configuration --
modparam("auth_radius", "radius_config",
"/usr/local/etc/radiusclient/radiusclient.conf")
modparam("auth_radius", "service_type", 15)
modparam("group_radius", "radius_config",
"/usr/local/etc/radiusclient/radiusclient.conf")
modparam("group_radius", "use_domain", 0)
# -- nathelper params --
modparam("nathelper", "rtpproxy_disable", 1)
modparam("nathelper", "natping_interval", 0)
# -- mediaproxy params --
modparam("mediaproxy", "natping_interval", 30)
modparam("mediaproxy", "mediaproxy_socket",
"/var/run/mediaproxy.sock")
modparam("mediaproxy", "sip_asymmetrics",
"/usr/local/etc/ser/sip-clients")
modparam("mediaproxy", "rtp_asymmetrics",
"/usr/local/etc/ser/rtp-clients")
# -- rr params --
# add value to ;lr param to make some broken UAs happy
modparam("rr", "enable_full_lr", 1)
modparam("registrar", "nat_flag", 6)
# ------------------------- request routing logic -------------------
# main routing logic
route{
#----------------------------------------------
# initial sanity checks -- messages with
# max_forwards==0, or excessively long requests
#----------------------------------------------
if (!mf_process_maxfwd_header("10")) {
sl_send_reply("483","Too Many Hops");
break;
};
if (msg:len > max_len ) {
sl_send_reply("513", "Message too big");
break;
};
#----------------------------------------------------
# we record-route all messages -- to make sure that
# subsequent messages will go through our proxy; that's
# particularly good if upstream and downstream entities
# use different transport protocol
#----------------------------------------------------
if (method=="INVITE" && client_nat_test("3")){
record_route_preset("200.94.75.6:5060;nat=yes");
}else if (!method=="REGISTER"){
record_route();
};
#---------------------------------------------
# we tear down the call before entering to loose route
#---------------------------------------------
if (method=="BYE" || method=="CANCEL") {
end_media_session();
append_hf("P-hint: finishing call\r\n");
};
#-------------------------------------------------
# subsequent messages withing a dialog should take the
# path determined by record-routing
#-------------------------------------------------
if (loose_route()) {
append_hf("P-hint: rr-enforced\r\n");
# The following lines are added due media proxy
if (has_totag() && (method=="INVITE" || method=="ACK")) {
if (client_nat_test("3") || search("^Route:.*;nat=yes")) {
# Mark as NAT'ed
setflag(6);
use_media_proxy();
};
};
# end media session for BYE and CANCEL is done above
# before entering the loose route. no need to call it here
route(1);
break;
};
#----------------------------------------
# processing the most common sip messages
# for all the calls
#----------------------------------------
if (!uri==myself) {
# mark routing logic in request
append_hf("P-hint: outbound\r\n");
route(1);
break;
};
if (uri==myself) {
#---------------------------------
#all the calls from the sip uacs should
#be handled by the b2bua for authorization
#and accounting
#---------------------------------
if (!(src_ip==200.94.75.6 || src_ip==200.94.75.1)and(method=="INVITE" ||
method=="BYE" || method=="CANCEL")) {
log("Hey this request is NOT from B2BUA\n");
log("Forwarding to B2BUA\n");
if (client_nat_test("3")) {
setflag(7);
force_rport();
fix_nated_contact();
};
forward(200.94.75.6,5065);
break;
};
if (method=="CANCEL" || method=="INVITE") {
route(3);
break;
} else if (method=="REGISTER") {
route(2);
break;
};
route(4);
if (!lookup("location")) {
sl_send_reply("404", "User Not Found");
break;
};
};
route(1);
}
route[1] {
#-------------------------------
# Default SIP message handler
# forward to current uri now; use stateful forwarding; that
# works reliably even if we forward from TCP to UDP
#------------------------------
t_on_reply("1");
if (!t_relay()) {
if (method=="INVITE" || method=="ACK") {
end_media_session();
append_hf("P-hint: finishing call no-relay\r\n");
};
sl_reply_error();
};
}
route[2] {
#---------------------------
# "REGISTER" message handler
#---------------------------
sl_send_reply("100", "Trying");
if (!search("^Contact:\ +\*") && client_nat_test("7")) {
setflag(6);
fix_nated_register();
force_rport();
};
if (is_from_local() || uri==myself) {
if (!radius_www_authorize("")) {
www_challenge("", "0");
break;
} else if (!check_to()){
sl_send_reply("403", "Username!=To not allowed");
break;
};
if (!save("location")) {
sl_reply_error();
};
} else {
append_hf("P-hint: outbound alias\r\n");
sl_send_reply("403", "This domain is not served here");
};
}
route[3] {
#--------------------------
#"CANCEL" and "INVITE" message handler
#--------------------------
if (client_nat_test("3")) {
setflag(7);
force_rport();
fix_nated_contact();
};
if (method=="INVITE") {
if (!(is_from_local() || uri==myself || is_uri_host_local())) {
sl_send_reply("403", "Relaying is forbidden");
break;
};
} else if (method=="CANCEL") {
route(1);
break;
};
route(4);
if (!lookup("location")) {
if ((uri=~"sip:01[1-9][0-9]+@.*") || (uri=~"sip:00[1-9][0-9]+@.*"))
{
rewritehost("200.94.75.1");
};
} else {
sl_send_reply("404", "User not found");
break;
};
#-------------------------------------
#RTP Proxy handler
#-------------------------------------
if (isflagset(6) || isflagset(7)) {
use_media_proxy();
append_hf("P-hint: are you nated?\r\n");
};
route(1);
}
route[4] {
#---------------
#we need to check for the alias
#---------------
lookup("aliases");
if (uri!=myself) {
route(1);
break;
};
}
failure_route[1] {
end_media_session();
append_hf("P-hint: finishing call on failure\r\n");
}
onreply_route[1] {
if ((isflagset(6) || isflagset(7)) &&
(status=~"(180)|(183)|(2[0-9][0-9])")) {
if (client_nat_test("1")) {
fix_nated_contact();
};
if (!search("^Content-Length:\ +0")) {
use_media_proxy();
append_hf("P-hint: use nat for call\r\n");
};
};
}