[Users] Multiple aliases -> 404 Not Found

mika.saari at wipsl.com mika.saari at wipsl.com
Mon May 22 12:20:25 CEST 2006


Hi,

  Oh sorry, I propably then clipped too much away from earlier log :(. Now
I have only clipped away the very first startup part and then only added
some headers to the log which shows what I am doing at the moment. It
seems that the Client1 calling to client2 just stops suddenly (404) and
nothing more comes to the log after that.

  In the log is next
    1) Client2 registers
    2) Client1 registers and tries to call a call (unsuccessful)
    3) Client2 calls a call to Client1 (successful)
    4) Server is shutdown

  Thanks very much again,
    -Mika


---- Clip ----
 Client2 Registers
-----------------------
 2(10000) SIP Request:
 2(10000)  method:  <REGISTER>
 2(10000)  uri:     <sip:isp1.test.com>
 2(10000)  version: <SIP/2.0>
 2(10000) parse_headers: flags=2
 2(10000) Found param type 232, <branch> = <z9hG4bK-cx9x59lr39qy>; state=6
 2(10000) Found param type 235, <rport> = <n/a>; state=17
 2(10000) end of header reached, state=5
 2(10000) parse_headers: Via found, flags=2
 2(10000) parse_headers: this is the first via
 2(10000) After parse_msg...
 2(10000) preparing to run routing scripts...
 2(10000) parse_headers: flags=10
 2(10000) DEBUG: add_param: tag=iu6d3hlwqt
 2(10000) DEBUG:parse_to:end of header reached, state=29
 2(10000) parse_headers: flags=8
 2(10000) DEBUG:parse_to:end of header reached, state=9
 2(10000) DEBUG: get_hdr_field: <To> [30]; uri=[sip:client2 at isp1.test.com]
 2(10000) DEBUG: to body [<sip:client2 at isp1.test.com>]
 2(10000) SIP: method [REGISTER] from [sip:client2 at isp1.test.com] to
[sip:client2 at isp1.test.com]
 2(10000) parse_headers: flags=100
 2(10000) get_hdr_field: cseq <CSeq>: <540> <REGISTER>
 2(10000) DEBUG:maxfwd:is_maxfwd_present: value = 70
 2(10000) parse_headers: flags=200
 2(10000) DEBUG: get_hdr_body : content_length=0
 2(10000) found end of header
 2(10000) find_first_route: No Route headers found
 2(10000) loose_route: There is no Route HF
 2(10000) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 2(10000) grep_sock_info - checking if port 5060 matches port 5060
 2(10000) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 2(10000) grep_sock_info - checking if port 5060 matches port 5060
 2(10000) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 2(10000) grep_sock_info - checking if port 5060 matches port 5060
 2(10000) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 2(10000) grep_sock_info - checking if port 5060 matches port 5060
 2(10000) parse_headers: flags=4000
 2(10000) pre_auth(): Credentials with given realm not found
 2(10000) build_auth_hf(): 'WWW-Authenticate: Digest
realm="isp1.test.com", nonce="44718d6bc40cf955718d5a164c1e451f3f6ecf8c"'
 2(10000) parse_headers: flags=ffffffffffffffff
 2(10000) check_via_address(193.65.64.185, 193.65.64.185, 0)
 2(10000) DEBUG:destroy_avp_list: destroying list (nil)
 2(10000) receive_msg: cleaning up
 3(10001) SIP Request:
 3(10001)  method:  <REGISTER>
 3(10001)  uri:     <sip:isp1.test.com>
 3(10001)  version: <SIP/2.0>
 3(10001) parse_headers: flags=2
 3(10001) Found param type 232, <branch> = <z9hG4bK-z04py3oa20zz>; state=6
 3(10001) Found param type 235, <rport> = <n/a>; state=17
 3(10001) end of header reached, state=5
 3(10001) parse_headers: Via found, flags=2
 3(10001) parse_headers: this is the first via
 3(10001) After parse_msg...
 3(10001) preparing to run routing scripts...
 3(10001) parse_headers: flags=10
 3(10001) DEBUG: add_param: tag=opu4ec5rdn
 3(10001) DEBUG:parse_to:end of header reached, state=29
 3(10001) parse_headers: flags=8
 3(10001) DEBUG:parse_to:end of header reached, state=9
 3(10001) DEBUG: get_hdr_field: <To> [30]; uri=[sip:client2 at isp1.test.com]
 3(10001) DEBUG: to body [<sip:client2 at isp1.test.com>]
 3(10001) SIP: method [REGISTER] from [sip:client2 at isp1.test.com] to
[sip:client2 at isp1.test.com]
 3(10001) parse_headers: flags=100
 3(10001) get_hdr_field: cseq <CSeq>: <541> <REGISTER>
 3(10001) DEBUG:maxfwd:is_maxfwd_present: value = 70
 3(10001) parse_headers: flags=200
 3(10001) DEBUG: get_hdr_body : content_length=0
 3(10001) found end of header
 3(10001) find_first_route: No Route headers found
 3(10001) loose_route: There is no Route HF
 3(10001) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) parse_headers: flags=4000
 3(10001) pre_auth(): Credentials with given realm not found
 3(10001) build_auth_hf(): 'WWW-Authenticate: Digest
realm="isp1.test.com", nonce="44718d6bc40cf955718d5a164c1e451f3f6ecf8c"'
 3(10001) parse_headers: flags=ffffffffffffffff
 3(10001) check_via_address(193.65.64.185, 193.65.64.185, 0)
 3(10001) DEBUG:destroy_avp_list: destroying list (nil)
 3(10001) receive_msg: cleaning up
 2(10000) SIP Request:
 2(10000)  method:  <REGISTER>
 2(10000)  uri:     <sip:isp1.test.com>
 2(10000)  version: <SIP/2.0>
 2(10000) parse_headers: flags=2
 2(10000) Found param type 232, <branch> = <z9hG4bK-bqdfe71z7k4a>; state=6
 2(10000) Found param type 235, <rport> = <n/a>; state=17
 2(10000) end of header reached, state=5
 2(10000) parse_headers: Via found, flags=2
 2(10000) parse_headers: this is the first via
 2(10000) After parse_msg...
 2(10000) preparing to run routing scripts...
 2(10000) parse_headers: flags=10
 2(10000) DEBUG: add_param: tag=iu6d3hlwqt
 2(10000) DEBUG:parse_to:end of header reached, state=29
 2(10000) parse_headers: flags=8
 2(10000) DEBUG:parse_to:end of header reached, state=9
 2(10000) DEBUG: get_hdr_field: <To> [30]; uri=[sip:client2 at isp1.test.com]
 2(10000) DEBUG: to body [<sip:client2 at isp1.test.com>]
 2(10000) SIP: method [REGISTER] from [sip:client2 at isp1.test.com] to
[sip:client2 at isp1.test.com]
 2(10000) parse_headers: flags=100
 2(10000) get_hdr_field: cseq <CSeq>: <541> <REGISTER>
 2(10000) DEBUG:maxfwd:is_maxfwd_present: value = 70
 2(10000) parse_headers: flags=200
 2(10000) DEBUG: get_hdr_body : content_length=0
 2(10000) found end of header
 2(10000) find_first_route: No Route headers found
 2(10000) loose_route: There is no Route HF
 2(10000) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 2(10000) grep_sock_info - checking if port 5060 matches port 5060
 2(10000) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 2(10000) grep_sock_info - checking if port 5060 matches port 5060
 2(10000) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 2(10000) grep_sock_info - checking if port 5060 matches port 5060
 2(10000) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 2(10000) grep_sock_info - checking if port 5060 matches port 5060
 2(10000) check_nonce(): comparing
