Scenario: I have two test phones setup to a SER server. The two phones are 192.168.2.133 and 192.168.2.101. My server is 192.168.2.1. I can call from .101 to .133 fine. When I try to place a call from .133 this is what I get.
0(2734) SIP Request: 0(2734) method: <INVITE> 0(2734) uri: sip:1001@192.168.2.1 0(2734) version: <SIP/2.0> 0(2734) parse_headers: flags=1 0(2734) Found param type 232, <branch> = <z9hG4bK7e2902f2a>; state=16 0(2734) end of header reached, state=5 0(2734) parse_headers: Via found, flags=1 0(2734) parse_headers: this is the first via 0(2734) After parse_msg... 0(2734) preparing to run routing scripts... 0(2734) parse_headers: flags=128 0(2734) DEBUG:maxfwd:is_maxfwd_present: value = 70 0(2734) DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16 0(2734) parse_headers: flags=8 0(2734) DEBUG: get_hdr_body : content_length=586 0(2734) end of header reached, state=9 0(2734) DEBUG: get_hdr_field: <To> [29]; uri=[sip:1001@192.168.2.1] 0(2734) DEBUG: to body [1001 sip:1001@192.168.2.1 ] 0(2734) DEBUG: add_param: tag=4d4e374f5ebe6ab 0(2734) end of header reached, state=29 0(2734) parse_headers: flags=256 0(2734) get_hdr_field: cseq <CSeq>: <1338505295> <INVITE> 0(2734) is_preloaded: Yes 0(2734) grep_sock_info - checking if host==us: 13==13 && [192.168.2.136] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) after_loose: Topmost route URI: 'sip:192.168.2.136:5060;lr' is me 0(2734) parse_headers: flags=256 0(2734) found end of header 0(2734) find_next_route: No next Route HF found 0(2734) after_loose: No next URI found 0(2734) grep_sock_info - checking if host==us: 11==13 && [192.168.2.1] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) grep_sock_info - checking if host==us: 11==13 && [192.168.2.1] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) check_self: host != me 0(2734) DEBUG: t_newtran: msg id=45 , global msg id=43 , T on entrance=0xffffffff 0(2734) parse_headers: flags=-1 0(2734) parse_headers: flags=60 0(2734) t_lookup_request: start searching: hash=15747, isACK=0 0(2734) DEBUG: RFC3261 transaction matching failed 0(2734) DEBUG: t_lookup_request: no transaction found 0(2734) SER: new INVITE 0(2734) parse_headers: flags=-1 0(2734) check_via_address(192.168.2.133, 192.168.2.133, 0) 0(2734) WARNING:vqm_resize: resize(0) called 0(2734) DEBUG: reply sent out. buf=0x8104e98: SIP/2.0 1..., shmem=0xb6145728: SIP/2.0 1 0(2734) DEBUG: _reply_light: finished 0(2734) DEBUG: mk_proxy: doing DNS lookup... 0(2734) check_via_address(192.168.2.133, 192.168.2.133, 0) 0(2734) DEBUG: add_to_tail_of_timer[4]: 0xb6143eb8 0(2734) DEBUG: add_to_tail_of_timer[0]: 0xb6143ec8 0(2734) SER: new transaction fwd'ed 0(2734) DEBUG:destroy_avp_list: destroying list (nil) 0(2734) receive_msg: cleaning up 1(2737) DEBUG: timer routine:4,tl=0xb6143eb8 next=(nil) 1(2737) DEBUG: retransmission_handler : request resending (t=0xb6143da0, INVITE si ... ) 1(2737) DEBUG: add_to_tail_of_timer[5]: 0xb6143eb8 1(2737) DEBUG: retransmission_handler : done 0(2734) SIP Request: 0(2734) method: <CANCEL> 0(2734) uri: sip:1001@192.168.2.1 0(2734) version: <SIP/2.0> 0(2734) parse_headers: flags=1 0(2734) Found param type 232, <branch> = <z9hG4bK7e2902f2a>; state=16 0(2734) end of header reached, state=5 0(2734) parse_headers: Via found, flags=1 0(2734) parse_headers: this is the first via 0(2734) After parse_msg... 0(2734) preparing to run routing scripts... 0(2734) parse_headers: flags=128 0(2734) DEBUG:maxfwd:is_maxfwd_present: value = 70 0(2734) DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16 0(2734) parse_headers: flags=8 0(2734) DEBUG: get_hdr_body : content_length=0 0(2734) end of header reached, state=9 0(2734) DEBUG: get_hdr_field: <To> [29]; uri=[sip:1001@192.168.2.1] 0(2734) DEBUG: to body [1001 sip:1001@192.168.2.1 ] 0(2734) DEBUG: add_param: tag=4d4e374f5ebe6ab 0(2734) end of header reached, state=29 0(2734) parse_headers: flags=256 0(2734) get_hdr_field: cseq <CSeq>: <1338505295> <CANCEL> 0(2734) is_preloaded: Yes 0(2734) grep_sock_info - checking if host==us: 13==13 && [192.168.2.136] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) after_loose: Topmost route URI: 'sip:192.168.2.136:5060;lr' is me 0(2734) parse_headers: flags=256 0(2734) found end of header 0(2734) find_next_route: No next Route HF found 0(2734) after_loose: No next URI found 0(2734) grep_sock_info - checking if host==us: 11==13 && [192.168.2.1] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) grep_sock_info - checking if host==us: 11==13 && [192.168.2.1] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) check_self: host != me 0(2734) DEBUG: t_newtran: msg id=46 , global msg id=45 , T on entrance=0xffffffff
Bill Hissong
For some reason your SER believes that 192.168.2.136 is its IP address, but 192.168.2.1 is not its IP address. My guess: you configured aliases in your config wrong. Second problem: the INVITE seems to contain a Route header with 192.168.136 in it. Why is this header there? Fix the configuration/setup of your phone to remove this "wrong" header.
Nils
On Thursday 21 December 2006 00:12, Bill wrote:
Scenario: I have two test phones setup to a SER server. The two phones are 192.168.2.133 and 192.168.2.101. My server is 192.168.2.1. I can call from .101 to .133 fine. When I try to place a call from .133 this is what I get.
0(2734) SIP Request: 0(2734) method: <INVITE> 0(2734) uri: sip:1001@192.168.2.1 0(2734) version: <SIP/2.0> 0(2734) parse_headers: flags=1 0(2734) Found param type 232, <branch> = <z9hG4bK7e2902f2a>; state=16 0(2734) end of header reached, state=5 0(2734) parse_headers: Via found, flags=1 0(2734) parse_headers: this is the first via 0(2734) After parse_msg... 0(2734) preparing to run routing scripts... 0(2734) parse_headers: flags=128 0(2734) DEBUG:maxfwd:is_maxfwd_present: value = 70 0(2734) DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16 0(2734) parse_headers: flags=8 0(2734) DEBUG: get_hdr_body : content_length=586 0(2734) end of header reached, state=9 0(2734) DEBUG: get_hdr_field: <To> [29]; uri=[sip:1001@192.168.2.1] 0(2734) DEBUG: to body [1001 sip:1001@192.168.2.1 ] 0(2734) DEBUG: add_param: tag=4d4e374f5ebe6ab 0(2734) end of header reached, state=29 0(2734) parse_headers: flags=256 0(2734) get_hdr_field: cseq <CSeq>: <1338505295> <INVITE> 0(2734) is_preloaded: Yes 0(2734) grep_sock_info - checking if host==us: 13==13 && [192.168.2.136] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) after_loose: Topmost route URI: 'sip:192.168.2.136:5060;lr' is me 0(2734) parse_headers: flags=256 0(2734) found end of header 0(2734) find_next_route: No next Route HF found 0(2734) after_loose: No next URI found 0(2734) grep_sock_info - checking if host==us: 11==13 && [192.168.2.1] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) grep_sock_info - checking if host==us: 11==13 && [192.168.2.1] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) check_self: host != me 0(2734) DEBUG: t_newtran: msg id=45 , global msg id=43 , T on entrance=0xffffffff 0(2734) parse_headers: flags=-1 0(2734) parse_headers: flags=60 0(2734) t_lookup_request: start searching: hash=15747, isACK=0 0(2734) DEBUG: RFC3261 transaction matching failed 0(2734) DEBUG: t_lookup_request: no transaction found 0(2734) SER: new INVITE 0(2734) parse_headers: flags=-1 0(2734) check_via_address(192.168.2.133, 192.168.2.133, 0) 0(2734) WARNING:vqm_resize: resize(0) called 0(2734) DEBUG: reply sent out. buf=0x8104e98: SIP/2.0 1..., shmem=0xb6145728: SIP/2.0 1 0(2734) DEBUG: _reply_light: finished 0(2734) DEBUG: mk_proxy: doing DNS lookup... 0(2734) check_via_address(192.168.2.133, 192.168.2.133, 0) 0(2734) DEBUG: add_to_tail_of_timer[4]: 0xb6143eb8 0(2734) DEBUG: add_to_tail_of_timer[0]: 0xb6143ec8 0(2734) SER: new transaction fwd'ed 0(2734) DEBUG:destroy_avp_list: destroying list (nil) 0(2734) receive_msg: cleaning up 1(2737) DEBUG: timer routine:4,tl=0xb6143eb8 next=(nil) 1(2737) DEBUG: retransmission_handler : request resending (t=0xb6143da0, INVITE si ... ) 1(2737) DEBUG: add_to_tail_of_timer[5]: 0xb6143eb8 1(2737) DEBUG: retransmission_handler : done 0(2734) SIP Request: 0(2734) method: <CANCEL> 0(2734) uri: sip:1001@192.168.2.1 0(2734) version: <SIP/2.0> 0(2734) parse_headers: flags=1 0(2734) Found param type 232, <branch> = <z9hG4bK7e2902f2a>; state=16 0(2734) end of header reached, state=5 0(2734) parse_headers: Via found, flags=1 0(2734) parse_headers: this is the first via 0(2734) After parse_msg... 0(2734) preparing to run routing scripts... 0(2734) parse_headers: flags=128 0(2734) DEBUG:maxfwd:is_maxfwd_present: value = 70 0(2734) DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16 0(2734) parse_headers: flags=8 0(2734) DEBUG: get_hdr_body : content_length=0 0(2734) end of header reached, state=9 0(2734) DEBUG: get_hdr_field: <To> [29]; uri=[sip:1001@192.168.2.1] 0(2734) DEBUG: to body [1001 sip:1001@192.168.2.1 ] 0(2734) DEBUG: add_param: tag=4d4e374f5ebe6ab 0(2734) end of header reached, state=29 0(2734) parse_headers: flags=256 0(2734) get_hdr_field: cseq <CSeq>: <1338505295> <CANCEL> 0(2734) is_preloaded: Yes 0(2734) grep_sock_info - checking if host==us: 13==13 && [192.168.2.136] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) after_loose: Topmost route URI: 'sip:192.168.2.136:5060;lr' is me 0(2734) parse_headers: flags=256 0(2734) found end of header 0(2734) find_next_route: No next Route HF found 0(2734) after_loose: No next URI found 0(2734) grep_sock_info - checking if host==us: 11==13 && [192.168.2.1] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) grep_sock_info - checking if host==us: 11==13 && [192.168.2.1] == [192.168.2.136] 0(2734) grep_sock_info - checking if port 5060 matches port 5060 0(2734) check_self: host != me 0(2734) DEBUG: t_newtran: msg id=46 , global msg id=45 , T on entrance=0xffffffff
Bill Hissong
Serusers mailing list Serusers@lists.iptel.org http://lists.iptel.org/mailman/listinfo/serusers
Hi
How does the log level in the module xlog module corresponds to the loglevel parameter defined in the ser.cfg file? Is there any relation?
Best tomasz
Yes, you won't see messages with level higher than debug=<debug> level.
E.g. xlog("L_INFO","INFO"); won't output anything unless debug=3 or higher is set (or ser -ddd executed).
L_ALERT =-3 L_CRIT =-2 L_ERR =-1 - all these are <0 so you will see then anytime (you can't set debug<0) L_WARN =1 L_NOTICE =2 L_INFO =3 L_DBG =4
Note, that only the third letter is used, so you can put xlog("L_D","DEBUG");
Michal
On Fri, 2006-12-22 at 22:35 +0100, TZieleniewski wrote:
Hi
How does the log level in the module xlog module corresponds to the loglevel parameter defined in the ser.cfg file? Is there any relation?
Best tomasz
-
Bill -
Michal Matyska -
Nils Ohlmeier -
TZieleniewski