Hi,
I do have four domain aliases for my openser server (clip of config below). Each alias should be handled by same server. I register three clients to the server
Client 1 = client1@isp1v.test.com Client 2 = client2@isp1.test.com Client 3 = client3@isp1.test.com
When calling from Client1 to Client2 (INVITE From URI: client1@isp1v.test.com To URI: client2@isp1.test.com) I get error 404 not found. But if I call from Client 3 to Client 2 the call is working nicely.
I am mainly using the basic OpenSER configuration with minor changes and it seems that the save("location") is saving the registration ok, but lookup("location") won't find what ever it is trying to find when calling from Client1 to Client2.
Any ideas, pointers or propably example openser configuration to handle this kind of configuration properly ?
Thank you many times, -Mika
-- clip --- debug=3 # debug level (cmd line: -dddddddddd) fork=yes log_stderror=no # (cmd line: -E) listen=193.65.64.130
#fork=no #log_stderror=yes
check_via=no # (cmd. line: -v) dns=no # (cmd. line: -r) rev_dns=no # (cmd. line: -R) port=5060 children=4 fifo="/tmp/openser_fifo" alias="isp1.test.com" alias="isp1v.test.com" alias="isp1s.test.com" alias="sip.isp1.test.com"
You're using uslroc module with use_domain set to 1. This means that lookup() will look for entries with same username AND domain. Since client 1 and client2|3 are in different domains, they can't communicate using just the username. Eihter set use_domain to 0 or add some trick in the config to enable users from different domains callling each other.
Samuel.
2006/5/18, mika.saari@wipsl.com mika.saari@wipsl.com:
Hi,
I do have four domain aliases for my openser server (clip of config below). Each alias should be handled by same server. I register three clients to the server
Client 1 = client1@isp1v.test.com Client 2 = client2@isp1.test.com Client 3 = client3@isp1.test.com
When calling from Client1 to Client2 (INVITE From URI: client1@isp1v.test.com To URI: client2@isp1.test.com) I get error 404 not found. But if I call from Client 3 to Client 2 the call is working nicely.
I am mainly using the basic OpenSER configuration with minor changes and it seems that the save("location") is saving the registration ok, but lookup("location") won't find what ever it is trying to find when calling from Client1 to Client2.
Any ideas, pointers or propably example openser configuration to handle this kind of configuration properly ?
Thank you many times, -Mika
-- clip --- debug=3 # debug level (cmd line: -dddddddddd) fork=yes log_stderror=no # (cmd line: -E) listen=193.65.64.130
#fork=no #log_stderror=yes
check_via=no # (cmd. line: -v) dns=no # (cmd. line: -r) rev_dns=no # (cmd. line: -R) port=5060 children=4 fifo="/tmp/openser_fifo" alias="isp1.test.com" alias="isp1v.test.com" alias="isp1s.test.com" alias="sip.isp1.test.com"
Users mailing list Users@openser.org http://openser.org/cgi-bin/mailman/listinfo/users
Hi,
I verified that I do have use_domain set to 0. Also configured the MySQL as a test to see that there isn't domains in the database saved. But this error still occurs. The most weird part is that I can not call from client1@isp1s.test.com to client2@isp1.test.com but other way around I can do the call.
I enclose the debug from the OpenSER when the client1 registers and tries to invite the client2. Any ideas what should I do ?
Thank you very much, - Mika
---------------- CLIP ------------------------ 6(8583) Binding 'client2','sip:client2@193.65.64.185:2051;line=210u03g0' has expired 5(8582) SIP Request: 5(8582) method: <REGISTER> 5(8582) uri: sip:isp1s.test.com 5(8582) version: <SIP/2.0> 5(8582) parse_headers: flags=2 5(8582) Found param type 232, <branch> = <z9hG4bK6s370o22rlhc6ucg0p088k5>; state=6 5(8582) Found param type 235, <rport> = <n/a>; state=17 5(8582) end of header reached, state=5 5(8582) parse_headers: Via found, flags=2 5(8582) parse_headers: this is the first via 5(8582) After parse_msg... 5(8582) preparing to run routing scripts... 5(8582) parse_headers: flags=10 5(8582) DEBUG: add_param: tag=ssln0o71iphc79uj0p08 5(8582) DEBUG:parse_to:end of header reached, state=29 5(8582) parse_headers: flags=8 5(8582) DEBUG:parse_to:end of header reached, state=9 5(8582) DEBUG: get_hdr_field: <To> [30]; uri=[sip:client1@isp1s.test.com] 5(8582) DEBUG: to body [sip:client1@isp1s.test.com ] 5(8582) SIP: method [REGISTER] from [sip:client1@isp1s.test.com] to [sip:client1@isp1s.test.com] 5(8582) parse_headers: flags=100 5(8582) get_hdr_field: cseq <CSeq>: <1293> <REGISTER> 5(8582) DEBUG:maxfwd:is_maxfwd_present: value = 70 5(8582) parse_headers: flags=200 5(8582) DEBUG: get_hdr_body : content_length=0 5(8582) found end of header 5(8582) find_first_route: No Route headers found 5(8582) loose_route: There is no Route HF 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) parse_headers: flags=4000 5(8582) pre_auth(): Credentials with given realm not found 5(8582) build_auth_hf(): 'WWW-Authenticate: Digest realm="isp1.test.com", nonce="44517dbd5eb9b101082bbfd0bb0ffe43b724d2a8" ' 5(8582) parse_headers: flags=ffffffffffffffff 5(8582) check_via_address(193.65.64.188, 193.65.64.188, 0) 5(8582) DEBUG:destroy_avp_list: destroying list (nil) 5(8582) receive_msg: cleaning up 2(8574) SIP Request: 2(8574) method: <REGISTER> 2(8574) uri: sip:isp1s.test.com 2(8574) version: <SIP/2.0> 2(8574) parse_headers: flags=2 2(8574) Found param type 232, <branch> = <z9hG4bKf8u0p28ch5rd4u77e1g5bo3>; state=6 2(8574) Found param type 235, <rport> = <n/a>; state=17 2(8574) end of header reached, state=5 2(8574) parse_headers: Via found, flags=2 2(8574) parse_headers: this is the first via 2(8574) After parse_msg... 2(8574) preparing to run routing scripts... 2(8574) parse_headers: flags=10 2(8574) DEBUG: add_param: tag=ssln0o71iphc79uj0p08 2(8574) DEBUG:parse_to:end of header reached, state=29 2(8574) parse_headers: flags=8 2(8574) DEBUG:parse_to:end of header reached, state=9 2(8574) DEBUG: get_hdr_field: <To> [30]; uri=[sip:client1@isp1s.test.com] 2(8574) DEBUG: to body [sip:client1@isp1s.test.com ] 2(8574) SIP: method [REGISTER] from [sip:client1@isp1s.test.com] to [sip:client1@isp1s.test.com] 2(8574) parse_headers: flags=100 2(8574) get_hdr_field: cseq <CSeq>: <1294> <REGISTER> 2(8574) DEBUG:maxfwd:is_maxfwd_present: value = 70 2(8574) parse_headers: flags=200 2(8574) DEBUG: get_hdr_body : content_length=0 2(8574) found end of header 2(8574) find_first_route: No Route headers found 2(8574) loose_route: There is no Route HF 2(8574) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 2(8574) grep_sock_info - checking if port 5060 matches port 5060 2(8574) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 2(8574) grep_sock_info - checking if port 5060 matches port 5060 2(8574) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 2(8574) grep_sock_info - checking if port 5060 matches port 5060 2(8574) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 2(8574) grep_sock_info - checking if port 5060 matches port 5060 2(8574) check_nonce(): comparing [44517dbd5eb9b101082bbfd0bb0ffe43b724d2a8] and [44517dbd5eb9b101082bbfd0bb0ffe43b724d2a8] 2(8574) DEBUG:auth_radius:radius_authorize_sterman: Success 2(8574) DEBUG:auth_radius:generate_avps: getting SIP AVPs from avpair 225 2(8574) parse_headers: flags=ffffffffffffffff 2(8574) parse_headers: flags=8000000 2(8574) parse_headers: flags=ffffffffffffffff 2(8574) build_contact(): Created Contact HF: Contact: sip:client1@193.65.64.188;expires=3600
2(8574) parse_headers: flags=ffffffffffffffff 2(8574) check_via_address(193.65.64.188, 193.65.64.188, 0) 2(8574) Returned [1] 2(8574) DEBUG:destroy_avp_list: destroying list (nil) 2(8574) receive_msg: cleaning up 5(8582) SIP Request: 5(8582) method: <INVITE> 5(8582) uri: sip:isp1s.test.com 5(8582) version: <SIP/2.0> 5(8582) parse_headers: flags=2 5(8582) Found param type 232, <branch> = <z9hG4bK0rtn0o1t1lhc6h4o2galqfs>; state=6 5(8582) Found param type 235, <rport> = <n/a>; state=17 5(8582) end of header reached, state=5 5(8582) parse_headers: Via found, flags=2 5(8582) parse_headers: this is the first via 5(8582) After parse_msg... 5(8582) preparing to run routing scripts... 5(8582) parse_headers: flags=10 5(8582) DEBUG: add_param: tag=cqcn0o0gbhhc7p9j2gal 5(8582) DEBUG:parse_to:end of header reached, state=29 5(8582) parse_headers: flags=8 5(8582) DEBUG:parse_to:end of header reached, state=9 5(8582) DEBUG: get_hdr_field: <To> [31]; uri=[sip:client2p@isp1.test.com] 5(8582) DEBUG: to body [sip:client2p@isp1.test.com ] 5(8582) SIP: method [INVITE] from [sip:client1@isp1s.test.com] to [sip:client2p@isp1.test.com] 5(8582) parse_headers: flags=100 5(8582) get_hdr_field: cseq <CSeq>: <1294> <INVITE> 5(8582) DEBUG:maxfwd:is_maxfwd_present: value = 70 5(8582) parse_headers: flags=200 5(8582) is_preloaded: Yes 5(8582) grep_sock_info - checking if host==us: 14==13 && [isp1.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 14==13 && [isp1.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) after_loose: Topmost route URI: 'sip:client2p@isp1.test.com' is me 5(8582) parse_headers: flags=200 5(8582) DEBUG: get_hdr_body : content_length=332 5(8582) found end of header 5(8582) find_next_route: No next Route HF found 5(8582) after_loose: No next URI found 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) lookup(): '' Not found in usrloc 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) lookup(): '' Not found in usrloc 5(8582) parse_headers: flags=ffffffffffffffff 5(8582) check_via_address(193.65.64.188, 193.65.64.188, 0) 5(8582) DEBUG:destroy_avp_list: destroying list (nil) 5(8582) receive_msg: cleaning up 2(8574) SIP Request: 2(8574) method: <ACK> 2(8574) uri: sip:isp1s.test.com 2(8574) version: <SIP/2.0> 2(8574) parse_headers: flags=2 2(8574) Found param type 232, <branch> = <z9hG4bK0rtn0o1t1lhc6h4o2galqfs>; state=6 2(8574) Found param type 235, <rport> = <n/a>; state=17 2(8574) end of header reached, state=5 2(8574) parse_headers: Via found, flags=2 2(8574) parse_headers: this is the first via 2(8574) After parse_msg... 2(8574) preparing to run routing scripts... 2(8574) parse_headers: flags=8 2(8574) DEBUG: add_param: tag=ead6a47b01fda88c7548438d3d23c061.1ce2 2(8574) DEBUG:parse_to:end of header reached, state=29 2(8574) DEBUG: get_hdr_field: <To> [73]; uri=[sip:client2p@isp1.test.com] 2(8574) DEBUG: to body [sip:client2p@isp1.test.com] 2(8574) DEBUG: sl_filter_ACK : local ACK found -> dropping it! 2(8574) DEBUG:destroy_avp_list: destroying list (nil) 2(8574) receive_msg: cleaning up
------------------- CLIP ----------------------------
You're using uslroc module with use_domain set to 1. This means that lookup() will look for entries with same username AND domain. Since client 1 and client2|3 are in different domains, they can't communicate using just the username. Eihter set use_domain to 0 or add some trick in the config to enable users from different domains callling each other.
In your logs I just see how client1 registers and how you are trying to call client2 but the log stops in the challenge....so I can not say much from the logs you sent.
Send the registration of the user that you can not call to and the full session initiation mesages.
Samuel. 2006/5/22, mika.saari@wipsl.com mika.saari@wipsl.com:
Hi,
I verified that I do have use_domain set to 0. Also configured the MySQL as a test to see that there isn't domains in the database saved. But this error still occurs. The most weird part is that I can not call from client1@isp1s.test.com to client2@isp1.test.com but other way around I can do the call.
I enclose the debug from the OpenSER when the client1 registers and tries to invite the client2. Any ideas what should I do ?
Thank you very much, - Mika
---------------- CLIP ------------------------ 6(8583) Binding 'client2','sip:client2@193.65.64.185:2051;line=210u03g0' has expired 5(8582) SIP Request: 5(8582) method: <REGISTER> 5(8582) uri: sip:isp1s.test.com 5(8582) version: <SIP/2.0> 5(8582) parse_headers: flags=2 5(8582) Found param type 232, <branch> = <z9hG4bK6s370o22rlhc6ucg0p088k5>; state=6 5(8582) Found param type 235, <rport> = <n/a>; state=17 5(8582) end of header reached, state=5 5(8582) parse_headers: Via found, flags=2 5(8582) parse_headers: this is the first via 5(8582) After parse_msg... 5(8582) preparing to run routing scripts... 5(8582) parse_headers: flags=10 5(8582) DEBUG: add_param: tag=ssln0o71iphc79uj0p08 5(8582) DEBUG:parse_to:end of header reached, state=29 5(8582) parse_headers: flags=8 5(8582) DEBUG:parse_to:end of header reached, state=9 5(8582) DEBUG: get_hdr_field: <To> [30]; uri=[sip:client1@isp1s.test.com] 5(8582) DEBUG: to body [sip:client1@isp1s.test.com ] 5(8582) SIP: method [REGISTER] from [sip:client1@isp1s.test.com] to [sip:client1@isp1s.test.com] 5(8582) parse_headers: flags=100 5(8582) get_hdr_field: cseq <CSeq>: <1293> <REGISTER> 5(8582) DEBUG:maxfwd:is_maxfwd_present: value = 70 5(8582) parse_headers: flags=200 5(8582) DEBUG: get_hdr_body : content_length=0 5(8582) found end of header 5(8582) find_first_route: No Route headers found 5(8582) loose_route: There is no Route HF 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) parse_headers: flags=4000 5(8582) pre_auth(): Credentials with given realm not found 5(8582) build_auth_hf(): 'WWW-Authenticate: Digest realm="isp1.test.com", nonce="44517dbd5eb9b101082bbfd0bb0ffe43b724d2a8" ' 5(8582) parse_headers: flags=ffffffffffffffff 5(8582) check_via_address(193.65.64.188, 193.65.64.188, 0) 5(8582) DEBUG:destroy_avp_list: destroying list (nil) 5(8582) receive_msg: cleaning up 2(8574) SIP Request: 2(8574) method: <REGISTER> 2(8574) uri: sip:isp1s.test.com 2(8574) version: <SIP/2.0> 2(8574) parse_headers: flags=2 2(8574) Found param type 232, <branch> = <z9hG4bKf8u0p28ch5rd4u77e1g5bo3>; state=6 2(8574) Found param type 235, <rport> = <n/a>; state=17 2(8574) end of header reached, state=5 2(8574) parse_headers: Via found, flags=2 2(8574) parse_headers: this is the first via 2(8574) After parse_msg... 2(8574) preparing to run routing scripts... 2(8574) parse_headers: flags=10 2(8574) DEBUG: add_param: tag=ssln0o71iphc79uj0p08 2(8574) DEBUG:parse_to:end of header reached, state=29 2(8574) parse_headers: flags=8 2(8574) DEBUG:parse_to:end of header reached, state=9 2(8574) DEBUG: get_hdr_field: <To> [30]; uri=[sip:client1@isp1s.test.com] 2(8574) DEBUG: to body [sip:client1@isp1s.test.com ] 2(8574) SIP: method [REGISTER] from [sip:client1@isp1s.test.com] to [sip:client1@isp1s.test.com] 2(8574) parse_headers: flags=100 2(8574) get_hdr_field: cseq <CSeq>: <1294> <REGISTER> 2(8574) DEBUG:maxfwd:is_maxfwd_present: value = 70 2(8574) parse_headers: flags=200 2(8574) DEBUG: get_hdr_body : content_length=0 2(8574) found end of header 2(8574) find_first_route: No Route headers found 2(8574) loose_route: There is no Route HF 2(8574) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 2(8574) grep_sock_info - checking if port 5060 matches port 5060 2(8574) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 2(8574) grep_sock_info - checking if port 5060 matches port 5060 2(8574) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 2(8574) grep_sock_info - checking if port 5060 matches port 5060 2(8574) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 2(8574) grep_sock_info - checking if port 5060 matches port 5060 2(8574) check_nonce(): comparing [44517dbd5eb9b101082bbfd0bb0ffe43b724d2a8] and [44517dbd5eb9b101082bbfd0bb0ffe43b724d2a8] 2(8574) DEBUG:auth_radius:radius_authorize_sterman: Success 2(8574) DEBUG:auth_radius:generate_avps: getting SIP AVPs from avpair 225 2(8574) parse_headers: flags=ffffffffffffffff 2(8574) parse_headers: flags=8000000 2(8574) parse_headers: flags=ffffffffffffffff 2(8574) build_contact(): Created Contact HF: Contact: sip:client1@193.65.64.188;expires=3600
2(8574) parse_headers: flags=ffffffffffffffff 2(8574) check_via_address(193.65.64.188, 193.65.64.188, 0) 2(8574) Returned [1] 2(8574) DEBUG:destroy_avp_list: destroying list (nil) 2(8574) receive_msg: cleaning up 5(8582) SIP Request: 5(8582) method: <INVITE> 5(8582) uri: sip:isp1s.test.com 5(8582) version: <SIP/2.0> 5(8582) parse_headers: flags=2 5(8582) Found param type 232, <branch> = <z9hG4bK0rtn0o1t1lhc6h4o2galqfs>; state=6 5(8582) Found param type 235, <rport> = <n/a>; state=17 5(8582) end of header reached, state=5 5(8582) parse_headers: Via found, flags=2 5(8582) parse_headers: this is the first via 5(8582) After parse_msg... 5(8582) preparing to run routing scripts... 5(8582) parse_headers: flags=10 5(8582) DEBUG: add_param: tag=cqcn0o0gbhhc7p9j2gal 5(8582) DEBUG:parse_to:end of header reached, state=29 5(8582) parse_headers: flags=8 5(8582) DEBUG:parse_to:end of header reached, state=9 5(8582) DEBUG: get_hdr_field: <To> [31]; uri=[sip:client2p@isp1.test.com] 5(8582) DEBUG: to body [sip:client2p@isp1.test.com ] 5(8582) SIP: method [INVITE] from [sip:client1@isp1s.test.com] to [sip:client2p@isp1.test.com] 5(8582) parse_headers: flags=100 5(8582) get_hdr_field: cseq <CSeq>: <1294> <INVITE> 5(8582) DEBUG:maxfwd:is_maxfwd_present: value = 70 5(8582) parse_headers: flags=200 5(8582) is_preloaded: Yes 5(8582) grep_sock_info - checking if host==us: 14==13 && [isp1.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 14==13 && [isp1.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) after_loose: Topmost route URI: 'sip:client2p@isp1.test.com' is me 5(8582) parse_headers: flags=200 5(8582) DEBUG: get_hdr_body : content_length=332 5(8582) found end of header 5(8582) find_next_route: No next Route HF found 5(8582) after_loose: No next URI found 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) lookup(): '' Not found in usrloc 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) grep_sock_info - checking if host==us: 15==13 && [isp1s.test.com] == [193.65.64.130] 5(8582) grep_sock_info - checking if port 5060 matches port 5060 5(8582) lookup(): '' Not found in usrloc 5(8582) parse_headers: flags=ffffffffffffffff 5(8582) check_via_address(193.65.64.188, 193.65.64.188, 0) 5(8582) DEBUG:destroy_avp_list: destroying list (nil) 5(8582) receive_msg: cleaning up 2(8574) SIP Request: 2(8574) method: <ACK> 2(8574) uri: sip:isp1s.test.com 2(8574) version: <SIP/2.0> 2(8574) parse_headers: flags=2 2(8574) Found param type 232, <branch> = <z9hG4bK0rtn0o1t1lhc6h4o2galqfs>; state=6 2(8574) Found param type 235, <rport> = <n/a>; state=17 2(8574) end of header reached, state=5 2(8574) parse_headers: Via found, flags=2 2(8574) parse_headers: this is the first via 2(8574) After parse_msg... 2(8574) preparing to run routing scripts... 2(8574) parse_headers: flags=8 2(8574) DEBUG: add_param: tag=ead6a47b01fda88c7548438d3d23c061.1ce2 2(8574) DEBUG:parse_to:end of header reached, state=29 2(8574) DEBUG: get_hdr_field: <To> [73]; uri=[sip:client2p@isp1.test.com] 2(8574) DEBUG: to body [sip:client2p@isp1.test.com] 2(8574) DEBUG: sl_filter_ACK : local ACK found -> dropping it! 2(8574) DEBUG:destroy_avp_list: destroying list (nil) 2(8574) receive_msg: cleaning up
------------------- CLIP ----------------------------
You're using uslroc module with use_domain set to 1. This means that lookup() will look for entries with same username AND domain. Since client 1 and client2|3 are in different domains, they can't communicate using just the username. Eihter set use_domain to 0 or add some trick in the config to enable users from different domains callling each other.
Users mailing list Users@openser.org http://openser.org/cgi-bin/mailman/listinfo/users
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@isp1.test.com] 2(10000) DEBUG: to body [sip:client2@isp1.test.com] 2(10000) SIP: method [REGISTER] from [sip:client2@isp1.test.com] to [sip:client2@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@isp1.test.com] 3(10001) DEBUG: to body [sip:client2@isp1.test.com] 3(10001) SIP: method [REGISTER] from [sip:client2@isp1.test.com] to [sip:client2@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@isp1.test.com] 2(10000) DEBUG: to body [sip:client2@isp1.test.com] 2(10000) SIP: method [REGISTER] from [sip:client2@isp1.test.com] to [sip:client2@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@isp1.test.com] 3(10001) DEBUG: to body [sip:client2@isp1.test.com] 3(10001) SIP: method [REGISTER] from [sip:client2@isp1.test.com] to [sip:client2@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@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@isp1v.test.com] 3(10001) DEBUG: to body [sip:client1@isp1v.test.com] 3(10001) SIP: method [REGISTER] from [sip:client1@isp1v.test.com] to [sip:client1@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@isp1v.test.com] 5(10003) DEBUG: to body [sip:client1@isp1v.test.com] 5(10003) SIP: method [REGISTER] from [sip:client1@isp1v.test.com] to [sip:client1@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@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@isp1.test.com] 3(10001) DEBUG: to body [sip:client2@isp1.test.com] 3(10001) SIP: method [INVITE] from [sip:client1@isp1v.test.com] to [sip:client2@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@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@isp1.test.com] 5(10003) DEBUG: to body [sip:client2@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@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@isp1.test.com] 4(10002) DEBUG: to body [sip:client1@isp1.test.com] 4(10002) SIP: method [INVITE] from [sip:client2@isp1.test.com] to [sip:client1@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@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@isp1.test.com] 5(10003) DEBUG: to body [sip:client1@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@isp1.test.com] 4(10002) DEBUG: to body [sip:client1@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@isp1.test.com;tag=t7am8pw33n To: sip:client1@isp1.test.com;tag=875dj3ephm95qdmi3hhuda32odkdc2ap Contact: sip:client1@193.65.64.188 Call-ID: 3c2cd5692e63-6u95t16ssrw2@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@isp1.test.com] 3(10001) DEBUG: to body [sip:client1@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@isp1.test.com;tag=875dj3ephm95qdmi3hhuda32odkdc2ap Contact: sip:client1@193.65.64.188 From: sip:client2@isp1.test.com;tag=t7am8pw33n Call-ID: 3c2cd5692e63-6u95t16ssrw2@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@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@isp1.test.com] 4(10002) DEBUG: to body [sip:client1@isp1.test.com] 4(10002) SIP: method [ACK] from [sip:client2@isp1.test.com] to [sip:client1@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@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@isp1.test.com;tag=t7am8pw33n To: sip:client1@isp1.test.com;tag=875dj3ephm95qdmi3hhuda32odkdc2ap Call-ID: 3c2cd5692e63-6u95t16ssrw2@snom360-000413231BFC CSeq: 1 ACK Max-Forwards: 69 Contact: sip:client2@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@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@isp1.test.com] 3(10001) DEBUG: to body [sip:client1@isp1.test.com] 3(10001) SIP: method [BYE] from [sip:client2@isp1.test.com] to [sip:client1@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@isp1.test.com] 4(10002) DEBUG: to body [sip:client1@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@isp1.test.com;tag=875dj3ephm95qdmi3hhuda32odkdc2ap From: sip:client2@isp1.test.com;tag=t7am8pw33n Call-ID: 3c2cd5692e63-6u95t16ssrw2@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@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
If you look at the INVITE req-URI in both cases, in one case you've got sip:username@domain and in the other you've just got sip:domain and that is why you can't call the other user.
When you try to call client 2, the User Agent (NOKIA?) does not place the userpart in the Req-URI:
3(10001) SIP Request: 3(10001) method: <INVITE> 3(10001) uri: sip:isp1v.test.com 3(10001) version: <SIP/2.0>
And later, when doing lookup, there is no username: 3(10001) lookup(): '' Not found in usrloc ^
If you take a look at the other INVITE, there is userpart: (10002) SIP Request: 4(10002) method: <INVITE> 4(10002) uri: sip:client1@isp1.test.com 4(10002) version: <SIP/2.0> and later the user is found: 4(10002) rewrite_uri: Rewriting Request-URI with 'sip:client1@193.65.64.188'
So, the NOKIA-SIPUA stack that you are using is somehow broken and does not place userpart in the INVITE...maybe try to use numbers instead of letters and see if this behaviour persists... If you exchange roles and register the current snom user in the nokia, and the nokia's in the snom, the behaviour you see will reverse..
Solution: upgrade nokia-sipua, use numbers, or use just snom360..
Hope it helps....
Samuel.
2006/5/22, mika.saari@wipsl.com mika.saari@wipsl.com:
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@isp1.test.com] 2(10000) DEBUG: to body [sip:client2@isp1.test.com] 2(10000) SIP: method [REGISTER] from [sip:client2@isp1.test.com] to [sip:client2@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@isp1.test.com] 3(10001) DEBUG: to body [sip:client2@isp1.test.com] 3(10001) SIP: method [REGISTER] from [sip:client2@isp1.test.com] to [sip:client2@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@isp1.test.com] 2(10000) DEBUG: to body [sip:client2@isp1.test.com] 2(10000) SIP: method [REGISTER] from [sip:client2@isp1.test.com] to [sip:client2@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@isp1.test.com] 3(10001) DEBUG: to body [sip:client2@isp1.test.com] 3(10001) SIP: method [REGISTER] from [sip:client2@isp1.test.com] to [sip:client2@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@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@isp1v.test.com] 3(10001) DEBUG: to body [sip:client1@isp1v.test.com] 3(10001) SIP: method [REGISTER] from [sip:client1@isp1v.test.com] to [sip:client1@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@isp1v.test.com] 5(10003) DEBUG: to body [sip:client1@isp1v.test.com] 5(10003) SIP: method [REGISTER] from [sip:client1@isp1v.test.com] to [sip:client1@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@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@isp1.test.com] 3(10001) DEBUG: to body [sip:client2@isp1.test.com] 3(10001) SIP: method [INVITE] from [sip:client1@isp1v.test.com] to [sip:client2@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@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@isp1.test.com] 5(10003) DEBUG: to body [sip:client2@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@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@isp1.test.com] 4(10002) DEBUG: to body [sip:client1@isp1.test.com] 4(10002) SIP: method [INVITE] from [sip:client2@isp1.test.com] to [sip:client1@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@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@isp1.test.com] 5(10003) DEBUG: to body [sip:client1@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@isp1.test.com] 4(10002) DEBUG: to body [sip:client1@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@isp1.test.com;tag=t7am8pw33n To: sip:client1@isp1.test.com;tag=875dj3ephm95qdmi3hhuda32odkdc2ap Contact: sip:client1@193.65.64.188 Call-ID: 3c2cd5692e63-6u95t16ssrw2@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@isp1.test.com] 3(10001) DEBUG: to body [sip:client1@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@isp1.test.com;tag=875dj3ephm95qdmi3hhuda32odkdc2ap Contact: sip:client1@193.65.64.188 From: sip:client2@isp1.test.com;tag=t7am8pw33n Call-ID: 3c2cd5692e63-6u95t16ssrw2@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@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@isp1.test.com] 4(10002) DEBUG: to body [sip:client1@isp1.test.com] 4(10002) SIP: method [ACK] from [sip:client2@isp1.test.com] to [sip:client1@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@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@isp1.test.com;tag=t7am8pw33n To: sip:client1@isp1.test.com;tag=875dj3ephm95qdmi3hhuda32odkdc2ap Call-ID: 3c2cd5692e63-6u95t16ssrw2@snom360-000413231BFC CSeq: 1 ACK Max-Forwards: 69 Contact: sip:client2@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@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@isp1.test.com] 3(10001) DEBUG: to body [sip:client1@isp1.test.com] 3(10001) SIP: method [BYE] from [sip:client2@isp1.test.com] to [sip:client1@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@isp1.test.com] 4(10002) DEBUG: to body [sip:client1@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@isp1.test.com;tag=875dj3ephm95qdmi3hhuda32odkdc2ap From: sip:client2@isp1.test.com;tag=t7am8pw33n Call-ID: 3c2cd5692e63-6u95t16ssrw2@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@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
Users mailing list Users@openser.org http://openser.org/cgi-bin/mailman/listinfo/users
-
mika.saari＠wipsl.com -
samuel