[44718d6bc40cf955718d5a164c1e451f3f6ecf8c] and
[44718d6bc40cf955718d5a164c1e451f3f6ecf8c]
 3(10001) SIP Request:
 3(10001)  method:  <REGISTER>
 3(10001)  uri:     <sip:isp1.test.com>
 3(10001)  version: <SIP/2.0>
 3(10001) parse_headers: flags=2
 3(10001) Found param type 232, <branch> = <z9hG4bK-86b2yutqnbl4>; state=6
 3(10001) Found param type 235, <rport> = <n/a>; state=17
 3(10001) end of header reached, state=5
 3(10001) parse_headers: Via found, flags=2
 3(10001) parse_headers: this is the first via
 3(10001) After parse_msg...
 3(10001) preparing to run routing scripts...
 3(10001) parse_headers: flags=10
 3(10001) DEBUG: add_param: tag=opu4ec5rdn
 3(10001) DEBUG:parse_to:end of header reached, state=29
 3(10001) parse_headers: flags=8
 3(10001) DEBUG:parse_to:end of header reached, state=9
 3(10001) DEBUG: get_hdr_field: <To> [30]; uri=[sip:client2 at isp1.test.com]
 3(10001) DEBUG: to body [<sip:client2 at isp1.test.com>]
 3(10001) SIP: method [REGISTER] from [sip:client2 at isp1.test.com] to
[sip:client2 at isp1.test.com]
 3(10001) parse_headers: flags=100
 3(10001) get_hdr_field: cseq <CSeq>: <542> <REGISTER>
 3(10001) DEBUG:maxfwd:is_maxfwd_present: value = 70
 3(10001) parse_headers: flags=200
 3(10001) DEBUG: get_hdr_body : content_length=0
 3(10001) found end of header
 3(10001) find_first_route: No Route headers found
 3(10001) loose_route: There is no Route HF
 3(10001) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) check_nonce(): comparing
[44718d6bc40cf955718d5a164c1e451f3f6ecf8c] and
[44718d6bc40cf955718d5a164c1e451f3f6ecf8c]
 3(10001) DEBUG:auth_radius:radius_authorize_sterman: Success
 3(10001) DEBUG:auth_radius:generate_avps: getting SIP AVPs from avpair 225
 3(10001) parse_headers: flags=ffffffffffffffff
 3(10001) parse_headers: flags=8000000
 3(10001) build_contact(): Created Contact HF: Contact:
<sip:client2 at 193.65.64.185:2051;line=210u03g0>;q=1;expires=3600
 3(10001) parse_headers: flags=ffffffffffffffff
 3(10001) check_via_address(193.65.64.185, 193.65.64.185, 0)
 3(10001) Returned [1] 3(10001) DEBUG:destroy_avp_list: destroying list (nil)
 3(10001) receive_msg: cleaning up
 2(10000) DEBUG:auth_radius:radius_authorize_sterman: Success
 2(10000) DEBUG:auth_radius:generate_avps: getting SIP AVPs from avpair 225
 2(10000) parse_headers: flags=ffffffffffffffff
 2(10000) parse_headers: flags=8000000
 2(10000) parse_headers: flags=ffffffffffffffff
 2(10000) check_via_address(193.65.64.185, 193.65.64.185, 0)
 2(10000) Returned [1] 2(10000) DEBUG:destroy_avp_list: destroying list (nil)
 2(10000) receive_msg: cleaning up



Client1 registers and tries to call a call. The call just stops to 404 not
found
-----------------------------------
 3(10001) SIP Request:
 3(10001)  method:  <REGISTER>
 3(10001)  uri:     <sip:isp1v.test.com>
 3(10001)  version: <SIP/2.0>
 3(10001) parse_headers: flags=2
 3(10001) Found param type 232, <branch> =
<z9hG4bKb9lhoovhilhc6c5s0p089or>; state=6
 3(10001) Found param type 235, <rport> = <n/a>; state=17
 3(10001) end of header reached, state=5
 3(10001) parse_headers: Via found, flags=2
 3(10001) parse_headers: this is the first via
 3(10001) After parse_msg...
 3(10001) preparing to run routing scripts...
 3(10001) parse_headers: flags=10
 3(10001) DEBUG: add_param: tag=ohs1ooq5sdhc6jid0p08
 3(10001) DEBUG:parse_to:end of header reached, state=29
 3(10001) parse_headers: flags=8
 3(10001) DEBUG:parse_to:end of header reached, state=9
 3(10001) DEBUG: get_hdr_field: <To> [30]; uri=[sip:client1 at isp1v.test.com]
 3(10001) DEBUG: to body [<sip:client1 at isp1v.test.com>]
 3(10001) SIP: method [REGISTER] from [sip:client1 at isp1v.test.com] to
[sip:client1 at isp1v.test.com]
 3(10001) parse_headers: flags=100
 3(10001) get_hdr_field: cseq <CSeq>: <1274> <REGISTER>
 3(10001) DEBUG:maxfwd:is_maxfwd_present: value = 70
 3(10001) parse_headers: flags=200
 3(10001) DEBUG: get_hdr_body : content_length=0
 3(10001) found end of header
 3(10001) find_first_route: No Route headers found
 3(10001) loose_route: There is no Route HF
 3(10001) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) parse_headers: flags=4000
 3(10001) pre_auth(): Credentials with given realm not found
 3(10001) build_auth_hf(): 'WWW-Authenticate: Digest
realm="isp1.test.com", nonce="44718d80a9d45f60a4285350a5fe01c65ed9ef02"'
 3(10001) parse_headers: flags=ffffffffffffffff
 3(10001) check_via_address(193.65.64.188, 193.65.64.188, 0)
 3(10001) DEBUG:destroy_avp_list: destroying list (nil)
 3(10001) receive_msg: cleaning up
 5(10003) SIP Request:
 5(10003)  method:  <REGISTER>
 5(10003)  uri:     <sip:isp1v.test.com>
 5(10003)  version: <SIP/2.0>
 5(10003) parse_headers: flags=2
 5(10003) Found param type 232, <branch> =
<z9hG4bKnknleuinf8j2mdmi3hhpiu3>; state=6
 5(10003) Found param type 235, <rport> = <n/a>; state=17
 5(10003) end of header reached, state=5
 5(10003) parse_headers: Via found, flags=2
 5(10003) parse_headers: this is the first via
 5(10003) After parse_msg...
 5(10003) preparing to run routing scripts...
 5(10003) parse_headers: flags=10
 5(10003) DEBUG: add_param: tag=ohs1ooq5sdhc6jid0p08
 5(10003) DEBUG:parse_to:end of header reached, state=29
 5(10003) parse_headers: flags=8
 5(10003) DEBUG:parse_to:end of header reached, state=9
 5(10003) DEBUG: get_hdr_field: <To> [30]; uri=[sip:client1 at isp1v.test.com]
 5(10003) DEBUG: to body [<sip:client1 at isp1v.test.com>]
 5(10003) SIP: method [REGISTER] from [sip:client1 at isp1v.test.com] to
[sip:client1 at isp1v.test.com]
 5(10003) parse_headers: flags=100
 5(10003) get_hdr_field: cseq <CSeq>: <1275> <REGISTER>
 5(10003) DEBUG:maxfwd:is_maxfwd_present: value = 70
 5(10003) parse_headers: flags=200
 5(10003) DEBUG: get_hdr_body : content_length=0
 5(10003) found end of header
 5(10003) find_first_route: No Route headers found
 5(10003) loose_route: There is no Route HF
 5(10003) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 5(10003) grep_sock_info - checking if port 5060 matches port 5060
 5(10003) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 5(10003) grep_sock_info - checking if port 5060 matches port 5060
 5(10003) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 5(10003) grep_sock_info - checking if port 5060 matches port 5060
 5(10003) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 5(10003) grep_sock_info - checking if port 5060 matches port 5060
 5(10003) check_nonce(): comparing
[44718d80a9d45f60a4285350a5fe01c65ed9ef02] and
[44718d80a9d45f60a4285350a5fe01c65ed9ef02]
 5(10003) DEBUG:auth_radius:radius_authorize_sterman: Success
 5(10003) DEBUG:auth_radius:generate_avps: getting SIP AVPs from avpair 225
 5(10003) parse_headers: flags=ffffffffffffffff
 5(10003) parse_headers: flags=8000000
 5(10003) parse_headers: flags=ffffffffffffffff
 5(10003) build_contact(): Created Contact HF: Contact:
<sip:client1 at 193.65.64.188>;expires=3600
 5(10003) parse_headers: flags=ffffffffffffffff
 5(10003) check_via_address(193.65.64.188, 193.65.64.188, 0)
 5(10003) Returned [1] 5(10003) DEBUG:destroy_avp_list: destroying list (nil)
 5(10003) receive_msg: cleaning up
 3(10001) SIP Request:
 3(10001)  method:  <INVITE>
 3(10001)  uri:     <sip:isp1v.test.com>
 3(10001)  version: <SIP/2.0>
 3(10001) parse_headers: flags=2
 3(10001) Found param type 232, <branch> =
<z9hG4bK77choose8lhc74bs11v7nbo>; state=6
 3(10001) Found param type 235, <rport> = <n/a>; state=17
 3(10001) end of header reached, state=5
 3(10001) parse_headers: Via found, flags=2
 3(10001) parse_headers: this is the first via
 3(10001) After parse_msg...
 3(10001) preparing to run routing scripts...
 3(10001) parse_headers: flags=10
 3(10001) DEBUG: add_param: tag=69v1oopq6dhc7fuk11v7
 3(10001) DEBUG:parse_to:end of header reached, state=29
 3(10001) parse_headers: flags=8
 3(10001) DEBUG:parse_to:end of header reached, state=9
 3(10001) DEBUG: get_hdr_field: <To> [30]; uri=[sip:client2 at isp1.test.com]
 3(10001) DEBUG: to body [<sip:client2 at isp1.test.com>]
 3(10001) SIP: method [INVITE] from [sip:client1 at isp1v.test.com] to
[sip:client2 at isp1.test.com]
 3(10001) parse_headers: flags=100
 3(10001) get_hdr_field: cseq <CSeq>: <1275> <INVITE>
 3(10001) DEBUG:maxfwd:is_maxfwd_present: value = 70
 3(10001) parse_headers: flags=200
 3(10001) is_preloaded: Yes
 3(10001) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) after_loose: Topmost route URI: 'sip:client2 at isp1.test.com' is me
 3(10001) parse_headers: flags=200
 3(10001) DEBUG: get_hdr_body : content_length=297
 3(10001) found end of header
 3(10001) find_next_route: No next Route HF found
 3(10001) after_loose: No next URI found
 3(10001) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) lookup(): '' Not found in usrloc
 3(10001) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 15==13 && 
[isp1v.test.com] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) lookup(): '' Not found in usrloc
 3(10001) parse_headers: flags=ffffffffffffffff
 3(10001) check_via_address(193.65.64.188, 193.65.64.188, 0)
 3(10001) DEBUG:destroy_avp_list: destroying list (nil)
 3(10001) receive_msg: cleaning up
 5(10003) SIP Request:
 5(10003)  method:  <ACK>
 5(10003)  uri:     <sip:isp1v.test.com>
 5(10003)  version: <SIP/2.0>
 5(10003) parse_headers: flags=2
 5(10003) Found param type 232, <branch> =
<z9hG4bK77choose8lhc74bs11v7nbo>; state=6
 5(10003) Found param type 235, <rport> = <n/a>; state=17
 5(10003) end of header reached, state=5
 5(10003) parse_headers: Via found, flags=2
 5(10003) parse_headers: this is the first via
 5(10003) After parse_msg...
 5(10003) preparing to run routing scripts...
 5(10003) parse_headers: flags=8
 5(10003) DEBUG: add_param: tag=ead6a47b01fda88c7548438d3d23c061.0998
 5(10003) DEBUG:parse_to:end of header reached, state=29
 5(10003) DEBUG: get_hdr_field: <To> [72]; uri=[sip:client2 at isp1.test.com]
 5(10003) DEBUG: to body [<sip:client2 at isp1.test.com>]
 5(10003) DEBUG: sl_filter_ACK : local ACK found -> dropping it!
 5(10003) DEBUG:destroy_avp_list: destroying list (nil)
 5(10003) receive_msg: cleaning up



Client2 calls a successful call:
--------------------------------
 4(10002) SIP Request:
 4(10002)  method:  <INVITE>
 4(10002)  uri:     <sip:client1 at isp1.test.com>
 4(10002)  version: <SIP/2.0>
 4(10002) parse_headers: flags=2
 4(10002) Found param type 232, <branch> = <z9hG4bK-46xaidama2ue>; state=6
 4(10002) Found param type 235, <rport> = <n/a>; state=17
 4(10002) end of header reached, state=5
 4(10002) parse_headers: Via found, flags=2
 4(10002) parse_headers: this is the first via
 4(10002) After parse_msg...
 4(10002) preparing to run routing scripts...
 4(10002) parse_headers: flags=10
 4(10002) DEBUG: add_param: tag=t7am8pw33n
 4(10002) DEBUG:parse_to:end of header reached, state=29
 4(10002) parse_headers: flags=8
 4(10002) DEBUG:parse_to:end of header reached, state=9
 4(10002) DEBUG: get_hdr_field: <To> [29]; uri=[sip:client1 at isp1.test.com]
 4(10002) DEBUG: to body [<sip:client1 at isp1.test.com>]
 4(10002) SIP: method [INVITE] from [sip:client2 at isp1.test.com] to
[sip:client1 at isp1.test.com]
 4(10002) parse_headers: flags=100
 4(10002) get_hdr_field: cseq <CSeq>: <1> <INVITE>
 4(10002) DEBUG:maxfwd:is_maxfwd_present: value = 70
 4(10002) parse_headers: flags=200
 4(10002) DEBUG: get_hdr_body : content_length=475
 4(10002) found end of header
 4(10002) find_first_route: No Route headers found
 4(10002) loose_route: There is no Route HF
 4(10002) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 4(10002) grep_sock_info - checking if port 5060 matches port 5060
 4(10002) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 4(10002) grep_sock_info - checking if port 5060 matches port 5060
 4(10002) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 4(10002) grep_sock_info - checking if port 5060 matches port 5060
 4(10002) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 4(10002) grep_sock_info - checking if port 5060 matches port 5060
 4(10002) lookup(): 'client1' Not found in usrloc
 4(10002) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 4(10002) grep_sock_info - checking if port 5060 matches port 5060
 4(10002) grep_sock_info - checking if host==us: 14==13 && 
[isp1.test.com] == [193.65.64.130]
 4(10002) grep_sock_info - checking if port 5060 matches port 5060
 4(10002) rewrite_uri: Rewriting Request-URI with 'sip:client1 at 193.65.64.188'
 4(10002) parse_headers: flags=ffffffffffffffff
 4(10002) DEBUG: t_newtran: msg id=1 , global msg id=0 , T on
entrance=0xffffffff
 4(10002) parse_headers: flags=ffffffffffffffff
 4(10002) parse_headers: flags=78
 4(10002) t_lookup_request: start searching: hash=31985, isACK=0
 4(10002) DEBUG: RFC3261 transaction matching failed
 4(10002) DEBUG: t_lookup_request: no transaction found
 4(10002) DEBUG:tm:t_relay: new INVITE
 4(10002) parse_headers: flags=ffffffffffffffff
 4(10002) check_via_address(193.65.64.185, 193.65.64.185, 0)
 4(10002) WARNING:vqm_resize: resize(0) called
 4(10002) DEBUG:tm:_reply_light: reply sent out. buf=0x814cb00: SIP/2.0
1..., shmem=0xb61146e8: SIP/2.0 1
 4(10002) DEBUG:tm:_reply_light: finished
 4(10002) DEBUG: mk_proxy: doing DNS lookup...
 4(10002) check_via_address(193.65.64.185, 193.65.64.185, 0)
 4(10002) DEBUG: add_to_tail_of_timer[4]: 0xb6112e8c
 4(10002) DEBUG: add_to_tail_of_timer[0]: 0xb6112e9c
 4(10002) SER: new transaction fwd'ed
 4(10002) DEBUG:destroy_avp_list: destroying list (nil)
 4(10002) receive_msg: cleaning up
 5(10003) SIP Reply  (status):
 5(10003)  version: <SIP/2.0>
 5(10003)  status:  <100>
 5(10003)  reason:  <Trying>
 5(10003) parse_headers: flags=2
 5(10003) Found param type 232, <branch> = <z9hG4bK1fc7.7197ab25.0>; state=9
 5(10003) parse_via: next_via
 5(10003) Found param type 232, <branch> = <z9hG4bK-46xaidama2ue>; state=6
 5(10003) Found param type 235, <rport> = <2051>; state=16
 5(10003) end of header reached, state=5
 5(10003) parse_headers: Via found, flags=2
 5(10003) parse_headers: this is the first via
 5(10003) After parse_msg...
 5(10003) forward_reply: found module tm, passing reply to it
 5(10003) DEBUG: t_check: msg id=3 global id=0 T start=0xffffffff
 5(10003) parse_headers: flags=22
 5(10003) DEBUG:parse_to:end of header reached, state=9
 5(10003) DEBUG: get_hdr_field: <To> [29]; uri=[sip:client1 at isp1.test.com]
 5(10003) DEBUG: to body [<sip:client1 at isp1.test.com>]
 5(10003) get_hdr_field: cseq <CSeq>: <1> <INVITE>
 5(10003) parse_headers: flags=8
 5(10003) DEBUG: t_reply_matching: hash 31985 label 1387952407 branch 0
 5(10003) DEBUG: t_reply_matching: reply matched (T=0xb6112d70)!
 5(10003) DEBUG: t_check: msg id=3 global id=3 T end=0xb6112d70
 5(10003) DEBUG:tm:reply_received: org. status uas=100, uac[0]=0 local=0
is_invite=1)
 5(10003) DEBUG:tm:t_should_relay_response: T_code=100, new_code=100
 5(10003) DEBUG:tm:relay_reply: branch=0, save=0, relay=-1
 5(10003) DEBUG: add_to_tail_of_timer[1]: 0xb6112e9c
 5(10003) DEBUG:destroy_avp_list: destroying list (nil)
 5(10003) receive_msg: cleaning up
 6(10004) DEBUG: timer routine:4,tl=0xb6112e8c next=(nil)
 4(10002) SIP Reply  (status):
 4(10002)  version: <SIP/2.0>
 4(10002)  status:  <180>
 4(10002)  reason:  <Ringing>
 4(10002) parse_headers: flags=2
 4(10002) Found param type 232, <branch> = <z9hG4bK1fc7.7197ab25.0>; state=9
 4(10002) parse_via: next_via
 4(10002) Found param type 232, <branch> = <z9hG4bK-46xaidama2ue>; state=6
 4(10002) Found param type 235, <rport> = <2051>; state=16
 4(10002) end of header reached, state=5
 4(10002) parse_headers: Via found, flags=2
 4(10002) parse_headers: this is the first via
 4(10002) After parse_msg...
 4(10002) forward_reply: found module tm, passing reply to it
 4(10002) DEBUG: t_check: msg id=2 global id=1 T start=0xffffffff
 4(10002) parse_headers: flags=22
 4(10002) DEBUG: add_param: tag=875dj3ephm95qdmi3hhuda32odkdc2ap
 4(10002) DEBUG:parse_to:end of header reached, state=29
 4(10002) DEBUG: get_hdr_field: <To> [66]; uri=[sip:client1 at isp1.test.com]
 4(10002) DEBUG: to body [<sip:client1 at isp1.test.com>]
 4(10002) get_hdr_field: cseq <CSeq>: <1> <INVITE>
 4(10002) parse_headers: flags=8
 4(10002) DEBUG: t_reply_matching: hash 31985 label 1387952407 branch 0
 4(10002) DEBUG: t_reply_matching: reply matched (T=0xb6112d70)!
 4(10002) DEBUG: t_check: msg id=2 global id=2 T end=0xb6112d70
 4(10002) DEBUG:tm:reply_received: org. status uas=100, uac[0]=100 local=0
is_invite=1)
 4(10002) DEBUG:tm:t_should_relay_response: T_code=100, new_code=180
 4(10002) DEBUG:tm:relay_reply: branch=0, save=0, relay=0
 4(10002)  old size: 462, new size: 406
 4(10002) build_res_from_sip_res: copied size: orig:139, new: 83, rest:
323 msg=
SIP/2.0 180 Ringing
Record-Route: <sip:193.65.64.130;lr=on;ftag=t7am8pw33n>
Via: SIP/2.0/UDP 193.65.64.185:2051;branch=z9hG4bK-46xaidama2ue;rport=2051
From: <sip:client2 at isp1.test.com>;tag=t7am8pw33n
To: <sip:client1 at isp1.test.com>;tag=875dj3ephm95qdmi3hhuda32odkdc2ap
Contact: <sip:client1 at 193.65.64.188>
Call-ID: 3c2cd5692e63-6u95t16ssrw2 at snom360-000413231BFC
CSeq: 1 INVITE
Content-Length: 0

 4(10002) DEBUG:tm:relay_reply: sent buf=0x814cd28: SIP/2.0 1...,
shmem=0xb61146e8: SIP/2.0 1
 4(10002) DEBUG: add_to_tail_of_timer[1]: 0xb6112e9c
 4(10002) DEBUG:destroy_avp_list: destroying list (nil)
 4(10002) receive_msg: cleaning up
 3(10001) SIP Reply  (status):
 3(10001)  version: <SIP/2.0>
 3(10001)  status:  <200>
 3(10001)  reason:  <OK>
 3(10001) parse_headers: flags=2
 3(10001) Found param type 232, <branch> = <z9hG4bK1fc7.7197ab25.0>; state=9
 3(10001) parse_via: next_via
 3(10001) Found param type 232, <branch> = <z9hG4bK-46xaidama2ue>; state=6
 3(10001) Found param type 235, <rport> = <2051>; state=16
 3(10001) end of header reached, state=5
 3(10001) parse_headers: Via found, flags=2
 3(10001) parse_headers: this is the first via
 3(10001) After parse_msg...
 3(10001) forward_reply: found module tm, passing reply to it
 3(10001) DEBUG: t_check: msg id=5 global id=0 T start=0xffffffff
 3(10001) parse_headers: flags=22
 3(10001) DEBUG: add_param: tag=875dj3ephm95qdmi3hhuda32odkdc2ap
 3(10001) DEBUG:parse_to:end of header reached, state=29
 3(10001) DEBUG: get_hdr_field: <To> [66]; uri=[sip:client1 at isp1.test.com]
 3(10001) DEBUG: to body [<sip:client1 at isp1.test.com>]
 3(10001) get_hdr_field: cseq <CSeq>: <1> <INVITE>
 3(10001) parse_headers: flags=8
 3(10001) DEBUG: t_reply_matching: hash 31985 label 1387952407 branch 0
 3(10001) DEBUG: t_reply_matching: reply matched (T=0xb6112d70)!
 3(10001) DEBUG: t_check: msg id=5 global id=5 T end=0xb6112d70
 3(10001) DEBUG:tm:reply_received: org. status uas=180, uac[0]=180 local=0
is_invite=1)
 3(10001) DEBUG:tm:t_should_relay_response: T_code=180, new_code=200
 3(10001) DEBUG:tm:relay_reply: branch=0, save=0, relay=0
 3(10001)  old size: 801, new size: 745
 3(10001) build_res_from_sip_res: copied size: orig:134, new: 78, rest:
667 msg=
SIP/2.0 200 OK
Record-Route: <sip:193.65.64.130;lr=on;ftag=t7am8pw33n>
Via: SIP/2.0/UDP 193.65.64.185:2051;branch=z9hG4bK-46xaidama2ue;rport=2051
To: <sip:client1 at isp1.test.com>;tag=875dj3ephm95qdmi3hhuda32odkdc2ap
Contact: <sip:client1 at 193.65.64.188>
From: <sip:client2 at isp1.test.com>;tag=t7am8pw33n
Call-ID: 3c2cd5692e63-6u95t16ssrw2 at snom360-000413231BFC
CSeq: 1 INVITE
Allow: INVITE,ACK,BYE,CANCEL,REFER,NOTIFY,OPTIONS
Content-Type: application/sdp
Accept: application/sdp
Content-Length: 235

v=0
o=Nokia-SIPUA 916528949 916528949 IN IP4 193.65.64.188
s=call
c=IN IP4 193.65.64.188
t=0 0
m=audio 16384 RTP/AVP 8 101
a=ptime:20
a=maxptime:100
a=fmtp:101 0-15
a=rtpmap:8 PCMA/8000/1
a=rtpmap:101 telephone-event/8000/1

 3(10001) DEBUG: add_to_tail_of_timer[2]: 0xb6112db8
 3(10001) DEBUG:tm:relay_reply: sent buf=0x814d0f8: SIP/2.0 2...,
shmem=0xb6114ef0: SIP/2.0 2
 3(10001) DEBUG: cleanup_uac_timers: RETR/FR timers reset
 3(10001) DEBUG:destroy_avp_list: destroying list (nil)
 3(10001) receive_msg: cleaning up
 4(10002) SIP Request:
 4(10002)  method:  <ACK>
 4(10002)  uri:     <sip:client1 at 193.65.64.188>
 4(10002)  version: <SIP/2.0>
 4(10002) parse_headers: flags=2
 4(10002) Found param type 232, <branch> = <z9hG4bK-oso6kd1fz5wc>; state=6
 4(10002) Found param type 235, <rport> = <n/a>; state=17
 4(10002) end of header reached, state=5
 4(10002) parse_headers: Via found, flags=2
 4(10002) parse_headers: this is the first via
 4(10002) After parse_msg...
 4(10002) preparing to run routing scripts...
 4(10002) DEBUG : sl_filter_ACK: to late to be a local ACK!
 4(10002) parse_headers: flags=10
 4(10002) DEBUG: add_param: tag=t7am8pw33n
 4(10002) DEBUG:parse_to:end of header reached, state=29
 4(10002) parse_headers: flags=8
 4(10002) DEBUG: add_param: tag=875dj3ephm95qdmi3hhuda32odkdc2ap
 4(10002) DEBUG:parse_to:end of header reached, state=29
 4(10002) DEBUG: get_hdr_field: <To> [66]; uri=[sip:client1 at isp1.test.com]
 4(10002) DEBUG: to body [<sip:client1 at isp1.test.com>]
 4(10002) SIP: method [ACK] from [sip:client2 at isp1.test.com] to
[sip:client1 at isp1.test.com]
 4(10002) parse_headers: flags=100
 4(10002) get_hdr_field: cseq <CSeq>: <1> <ACK>
 4(10002) DEBUG:maxfwd:is_maxfwd_present: value = 70
 4(10002) parse_headers: flags=200
 4(10002) is_preloaded: No
 4(10002) grep_sock_info - checking if host==us: 13==13 && 
[193.65.64.188] == [193.65.64.130]
 4(10002) grep_sock_info - checking if port 5060 matches port 5060
 4(10002) grep_sock_info - checking if host==us: 13==13 && 
[193.65.64.188] == [193.65.64.130]
 4(10002) grep_sock_info - checking if port 5060 matches port 5060
 4(10002) check_self: host != me
 4(10002) grep_sock_info - checking if host==us: 13==13 && 
[193.65.64.130] == [193.65.64.130]
 4(10002) grep_sock_info - checking if port 5060 matches port 5060
 4(10002) after_loose: Topmost route URI:
'sip:193.65.64.130;lr=on;ftag=t7am8pw33n' is me
 4(10002) parse_headers: flags=200
 4(10002) DEBUG: get_hdr_body : content_length=0
 4(10002) found end of header
 4(10002) find_next_route: No next Route HF found
 4(10002) after_loose: No next URI found
 4(10002) parse_headers: flags=ffffffffffffffff
 4(10002) DEBUG: t_newtran: msg id=3 , global msg id=2 , T on
entrance=0xffffffff
 4(10002) parse_headers: flags=ffffffffffffffff
 4(10002) parse_headers: flags=78
 4(10002) t_lookup_request: start searching: hash=31985, isACK=1
 4(10002) parse_headers: flags=38
 4(10002) DEBUG: t_lookup_request: e2e proxy ACK found
 4(10002) DEBUG:tm:t_relay: forwarding ACK  statelessly
 4(10002) DEBUG: mk_proxy: doing DNS lookup...
 4(10002) check_via_address(193.65.64.185, 193.65.64.185, 0)
 4(10002) Sending:
ACK sip:client1 at 193.65.64.188 SIP/2.0
Record-Route: <sip:193.65.64.130;lr=on;ftag=t7am8pw33n>
Via: SIP/2.0/UDP 193.65.64.130;branch=0
Via: SIP/2.0/UDP 193.65.64.185:2051;branch=z9hG4bK-oso6kd1fz5wc;rport=2051
From: <sip:client2 at isp1.test.com>;tag=t7am8pw33n
To: <sip:client1 at isp1.test.com>;tag=875dj3ephm95qdmi3hhuda32odkdc2ap
Call-ID: 3c2cd5692e63-6u95t16ssrw2 at snom360-000413231BFC
CSeq: 1 ACK
Max-Forwards: 69
Contact: <sip:client2 at 193.65.64.185:2051;line=210u03g0>;flow-id=1
Content-Length: 0
P-hint: rr-enforced

.
 4(10002) orig. len=456, new_len=530, proto=1
 4(10002) DEBUG:destroy_avp_list: destroying list (nil)
 4(10002) receive_msg: cleaning up
 6(10004) DEBUG: timer routine:1,tl=0xb6112e9c next=(nil)
 6(10004) DEBUG: timer routine:2,tl=0xb6112db8 next=(nil)
 6(10004) DEBUG: wait_handler : removing 0xb6112d70 from table
 6(10004) DEBUG: delete transaction 0xb6112d70
 6(10004) DEBUG: wait_handler : done
 3(10001) SIP Request:
 3(10001)  method:  <BYE>
 3(10001)  uri:     <sip:client1 at 193.65.64.188>
 3(10001)  version: <SIP/2.0>
 3(10001) parse_headers: flags=2
 3(10001) Found param type 232, <branch> = <z9hG4bK-9z0xphr8e1e8>; state=6
 3(10001) Found param type 235, <rport> = <n/a>; state=17
 3(10001) end of header reached, state=5
 3(10001) parse_headers: Via found, flags=2
 3(10001) parse_headers: this is the first via
 3(10001) After parse_msg...
 3(10001) preparing to run routing scripts...
 3(10001) parse_headers: flags=10
 3(10001) DEBUG: add_param: tag=t7am8pw33n
 3(10001) DEBUG:parse_to:end of header reached, state=29
 3(10001) parse_headers: flags=8
 3(10001) DEBUG: add_param: tag=875dj3ephm95qdmi3hhuda32odkdc2ap
 3(10001) DEBUG:parse_to:end of header reached, state=29
 3(10001) DEBUG: get_hdr_field: <To> [66]; uri=[sip:client1 at isp1.test.com]
 3(10001) DEBUG: to body [<sip:client1 at isp1.test.com>]
 3(10001) SIP: method [BYE] from [sip:client2 at isp1.test.com] to
[sip:client1 at isp1.test.com]
 3(10001) parse_headers: flags=100
 3(10001) get_hdr_field: cseq <CSeq>: <2> <BYE>
 3(10001) DEBUG:maxfwd:is_maxfwd_present: value = 70
 3(10001) parse_headers: flags=200
 3(10001) is_preloaded: No
 3(10001) grep_sock_info - checking if host==us: 13==13 && 
[193.65.64.188] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) grep_sock_info - checking if host==us: 13==13 && 
[193.65.64.188] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) check_self: host != me
 3(10001) grep_sock_info - checking if host==us: 13==13 && 
[193.65.64.130] == [193.65.64.130]
 3(10001) grep_sock_info - checking if port 5060 matches port 5060
 3(10001) after_loose: Topmost route URI:
'sip:193.65.64.130;lr=on;ftag=t7am8pw33n' is me
 3(10001) parse_headers: flags=200
 3(10001) DEBUG: get_hdr_body : content_length=0
 3(10001) found end of header
 3(10001) find_next_route: No next Route HF found
 3(10001) after_loose: No next URI found
 3(10001) parse_headers: flags=ffffffffffffffff
 3(10001) DEBUG: t_newtran: msg id=6 , global msg id=5 , T on
entrance=0xffffffff
 3(10001) parse_headers: flags=ffffffffffffffff
 3(10001) parse_headers: flags=78
 3(10001) t_lookup_request: start searching: hash=31982, isACK=0
 3(10001) DEBUG: RFC3261 transaction matching failed
 3(10001) DEBUG: t_lookup_request: no transaction found
 3(10001) DEBUG: mk_proxy: doing DNS lookup...
 3(10001) check_via_address(193.65.64.185, 193.65.64.185, 0)
 3(10001) DEBUG: add_to_tail_of_timer[4]: 0xb6112e8c
 3(10001) DEBUG: add_to_tail_of_timer[0]: 0xb6112e9c
 3(10001) SER: new transaction fwd'ed
 3(10001) DEBUG:destroy_avp_list: destroying list (nil)
 3(10001) receive_msg: cleaning up
 4(10002) SIP Reply  (status):
 4(10002)  version: <SIP/2.0>
 4(10002)  status:  <200>
 4(10002)  reason:  <OK>
 4(10002) parse_headers: flags=2
 4(10002) Found param type 232, <branch> = <z9hG4bKeec7.563fca56.0>; state=9
 4(10002) parse_via: next_via
 4(10002) Found param type 232, <branch> = <z9hG4bK-9z0xphr8e1e8>; state=6
 4(10002) Found param type 235, <rport> = <2051>; state=16
 4(10002) end of header reached, state=5
 4(10002) parse_headers: Via found, flags=2
 4(10002) parse_headers: this is the first via
 4(10002) After parse_msg...
 4(10002) forward_reply: found module tm, passing reply to it
 4(10002) DEBUG: t_check: msg id=4 global id=3 T start=(nil)
 4(10002) parse_headers: flags=22
 4(10002) DEBUG: add_param: tag=875dj3ephm95qdmi3hhuda32odkdc2ap
 4(10002) DEBUG:parse_to:end of header reached, state=29
 4(10002) DEBUG: get_hdr_field: <To> [66]; uri=[sip:client1 at isp1.test.com]
 4(10002) DEBUG: to body [<sip:client1 at isp1.test.com>]
 4(10002) get_hdr_field: cseq <CSeq>: <2> <BYE>
 4(10002) DEBUG: t_reply_matching: hash 31982 label 1705833317 branch 0
 4(10002) DEBUG: t_reply_matching: reply matched (T=0xb6112d70)!
 4(10002) DEBUG: t_check: msg id=4 global id=4 T end=0xb6112d70
 4(10002) DEBUG:tm:reply_received: org. status uas=0, uac[0]=0 local=0
is_invite=0)
 4(10002) DEBUG:tm:t_should_relay_response: T_code=0, new_code=200
 4(10002) DEBUG:tm:relay_reply: branch=0, save=0, relay=0
 4(10002)  old size: 360, new size: 304
 4(10002) build_res_from_sip_res: copied size: orig:77, new: 21, rest: 283
msg=
SIP/2.0 200 OK
Via: SIP/2.0/UDP 193.65.64.185:2051;branch=z9hG4bK-9z0xphr8e1e8;rport=2051
To: <sip:client1 at isp1.test.com>;tag=875dj3ephm95qdmi3hhuda32odkdc2ap
From: <sip:client2 at isp1.test.com>;tag=t7am8pw33n
Call-ID: 3c2cd5692e63-6u95t16ssrw2 at snom360-000413231BFC
CSeq: 2 BYE
Content-Length: 0


 4(10002) WARNING:vqm_resize: resize(0) called
 4(10002) DEBUG: add_to_tail_of_timer[2]: 0xb6112db8
 4(10002) DEBUG:tm:relay_reply: sent buf=0x814cd28: SIP/2.0 2...,
shmem=0xb61146e8: SIP/2.0 2
 4(10002) DEBUG: cleanup_uac_timers: RETR/FR timers reset
 4(10002) DEBUG:destroy_avp_list: destroying list (nil)
 4(10002) receive_msg: cleaning up
 6(10004) DEBUG: timer routine:0,tl=0xb6112e9c next=(nil)
 6(10004) DEBUG: timer routine:4,tl=0xb6112e8c next=(nil)

 6(10004) DEBUG: timer routine:2,tl=0xb6112db8 next=(nil)
 6(10004) DEBUG: wait_handler : removing 0xb6112d70 from table
 6(10004) DEBUG: delete transaction 0xb6112d70
 6(10004) DEBUG: wait_handler : done

 6(10004) Binding 'client2','sip:client2 at 193.65.64.185:2051;line=210u03g0'
has expired


/etc/rc.d/init.d/openser stop
---------------------------------
Stopping openser: 10(10008) INFO: signal 15 received
10(10008) Memory status (pkg):
10(10008) fm_status (0x8140260):
10(10008)  heap size= 1048576
10(10008)  used= 78688, used+overhead=98024, free=950552
10(10008)  max used (+overhead)= 98024
10(10008) dumping free list:
10(10008) hash =   1 fragments no.:     1, unused:     0
                 bucket size:         8 -         8 (first         8)
10(10008) hash =   8 fragments no.:     1, unused:     0
                 bucket size:        64 -        64 (first        64)
10(10008) hash =  16 fragments no.:     7, unused:     0
                 bucket size:       128 -       128 (first       128)
10(10008) hash =  24 fragments no.:     5, unused:     0
                 bucket size:       192 -       192 (first       192)
10(10008) hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    948624)
10(10008) TOTAL:     15 free fragments = 950552 free bytes
10(10008) -----------------------------
11(10009) INFO: signal 15 received
11(10009) Memory status (pkg):
11(10009) fm_status (0x8140260):
11(10009)  heap size= 1048576
11(10009)  used= 77600, used+overhead=96904, free=951672
11(10009)  max used (+overhead)= 96904
11(10009) dumping free list:
11(10009) hash =   1 fragments no.:     3, unused:     0
                 bucket size:         8 -         8 (first         8)
11(10009) hash =   2 fragments no.:     1, unused:     0
                 bucket size:        16 -        16 (first        16)
11(10009) hash =   3 fragments no.:     1, unused:     0
                 bucket size:        24 -        24 (first        24)
11(10009) hash =   5 fragments no.:     1, unused:     0
                 bucket size:        40 -        40 (first        40)
11(10009) hash =  16 fragments no.:     8, unused:     0
                 bucket size:       128 -       128 (first       128)
11(10009) hash =  24 fragments no.:     5, unused:     0
                 bucket size:       192 -       192 (first       192)
11(10009) hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    949584)
11(10009) TOTAL:     20 free fragments = 951672 free bytes
11(10009) -----------------------------
 0(9995) child process 10008 exited normally, status=0
 0(9995) INFO: terminating due to SIGCHLD
 6(10004) INFO: signal 15 received
 6(10004) Memory status (pkg):
 6(10004) fm_status (0x8140260):
 6(10004)  heap size= 1048576
 6(10004)  used= 27792, used+overhead=47080, free=1001496
 6(10004)  max used (+overhead)= 48512
 6(10004) dumping free list:
 6(10004) hash =   1 fragments no.:     3, unused:     0
                 bucket size:         8 -         8 (first         8)
 6(10004) hash =   2 fragments no.:     1, unused:     0
                 bucket size:        16 -        16 (first        16)
 6(10004) hash =   3 fragments no.:     1, unused:     0
                 bucket size:        24 -        24 (first        24)
 6(10004) hash =   5 fragments no.:     1, unused:     0
                 bucket size:        40 -        40 (first        40)
 6(10004) hash =  16 fragments no.:     8, unused:     0
                 bucket size:       128 -       128 (first       128)
 6(10004) hash =  24 fragments no.:     5, unused:     0
                 bucket size:       192 -       192 (first       192)
 6(10004) hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    999408)
 6(10004) TOTAL:     20 free fragments = 1001496 free bytes
 6(10004) -----------------------------
 1(9999) INFO: signal 15 received
 1(9999) Memory status (pkg):
 1(9999) fm_status (0x8140260):
 1(9999)  heap size= 1048576
 1(9999)  used= 27960, used+overhead=47288, free=1001288
 1(9999)  max used (+overhead)= 48512
 1(9999) dumping free list:
 1(9999) hash =   1 fragments no.:     3, unused:     0
                 bucket size:         8 -         8 (first         8)
 1(9999) hash =  16 fragments no.:     7, unused:     0
                 bucket size:       128 -       128 (first       128)
 1(9999) hash =  24 fragments no.:     5, unused:     0
                 bucket size:       192 -       192 (first       192)
 1(9999) hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    999408)
 1(9999) TOTAL:     16 free fragments = 1001288 free bytes
 1(9999) -----------------------------
 2(10000) INFO: signal 15 received
 2(10000) Memory status (pkg):
 2(10000) fm_status (0x8140260):
 2(10000)  heap size= 1048576
 2(10000)  used= 28944, used+overhead=48480, free=1000096
 2(10000)  max used (+overhead)= 51592
 2(10000) dumping free list:
 2(10000) hash =   1 fragments no.:     1, unused:     0
                 bucket size:         8 -         8 (first         8)
 2(10000) hash =   2 fragments no.:     2, unused:     0
                 bucket size:        16 -        16 (first        16)
 2(10000) hash =   3 fragments no.:     2, unused:     0
                 bucket size:        24 -        24 (first        24)
 2(10000) hash =   4 fragments no.:     9, unused:     0
                 bucket size:        32 -        32 (first        32)
 2(10000) hash =   5 fragments no.:    13, unused:     0
                 bucket size:        40 -        40 (first        40)
 2(10000) hash =   6 fragments no.:     5, unused:     0
                 bucket size:        48 -        48 (first        48)
 2(10000) hash =   7 fragments no.:     1, unused:     0
                 bucket size:        56 -        56 (first        56)
 2(10000) hash =  10 fragments no.:     3, unused:     0
                 bucket size:        80 -        80 (first        80)
 2(10000) hash =  16 fragments no.:     1, unused:     0
                 bucket size:       128 -       128 (first       128)
 2(10000) hash =  18 fragments no.:     1, unused:     0
                 bucket size:       144 -       144 (first       144)
 2(10000) hash =  77 fragments no.:     1, unused:     0
                 bucket size:       616 -       616 (first       616)
 2(10000) hash =  99 fragments no.:     1, unused:     0
                 bucket size:       792 -       792 (first       792)
 2(10000) hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    996984)
 2(10000) TOTAL:     41 free fragments = 1000096 free bytes
 2(10000) -----------------------------
 4(10002) INFO: signal 15 received
 4(10002) Memory status (pkg):
 4(10002) fm_status (0x8140260):
 4(10002)  heap size= 1048576
 4(10002)  used= 28944, used+overhead=48704, free=999872
 4(10002)  max used (+overhead)= 53096
 4(10002) dumping free list:
 4(10002) hash =   1 fragments no.:     7, unused:     0
                 bucket size:         8 -         8 (first         8)
 4(10002) hash =   2 fragments no.:     2, unused:     0
                 bucket size:        16 -        16 (first        16)
 4(10002) hash =   3 fragments no.:     7, unused:     0
                 bucket size:        24 -        24 (first        24)
 4(10002) hash =   4 fragments no.:    22, unused:     0
                 bucket size:        32 -        32 (first        32)
 4(10002) hash =   5 fragments no.:    16, unused:     0
                 bucket size:        40 -        40 (first        40)
 4(10002) hash =   6 fragments no.:     4, unused:     0
                 bucket size:        48 -        48 (first        48)
 4(10002) hash =   7 fragments no.:     1, unused:     0
                 bucket size:        56 -        56 (first        56)
 4(10002) hash =   8 fragments no.:     1, unused:     0
                 bucket size:        64 -        64 (first        64)
 4(10002) hash =   9 fragments no.:     1, unused:     0
                 bucket size:        72 -        72 (first        72)
 4(10002) hash =  10 fragments no.:     2, unused:     0
                 bucket size:        80 -        80 (first        80)
 4(10002) hash =  16 fragments no.:     1, unused:     0
                 bucket size:       128 -       128 (first       128)
 4(10002) hash =  20 fragments no.:     1, unused:     0
                 bucket size:       160 -       160 (first       160)
 4(10002) hash =  51 fragments no.:     1, unused:     0
                 bucket size:       408 -       408 (first       408)
 4(10002) hash =  99 fragments no.:     1, unused:     0
                 bucket size:       792 -       792 (first       792)
 4(10002) hash = 115 fragments no.:     1, unused:     0
                 bucket size:       920 -       920 (first       920)
 4(10002) hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    995320)
 4(10002) TOTAL:     69 free fragments = 999872 free bytes
 4(10002) -----------------------------
 5(10003) INFO: signal 15 received
 5(10003) Memory status (pkg):
 5(10003) fm_status (0x8140260):
 5(10003)  heap size= 1048576
 5(10003)  used= 29016, used+overhead=48464, free=1000112
 5(10003)  max used (+overhead)= 51088
 5(10003) dumping free list:
 5(10003) hash =   1 fragments no.:     1, unused:     0
                 bucket size:         8 -         8 (first         8)
 5(10003) hash =   2 fragments no.:     2, unused:     0
                 bucket size:        16 -        16 (first        16)
 5(10003) hash =   3 fragments no.:     2, unused:     0
                 bucket size:        24 -        24 (first        24)
 5(10003) hash =   4 fragments no.:     1, unused:     0
                 bucket size:        32 -        32 (first        32)
 5(10003) hash =   5 fragments no.:     9, unused:     0
                 bucket size:        40 -        40 (first        40)
 5(10003) hash =   6 fragments no.:     2, unused:     0
                 bucket size:        48 -        48 (first        48)
 5(10003) hash =   8 fragments no.:     1, unused:     0
                 bucket size:        64 -        64 (first        64)
 5(10003) hash =  10 fragments no.:     3, unused:     0
                 bucket size:        80 -        80 (first        80)
 5(10003) hash =  12 fragments no.:     1, unused:     0
                 bucket size:        96 -        96 (first        96)
 5(10003) hash =  16 fragments no.:     1, unused:     0
                 bucket size:       128 -       128 (first       128)
 5(10003) hash =  24 fragments no.:     3, unused:     0
                 bucket size:       192 -       192 (first       192)
 5(10003) hash =  75 fragments no.:     1, unused:     0
                 bucket size:       600 -       600 (first       600)
 5(10003) hash =  99 fragments no.:     1, unused:     0
                 bucket size:       792 -       792 (first       792)
 5(10003) hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    997040)
 5(10003) TOTAL:     29 free fragments = 1000112 free bytes
 5(10003) -----------------------------
 7(10005) INFO: signal 15 received
 7(10005) Memory status (pkg):
 7(10005) fm_status (0x8140260):
 7(10005)  heap size= 1048576
 7(10005)  used= 78688, used+overhead=98024, free=950552
 7(10005)  max used (+overhead)= 98024
 7(10005) dumping free list:
 7(10005) hash =   1 fragments no.:     1, unused:     0
                 bucket size:         8 -         8 (first         8)
 7(10005) hash =   8 fragments no.:     1, unused:     0
                 bucket size:        64 -        64 (first        64)
 7(10005) hash =  16 fragments no.:     7, unused:     0
                 bucket size:       128 -       128 (first       128)
 7(10005) hash =  24 fragments no.:     5, unused:     0
                 bucket size:       192 -       192 (first       192)
 7(10005)  9(10007) INFO: signal 15 received
 9(10007) Memory status (pkg):
 9(10007) fm_status (0x8140260):
 9(10007)  heap size= 1048576
 9(10007)  used= 78688, used+overhead=98024, free=950552
 9(10007)  max used (+overhead)= 98024
 9(10007) dumping free list:
 9(10007) hash =   1 fragments no.:     1, unused:     0
                 bucket size:         8 -         8 (first         8)
 9(10007) hash =   8 fragments no.:     1, unused:     0
                 bucket size:        64 -        64 (first        64)
 9(10007) hash =  16 fragments no.:     7, unused:     0
                 bucket size:       128 -       128 (first       128)
 9(10007) hash =  24 fragments no.:     5, unused:     0
                 bucket size:       192 -       192 (first       192)
 9(10007) hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    948624)
 9(10007) TOTAL:     15 free fragments = 950552 free bytes
 9(10007) -----------------------------
hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    948624)
 7(10005) TOTAL:     15 free fragments = 950552 free bytes
 7(10005) -----------------------------
 8(10006) INFO: signal 15 received
 8(10006) Memory status (pkg):
 8(10006) fm_status (0x8140260):
 8(10006)  heap size= 1048576
 8(10006)  used= 78688, used+overhead=98024, free=950552
 8(10006)  max used (+overhead)= 98024
 8(10006) dumping free list:
 8(10006) hash =   1 fragments no.:     1, unused:     0
                 bucket size:         8 -         8 (first         8)
 8(10006) hash =   8 fragments no.:     1, unused:     0
                 bucket size:        64 -        64 (first        64)
 8(10006) hash =  16 fragments no.:     7, unused:     0
                 bucket size:       128 -       128 (first       128)
 8(10006) hash =  24 fragments no.:     5, unused:     0
                 bucket size:       192 -       192 (first       192)
 8(10006) hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    948624)
 8(10006) TOTAL:     15 free fragments = 950552 free bytes
 8(10006) -----------------------------
 3(10001) INFO: signal 15 received
 3(10001) Memory status (pkg):
 3(10001) fm_status (0x8140260):
 3(10001)  heap size= 1048576
 3(10001)  used= 29040, used+overhead=48792, free=999784
 3(10001)  max used (+overhead)= 52632
 3(10001) dumping free list:
 3(10001) hash =   1 fragments no.:     3, unused:     0
                 bucket size:         8 -         8 (first         8)
 3(10001) hash =   2 fragments no.:     6, unused:     0
                 bucket size:        16 -        16 (first        16)
 3(10001) hash =   3 fragments no.:     3, unused:     0
                 bucket size:        24 -        24 (first        24)
 3(10001) hash =   4 fragments no.:    21, unused:     0
                 bucket size:        32 -        32 (first        32)
 3(10001) hash =   5 fragments no.:    19, unused:     0
                 bucket size:        40 -        40 (first        40)
 3(10001) hash =   6 fragments no.:     6, unused:     0
                 bucket size:        48 -        48 (first        48)
 3(10001) hash =   8 fragments no.:     1, unused:     0
                 bucket size:        64 -        64 (first        64)
 3(10001) hash =   9 fragments no.:     1, unused:     0
                 bucket size:        72 -        72 (first        72)
 3(10001) hash =  15 fragments no.:     1, unused:     0
                 bucket size:       120 -       120 (first       120)
 3(10001) hash =  16 fragments no.:     1, unused:     0
                 bucket size:       128 -       128 (first       128)
 3(10001) hash =  44 fragments no.:     1, unused:     0
                 bucket size:       352 -       352 (first       352)
 3(10001) hash =  83 fragments no.:     1, unused:     0
                 bucket size:       664 -       664 (first       664)
 3(10001) hash =  94 fragments no.:     1, unused:     0
                 bucket size:       752 -       752 (first       752)
 3(10001) hash =  99 fragments no.:     1, unused:     0
                 bucket size:       792 -       792 (first       792)
 3(10001) hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    994928)
 3(10001) TOTAL:     67 free fragments = 999784 free bytes
 3(10001) -----------------------------
 0(9995) XLOG: destroy module ...
 0(9995) pool_remove: Removing connection from the pool
 0(9995) DEBUG: tm_shutdown : start
 0(9995) DEBUG: unlink_timer_lists : emptying DELETE list
 0(9995) DEBUG: tm_shutdown : emptying hash table
 0(9995) DEBUG: tm_shutdown : releasing timers
 0(9995) DEBUG: tm_shutdown : removing semaphores
 0(9995) DEBUG: tm_shutdown : destroying tmcb lists
 0(9995) DEBUG: tm_shutdown : done
 0(9995) destroy_tls: Entered
 0(9995) Memory status (pkg):
 0(9995) fm_status (0x8140260):
 0(9995)  heap size= 1048576
 0(9995)  used= 18720, used+overhead=38008, free=1010568
 0(9995)  max used (+overhead)= 48512
 0(9995) dumping free list:
 0(9995) hash =   1 fragments no.:     6, unused:     0
                 bucket size:         8 -         8 (first         8)
 0(9995) hash =   2 fragments no.:    42, unused:     0
                 bucket size:        16 -        16 (first        16)
 0(9995) hash =   3 fragments no.:     4, unused:     0
                 bucket size:        24 -        24 (first        24)
 0(9995) hash =   4 fragments no.:     2, unused:     0
                 bucket size:        32 -        32 (first        32)
 0(9995) hash =   5 fragments no.:     1, unused:     0
                 bucket size:        40 -        40 (first        40)
 0(9995) hash =  16 fragments no.:     8, unused:     0
                 bucket size:       128 -       128 (first       128)
 0(9995) hash =  24 fragments no.:     5, unused:     0
                 bucket size:       192 -       192 (first       192)
 0(9995) hash = 232 fragments no.:     1, unused:     0
                 bucket size:      1856 -      1856 (first      1856)
 0(9995) hash = 800 fragments no.:     1, unused:     0
                 bucket size:      6400 -      6400 (first      6400)
 0(9995) hash = 2054 fragments no.:     1, unused:     0
                 bucket size:    524288 -   1048576 (first    999408)
 0(9995) TOTAL:     71 free fragments = 1010568 free bytes
 0(9995) -----------------------------
 0(9995) Memory status (shm):
 0(9995) fm_status (0xb5f87000):
 0(9995)  heap size= 33554432
 0(9995)  used= 88, used+overhead=17808, free=33536624
 0(9995)  max used (+overhead)= 1629992
 0(9995) dumping free list:
 0(9995) hash =   0 fragments no.:     5, unused:     0
                 bucket size:         0 -         0 (first         0)
 0(9995) hash =   1 fragments no.:    47, unused:     0
                 bucket size:         8 -         8 (first         8)
 0(9995) hash =   2 fragments no.:     8, unused:     0
                 bucket size:        16 -        16 (first        16)
 0(9995) hash =   3 fragments no.:     5, unused:     0
                 bucket size:        24 -        24 (first        24)
 0(9995) hash =   4 fragments no.:    40, unused:     0
                 bucket size:        32 -        32 (first        32)
 0(9995) hash =   5 fragments no.:     9, unused:     0
                 bucket size:        40 -        40 (first        40)
 0(9995) hash =   6 fragments no.:     4, unused:     0
                 bucket size:        48 -        48 (first        48)
 0(9995) hash =   7 fragments no.:     1, unused:     0
                 bucket size:        56 -        56 (first        56)
 0(9995) hash =   8 fragments no.:     1, unused:     0
                 bucket size:        64 -        64 (first        64)
 0(9995) hash =  11 fragments no.:     5, unused:     0
                 bucket size:        88 -        88 (first        88)
 0(9995) hash =  13 fragments no.:     1, unused:     0
                 bucket size:       104 -       104 (first       104)
 0(9995) hash =  38 fragments no.:     1, unused:     0
                 bucket size:       304 -       304 (first       304)
 0(9995) hash =  40 fragments no.:     1, unused:     0
                 bucket size:       320 -       320 (first       320)
 0(9995) hash =  49 fragments no.:     1, unused:     0
                 bucket size:       392 -       392 (first       392)
 0(9995) hash =  94 fragments no.:     1, unused:     0
                 bucket size:       752 -       752 (first       752)
 0(9995) hash = 130 fragments no.:     1, unused:     0
                 bucket size:      1040 -      1040 (first      1040)
 0(9995) hash = 167 fragments no.:     1, unused:     0
                 bucket size:      1336 -      1336 (first      1336)
 0(9995) hash = 210 fragments no.:     1, unused:     0
                 bucket size:      1680 -      1680 (first      1680)
 0(9995) hash = 354 fragments no.:     1, unused:     0
                 bucket size:      2832 -      2832 (first      2832)
 0(9995) hash = 459 fragments no.:     1, unused:     0
                 bucket size:      3672 -      3672 (first      3672)
 0(9995) hash = 512 fragments no.:     2, unused:     0
                 bucket size:      4096 -      4096 (first      4096)
 0(9995) hash = 1024 fragments no.:     2, unused:     0
                 bucket size:      8192 -      8192 (first      8192)
 0(9995) hash = 2055 fragments no.:     1, unused:     0
                 bucket size:   1048576 -   2097152 (first   1572864)
 0(9995) hash = 2059 fragments no.:     1, unused:     0
                 bucket size:  16777216 -  33554432 (first  31923736)
 0(9995) TOTAL:    141 free fragments = 33536624 free bytes
 0(9995) -----------------------------
 0(9995) shm_mem_destroy
 0(9995) destroying the shared memory lock
 0(9995) terminating due to SIGCHLD






More information about the Users mailing list