RE: [Serusers] Click to dial - error 408

-----Original Message----- From: serusers-bounces(a)lists.iptel.org [mailto:serusers-bounces@lists.iptel.org] On Behalf Of Peter Herre Sent: Wednesday, 15 September 2004 6:20 AM To: serusers(a)lists.iptel.org Subject: [Serusers] Click to dial - error 408 Hello serusers, currently I am configuring serweb's click to dial application. Both clients are inside the same private network without any NAT in between. Standard calls between the two clients work well. When I invoke ctd, the SIP phone of the calling party rings. Pick-up of the phone works, I get connected to the referrer, but the connection to the called party fails. See an excerpt of the log file: (Scenario: peter.herre calls helga.herre, i.e. helga.herre is referred by the ctd application's e-mail address &#39;clicktodial(a)inconsult.at&#39;.at'.) 9(13200) fifo_get_method: method: 'REFER' 9(13200) DEBUG: fifo_get_ruri: 'sip:peter.herre@10.49.9.170:5060' 9(13200) DEBUG: fifo_get_nexthop: hop: 'sip:peter.herre@10.49.9.170:5060' 9(13200) fifo_get_headers: headers: To: <sip:peter.herre@inconsult.at>;tag=414750038e741 From: <sip:clicktodial@inconsult.at>;tag=414750038e741 Call-ID: 414750038e741.fifouacctd Contact: <sip:caller@!!> CSeq: 2 REFER Referred-By: <sip:clicktodial@inconsult.at> Refer-To: sip:helga.herre@inconsult.at 9(13200) parse_headers: flags=-1 9(13200) DEBUG: add_param: tag=414750038e741 9(13200) end of header reached, state=29 9(13200) DEBUG: get_hdr_field: <To> [50]; uri=[sip:peter.herre@inconsult.at] 9(13200) DEBUG: to body [<sip:peter.herre@inconsult.at>] 9(13200) get_hdr_field: cseq <CSeq>: <2> <REFER> 9(13200) DEBUG: fifo_uac: parse_headers succeeded 9(13200) fifo_get_body: body: 9(13200) DEBUG: add_param: tag=414750038e741 9(13200) end of header reached, state=29 9(13200) DEBUG: mk_proxy: doing DNS lookup... 9(13200) DEBUG: get_hf_block: one more hf processed 9(13200) DEBUG: get_hf_block: one more hf processed 9(13200) DEBUG: get_hf_block: one more hf processed 9(13200) DEBUG: fifo_uac: EoL -- proceeding to transaction creation 9(13200) DEBUG: mk_proxy: doing DNS lookup... 9(13200) DEBUG: dlg2hash: 49113 9(13200) DEBUG: add_to_tail_of_timer[4]: 0x402e2b58 9(13200) DEBUG: add_to_tail_of_timer[0]: 0x402e2b6c 9(13200) INFO: fifo_server: command empty 10(13212) DEBUG: timer routine:1,tl=0x402e1fb4 next=0x402e09a4 10(13212) DEBUG: timer routine:1,tl=0x402e09a4 next=(nil) 10(13212) DEBUG: timer routine:4,tl=0x402e2b58 next=(nil) 10(13212) DEBUG: retransmission_handler : request resending (t=0x402e2a30, REFER sip ... ) 10(13212) DEBUG: add_to_tail_of_timer[5]: 0x402e2b58 10(13212) DEBUG: retransmission_handler : done 10(13212) DEBUG: timer routine:5,tl=0x402e2b58 next=(nil) Does anybody has a hint what is going wrong? DNS lookup fails?! Currently I have my domain in /etc/hosts. Below find the complete log file of the whole call. Best regards, Peter sip:/usr/local/etc/ser # tail -f /var/log/ser.log 4(13176) udp_rcv_loop: probing packet received from 10.49.9.170 34820 3(13161) udp_rcv_loop: probing packet received from 10.49.8.8 50195 9(13200) fifo_get_method: method: 'INVITE' 9(13200) DEBUG: fifo_get_ruri: 'sip:peter.herre@inconsult.at' 9(13200) DEBUG: fifo_get_nexthop: next hop empty 9(13200) fifo_get_headers: headers: From: <sip:clicktodial@inconsult.at>;tag=414750038e741 Call-ID: 414750038e741.fifouacctd Contact: <sip:caller@!!> To: <sip:peter.herre@inconsult.at> CSeq: 1 INVITE Content-Type: application/sdp 9(13200) parse_headers: flags=-1 9(13200) end of header reached, state=9 9(13200) DEBUG: get_hdr_field: <To> [32]; uri=[sip:peter.herre@inconsult.at] 9(13200) DEBUG: to body [<sip:peter.herre@inconsult.at> ] 9(13200) get_hdr_field: cseq <CSeq>: <1> <INVITE> 9(13200) DEBUG: fifo_uac: parse_headers succeeded 9(13200) fifo_get_body: body: v=0 o=click-to-dial 0 0 IN IP4 0.0.0.0 s=session c=IN IP4 0.0.0.0 b=CT:1000 t=0 0 m=audio 9 RTP/AVP 0 a=rtpmap:0 PCMU/8000 9(13200) DEBUG: add_param: tag=414750038e741 9(13200) end of header reached, state=29 9(13200) DEBUG: mk_proxy: doing DNS lookup... 9(13200) get_record: lookup(_sip._udp.inconsult.at, 33) failed 9(13200) sip_resolvehost: no SRV record found for inconsult.at, trying 'normal' lookup... 9(13200) DEBUG: get_hf_block: one more hf processed 9(13200) DEBUG: get_hf_block: one more hf processed 9(13200) DEBUG: fifo_uac: EoL -- proceeding to transaction creation 9(13200) DEBUG: mk_proxy: doing DNS lookup... 9(13200) get_record: lookup(_sip._udp.inconsult.at, 33) failed 9(13200) sip_resolvehost: no SRV record found for inconsult.at, trying 'normal' lookup... 9(13200) DEBUG: dlg2hash: 49116 9(13200) DEBUG: add_to_tail_of_timer[4]: 0x402e0990 9(13200) DEBUG: add_to_tail_of_timer[0]: 0x402e09a4 9(13200) INFO: fifo_server: command empty 2(13160) SIP Request: 2(13160) method: <INVITE> 2(13160) uri: <sip:peter.herre@inconsult.at> 2(13160) version: <SIP/2.0> 2(13160) parse_headers: flags=1 2(13160) Found param type 232, <branch> = <z9hG4bKcdfb.4a6c0fb3.0>; state=16 2(13160) end of header reached, state=5 2(13160) parse_headers: Via found, flags=1 2(13160) parse_headers: this is the first via 2(13160) After parse_msg... 2(13160) preparing to run routing scripts... 2(13160) ------------------------------------------- 2(13160) entering main loop 2(13160) check_via_address(10.52.0.11, 10.52.0.11, 0) 2(13160) INVITE message received 2(13160) DEBUG : is_maxfwd_present: searching for max_forwards header 2(13160) parse_headers: flags=128 2(13160) end of header reached, state=9 2(13160) DEBUG: get_hdr_field: <To> [32]; uri=[sip:peter.herre@inconsult.at] 2(13160) DEBUG: to body [<sip:peter.herre@inconsult.at> ] 2(13160) get_hdr_field: cseq <CSeq>: <1> <INVITE> 2(13160) DEBUG: get_hdr_body : content_length=131 2(13160) found end of header 2(13160) DEBUG: is_maxfwd_present: max_forwards header not found! 2(13160) parse_headers: flags=256 2(13160) find_first_route(): No Route headers found 2(13160) loose_route(): There is no Route HF 2(13160) check_self - checking if host==us: 12==20 && [inconsult.at] == [sip.int.inconsult.at] 2(13160) check_self - checking if port 5060 matches port 5060 2(13160) check_self - checking if host==us: 12==16 && [inconsult.at] == [sip.inconsult.at] 2(13160) check_self - checking if port 5060 matches port 5060 2(13160) lookup(): 'peter.herre' Not found in usrloc 2(13160) query="select grp from grp where username='peter.herre' AND grp='voicemail'" 2(13160) is_user_in(): User is in group 'voicemail' 2(13160) requested user is in voicemail group 2(13160) rwrite(): Rewriting Request-URI with 'sip:peter.herre@10.49.9.17 0:5060' 2(13160) invite for voicemail user->initiate failureroute[1] 2(13160) ------------------------------------------- 2(13160) entering route[1] - relaying SIP message 2(13160) parse_headers: flags=44 2(13160) DEBUG: add_param: tag=414750038e741 2(13160) end of header reached, state=29 2(13160) relaying message ... 2(13160) DEBUG: t_addifnew: msg id=19 , global msg id=16 , T on entrance=0xffffffff 2(13160) parse_headers: flags=-1 2(13160) parse_headers: flags=60 2(13160) t_lookup_request: start searching: hash=49116, isACK=0 2(13160) DEBUG: RFC3261 transaction matching failed 2(13160) DEBUG: t_lookup_request: no transaction found 2(13160) DBG: callback type 2, id 3 entered 2(13160) parse_headers: flags=44 2(13160) DEBUG: noisy_timer set for accounting 2(13160) SER: new INVITE 2(13160) parse_headers: flags=-1 2(13160) check_via_address(10.52.0.11, 10.52.0.11, 0) 2(13160) WARNING:vqm_resize: resize(0) called 4(13176) SIP Reply (status): 4(13176) version: <SIP/2.0> 4(13176) status: <100> 4(13176) reason: <trying -- your call is important to us> 4(13176) parse_headers: flags=1 4(13176) Found param type 232, <branch> = <z9hG4bKcdfb.4a6c0fb3.0>; state=16 4(13176) end of header reached, state=5 4(13176) parse_headers: Via found, flags=1 4(13176) parse_headers: this is the first via 4(13176) After parse_msg... 4(13176) forward_reply: found module tm, passing reply to it 4(13176) DEBUG: t_check: msg id=18 global id=15 T start=0xffffffff 4(13176) parse_headers: flags=17 4(13176) end of header reached, state=9 4(13176) DEBUG: get_hdr_field: <To> [32]; uri=[sip:peter.herre@inconsult.at] 4(13176) DEBUG: to body [<sip:peter.herre@inconsult.at> ] 4(13176) get_hdr_field: cseq <CSeq>: <1> <INVITE> 4(13176) parse_headers: flags=4 4(13176) DEBUG: t_reply_matching: hash 49116 label 1005635236 branch 0 4(13176) DEBUG: t_reply_matching: reply matched (T=0x402e0868)! 4(13176) DEBUG: t_check: msg id=18 global id=18 T end=0x402e0868 4(13176) DEBUG: t_on_reply: org. status uas=0, uac[0]=0 local=1 is_invite=1) 4(13176) ->>>>>>>>> T_code=0, new_code=100 4(13176) DEBUG: local_reply: branch=0, save=0, winner=-1 4(13176) DEBUG: add_to_tail_of_timer[1]: 0x402e09a4 4(13176) DEBUG:destroy_avp_list: destroing list (nil) 4(13176) receive_msg: cleaning up 2(13160) DEBUG: reply sent out. buf=0x80d1d38: SIP/2.0 1..., shmem=0x402df5b8: SIP/2.0 1 2(13160) DEBUG: t_reply: finished 2(13160) DEBUG: mk_proxy: doing DNS lookup... 2(13160) check_via_address(10.52.0.11, 10.52.0.11, 0) 2(13160) DEBUG: add_to_tail_of_timer[4]: 0x402e1fa0 2(13160) DEBUG: add_to_tail_of_timer[0]: 0x402e1fb4 2(13160) SER: new transaction fwd'ed 2(13160) DEBUG:destroy_avp_list: destroing list (nil) 2(13160) receive_msg: cleaning up 3(13161) SIP Reply (status): 3(13161) version: <SIP/2.0> 3(13161) status: <100> 3(13161) reason: <Trying> 3(13161) parse_headers: flags=1 3(13161) Found param type 232, <branch> = <z9hG4bKcdfb.5a6c0fb3.0>; state=16 3(13161) end of header reached, state=5 3(13161) parse_headers: Via found, flags=1 3(13161) parse_headers: this is the first via 3(13161) After parse_msg... 3(13161) forward_reply: found module tm, passing reply to it 3(13161) DEBUG: t_check: msg id=18 global id=14 T start=0xffffffff 3(13161) parse_headers: flags=17 3(13161) Found param type 232, <branch> = <z9hG4bKcdfb.4a6c0fb3.0>; state=16 3(13161) end of header reached, state=5 3(13161) parse_headers: Via found, flags=17 3(13161) parse_headers: this is the second via 3(13161) DEBUG: add_param: tag=414750038e741 3(13161) end of header reached, state=29 3(13161) DEBUG: get_hdr_field: <To> [50]; uri=[sip:peter.herre@inconsult.at] 3(13161) DEBUG: to body [<sip:peter.herre@inconsult.at>] 3(13161) get_hdr_field: cseq <CSeq>: <1> <INVITE> 3(13161) parse_headers: flags=4 3(13161) DEBUG: t_reply_matching: hash 49116 label 1005635237 branch 0 3(13161) DEBUG: t_reply_matching: reply matched (T=0x402e1e78)! 3(13161) DBG: callback type 1, id 5 entered 3(13161) DEBUG: t_check: msg id=18 global id=18 T end=0x402e1e78 3(13161) DEBUG: t_on_reply: org. status uas=100, uac[0]=0 local=0 is_invite=1) 3(13161) ->>>>>>>>> T_code=100, new_code=100 3(13161) DEBUG: relay_reply: branch=0, save=0, relay=-1 3(13161) DEBUG: add_to_tail_of_timer[1]: 0x402e1fb4 3(13161) DEBUG:destroy_avp_list: destroing list (nil) 3(13161) receive_msg: cleaning up 4(13176) SIP Reply (status): 4(13176) version: <SIP/2.0> 4(13176) status: <180> 4(13176) reason: <Ringing> 4(13176) parse_headers: flags=1 4(13176) Found param type 232, <branch> = <z9hG4bKcdfb.5a6c0fb3.0>; state=16 4(13176) end of header reached, state=5 4(13176) parse_headers: Via found, flags=1 4(13176) parse_headers: this is the first via 4(13176) After parse_msg... 4(13176) forward_reply: found module tm, passing reply to it 4(13176) DEBUG: t_check: msg id=19 global id=18 T start=0xffffffff 4(13176) parse_headers: flags=17 4(13176) Found param type 232, <branch> = <z9hG4bKcdfb.4a6c0fb3.0>; state=16 4(13176) end of header reached, state=5 4(13176) parse_headers: Via found, flags=17 4(13176) parse_headers: this is the second via 4(13176) DEBUG: add_param: tag=414750038e741 4(13176) end of header reached, state=29 4(13176) DEBUG: get_hdr_field: <To> [50]; uri=[sip:peter.herre@inconsult.at] 4(13176) DEBUG: to body [<sip:peter.herre@inconsult.at>] 4(13176) get_hdr_field: cseq <CSeq>: <1> <INVITE> 4(13176) parse_headers: flags=4 4(13176) DEBUG: t_reply_matching: hash 49116 label 1005635237 branch 0 4(13176) DEBUG: t_reply_matching: reply matched (T=0x402e1e78)! 4(13176) DBG: callback type 1, id 5 entered 4(13176) DEBUG: t_check: msg id=19 global id=19 T end=0x402e1e78 4(13176) DEBUG: t_on_reply: org. status uas=100, uac[0]=100 local=0 is_invite=1) 4(13176) ->>>>>>>>> T_code=100, new_code=180 4(13176) DEBUG: relay_reply: branch=0, save=0, relay=0 4(13176) old size: 393, new size: 334 4(13176) build_res_from_sip_res: copied size: orig:80, new: 21, rest: 313 msg= SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.52.0.11;branch=z9hG4bKcdfb.4a6c0fb3.0 From: <sip:clicktodial@inconsult.at>;tag=414750038e741 To: <sip:peter.herre@inconsult.at>;tag=414750038e741 Contact: <sip:peter.herre@10.49.9.170:5060> Call-ID: 414750038e741.fifouacctd CSeq: 1 INVITE Server: X-Lite build 1095 Content-Length: 0 4(13176) DEBUG: reply relayed. buf=0x80d1c10: SIP/2.0 1..., shmem=0x402dfbf0: SIP/2.0 1 4(13176) DBG: callback type 7, id 1 entered 4(13176) DEBUG: add_to_tail_of_timer[1]: 0x402e1fb4 4(13176) DEBUG:destroy_avp_list: destroing list (nil) 4(13176) receive_msg: cleaning up 4(13176) SIP Reply (status): 4(13176) version: <SIP/2.0> 4(13176) status: <180> 4(13176) reason: <Ringing> 4(13176) parse_headers: flags=1 4(13176) Found param type 232, <branch> = <z9hG4bKcdfb.4a6c0fb3.0>; state=16 4(13176) end of header reached, state=5 4(13176) parse_headers: Via found, flags=1 4(13176) parse_headers: this is the first via 4(13176) After parse_msg... 4(13176) forward_reply: found module tm, passing reply to it 4(13176) DEBUG: t_check: msg id=20 global id=19 T start=0xffffffff 4(13176) parse_headers: flags=17 4(13176) DEBUG: add_param: tag=414750038e741 4(13176) end of header reached, state=29 4(13176) DEBUG: get_hdr_field: <To> [50]; uri=[sip:peter.herre@inconsult.at] 4(13176) DEBUG: to body [<sip:peter.herre@inconsult.at>] 4(13176) get_hdr_field: cseq <CSeq>: <1> <INVITE> 4(13176) parse_headers: flags=4 4(13176) DEBUG: t_reply_matching: hash 49116 label 1005635236 branch 0 4(13176) DEBUG: t_reply_matching: reply matched (T=0x402e0868)! 4(13176) DEBUG: t_check: msg id=20 global id=20 T end=0x402e0868 4(13176) DEBUG: t_on_reply: org. status uas=0, uac[0]=100 local=1 is_invite=1) 4(13176) ->>>>>>>>> T_code=0, new_code=180 4(13176) DEBUG: local_reply: branch=0, save=0, winner=0 4(13176) DEBUG: add_to_tail_of_timer[1]: 0x402e09a4 4(13176) DEBUG:destroy_avp_list: destroing list (nil) 4(13176) receive_msg: cleaning up 10(13212) DEBUG: timer routine:4,tl=0x402e0990 next=0x402e1fa0 10(13212) DEBUG: timer routine:4,tl=0x402e1fa0 next=(nil) 3(13161) SIP Reply (status): 3(13161) version: <SIP/2.0> 3(13161) status: <200> 3(13161) reason: <Ok> 3(13161) parse_headers: flags=1 3(13161) Found param type 232, <branch> = <z9hG4bKcdfb.5a6c0fb3.0>; state=16 3(13161) end of header reached, state=5 3(13161) parse_headers: Via found, flags=1 3(13161) parse_headers: this is the first via 3(13161) After parse_msg... 3(13161) forward_reply: found module tm, passing reply to it 3(13161) DEBUG: t_check: msg id=19 global id=18 T start=0xffffffff 3(13161) parse_headers: flags=17 3(13161) Found param type 232, <branch> = <z9hG4bKcdfb.4a6c0fb3.0>; state=16 3(13161) end of header reached, state=5 3(13161) parse_headers: Via found, flags=17 3(13161) parse_headers: this is the second via 3(13161) DEBUG: add_param: tag=414750038e741 3(13161) end of header reached, state=29 3(13161) DEBUG: get_hdr_field: <To> [50]; uri=[sip:peter.herre@inconsult.at] 3(13161) DEBUG: to body [<sip:peter.herre@inconsult.at>] 3(13161) get_hdr_field: cseq <CSeq>: <1> <INVITE> 3(13161) parse_headers: flags=4 3(13161) DEBUG: t_reply_matching: hash 49116 label 1005635237 branch 0 3(13161) DEBUG: t_reply_matching: reply matched (T=0x402e1e78)! 3(13161) parse_headers: flags=4 3(13161) DBG: callback type 1, id 5 entered 3(13161) parse_headers: flags=4 3(13161) DEBUG: t_check: msg id=19 global id=19 T end=0x402e1e78 3(13161) DEBUG: t_on_reply: org. status uas=180, uac[0]=180 local=0 is_invite=1) 3(13161) ->>>>>>>>> T_code=180, new_code=200 3(13161) DEBUG: relay_reply: branch=0, save=0, relay=0 3(13161) old size: 725, new size: 666 3(13161) build_res_from_sip_res: copied size: orig:75, new: 16, rest: 650 msg= SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.52.0.11;branch=z9hG4bKcdfb.4a6c0fb3.0 From: <sip:clicktodial@inconsult.at>;tag=414750038e741 To: <sip:peter.herre@inconsult.at>;tag=414750038e741 Contact: <sip:peter.herre@10.49.9.170:5060> Call-ID: 414750038e741.fifouacctd CSeq: 1 INVITE Content-Type: application/sdp Server: X-Lite build 1095 Content-Length: 304 v=0 o=peter.herre 1042331213 1042331213 IN IP4 10.49.9.170 s=X-Lite c=IN IP4 10.49.9.170 t=0 0 m=audio 8000 RTP/AVP 0 8 3 97 110 101 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:3 gsm/8000 a=rtpmap:97 iLBC/8000 a=rtpmap:110 speex/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 3(13161) DEBUG: update_totag_set: new totag 3(13161) DEBUG: reply relayed. buf=0x80d2408: SIP/2.0 2..., shmem=0x402df5b8: SIP/2.0 2 3(13161) DBG: callback type 7, id 1 entered 3(13161) ACC: transaction answered: method=INVITE, i-uri=sip:peter.herre@inconsult.at, o-uri=sip:peter.herre@10.49.9.17 0:5060, call_id=414750038e741.fifouacctd, from=<sip:clicktodial@inconsult.at>;tag=414750038e741, code=200 3(13161) DEBUG: cleanup_uacs: RETR/FR timers reset 3(13161) DEBUG: add_to_tail_of_timer[2]: 0x402e1ec0 3(13161) DEBUG:destroy_avp_list: destroing list (nil) 3(13161) receive_msg: cleaning up 4(13176) SIP Reply (status): 4(13176) version: <SIP/2.0> 4(13176) status: <200> 4(13176) reason: <Ok> 4(13176) parse_headers: flags=1 4(13176) Found param type 232, <branch> = <z9hG4bKcdfb.4a6c0fb3.0>; state=16 4(13176) end of header reached, state=5 4(13176) parse_headers: Via found, flags=1 4(13176) parse_headers: this is the first via 4(13176) After parse_msg... 4(13176) forward_reply: found module tm, passing reply to it 4(13176) DEBUG: t_check: msg id=21 global id=20 T start=0xffffffff 4(13176) parse_headers: flags=17 4(13176) DEBUG: add_param: tag=414750038e741 4(13176) end of header reached, state=29 4(13176) DEBUG: get_hdr_field: <To> [50]; uri=[sip:peter.herre@inconsult.at] 4(13176) DEBUG: to body [<sip:peter.herre@inconsult.at>] 4(13176) get_hdr_field: cseq <CSeq>: <1> <INVITE> 4(13176) parse_headers: flags=4 4(13176) DEBUG: t_reply_matching: hash 49116 label 1005635236 branch 0 4(13176) DEBUG: t_reply_matching: reply matched (T=0x402e0868)! 4(13176) DEBUG: t_check: msg id=21 global id=21 T end=0x402e0868 4(13176) DEBUG: t_on_reply: org. status uas=180, uac[0]=180 local=1 is_invite=1) 4(13176) parse_headers: flags=-1 4(13176) DEBUG: get_hdr_body : content_length=304 4(13176) found end of header 4(13176) DEBUG: mk_proxy: doing DNS lookup... 4(13176) DEBUG: mk_proxy: doing DNS lookup... 4(13176) ->>>>>>>>> T_code=180, new_code=200 4(13176) DEBUG: local_reply: branch=0, save=0, winner=0 4(13176) DEBUG: update_totag_set: new totag 4(13176) DEBUG: local transaction completed 4(13176) !!!!! ref_counter: 1 4(13176) DEBUG: fifo UAC completed with status 200 4(13176) parse_headers: flags=-1 4(13176) DEBUG: fifo_callback sucesssfuly completed 4(13176) DEBUG: cleanup_uacs: RETR/FR timers reset 4(13176) DEBUG: add_to_tail_of_timer[2]: 0x402e08b0 4(13176) DEBUG:destroy_avp_list: destroing list (nil) 4(13176) receive_msg: cleaning up 9(13200) fifo_get_method: method: 'REFER' 9(13200) DEBUG: fifo_get_ruri: 'sip:peter.herre@10.49.9.170:5060' 9(13200) DEBUG: fifo_get_nexthop: hop: 'sip:peter.herre@10.49.9.170:5060' 9(13200) fifo_get_headers: headers: To: <sip:peter.herre@inconsult.at>;tag=414750038e741 From: <sip:clicktodial@inconsult.at>;tag=414750038e741 Call-ID: 414750038e741.fifouacctd Contact: <sip:caller@!!> CSeq: 2 REFER Referred-By: <sip:clicktodial@inconsult.at> Refer-To: sip:helga.herre@inconsult.at 9(13200) parse_headers: flags=-1 9(13200) DEBUG: add_param: tag=414750038e741 9(13200) end of header reached, state=29 9(13200) DEBUG: get_hdr_field: <To> [50]; uri=[sip:peter.herre@inconsult.at] 9(13200) DEBUG: to body [<sip:peter.herre@inconsult.at>] 9(13200) get_hdr_field: cseq <CSeq>: <2> <REFER> 9(13200) DEBUG: fifo_uac: parse_headers succeeded 9(13200) fifo_get_body: body: 9(13200) DEBUG: add_param: tag=414750038e741 9(13200) end of header reached, state=29 9(13200) DEBUG: mk_proxy: doing DNS lookup... 9(13200) DEBUG: get_hf_block: one more hf processed 9(13200) DEBUG: get_hf_block: one more hf processed 9(13200) DEBUG: get_hf_block: one more hf processed 9(13200) DEBUG: fifo_uac: EoL -- proceeding to transaction creation 9(13200) DEBUG: mk_proxy: doing DNS lookup... 9(13200) DEBUG: dlg2hash: 49113 9(13200) DEBUG: add_to_tail_of_timer[4]: 0x402e2b58 9(13200) DEBUG: add_to_tail_of_timer[0]: 0x402e2b6c 9(13200) INFO: fifo_server: command empty 10(13212) DEBUG: timer routine:1,tl=0x402e1fb4 next=0x402e09a4 10(13212) DEBUG: timer routine:1,tl=0x402e09a4 next=(nil) 10(13212) DEBUG: timer routine:4,tl=0x402e2b58 next=(nil) 10(13212) DEBUG: retransmission_handler : request resending (t=0x402e2a30, REFER sip ... ) 10(13212) DEBUG: add_to_tail_of_timer[5]: 0x402e2b58 10(13212) DEBUG: retransmission_handler : done 10(13212) DEBUG: timer routine:5,tl=0x402e2b58 next=(nil) 10(13212) DEBUG: retransmission_handler : request resending (t=0x402e2a30, REFER sip ... ) 10(13212) DEBUG: add_to_tail_of_timer[6]: 0x402e2b58 10(13212) DEBUG: retransmission_handler : done 4(13176) udp_rcv_loop: probing packet received from 10.49.9.170 34820 1(13158) udp_rcv_loop: probing packet received from 10.49.8.8 50195 10(13212) DEBUG: timer routine:6,tl=0x402e2b58 next=(nil) 10(13212) DEBUG: retransmission_handler : request resending (t=0x402e2a30, REFER sip ... ) 10(13212) DEBUG: add_to_tail_of_timer[7]: 0x402e2b58 10(13212) DEBUG: retransmission_handler : done 10(13212) DEBUG: timer routine:0,tl=0x402e2b6c next=(nil) 10(13212) DEBUG: FR_handler:stop retr. and send CANCEL (0x402e2a30) 10(13212) ->>>>>>>>> T_code=0, new_code=408 10(13212) DBG: callback type 6, id 4 entered 10(13212) DBG: acc: on_missed: no uas.request, local t; skipping 10(13212) DEBUG: local_reply: branch=0, save=0, winner=0 10(13212) DEBUG: local transaction completed 10(13212) !!!!! ref_counter: 0 10(13212) DEBUG: fifo UAC completed with status 408 10(13212) DEBUG: fifo_callback sucesssfuly completed 10(13212) DEBUG: add_to_tail_of_timer[2]: 0x402e2a78 10(13212) DEBUG: final_response_handler : done 10(13212) DEBUG: timer routine:2,tl=0x402e1ec0 next=0x402e08b0 10(13212) DEBUG: wait_handler : removing 0x402e1e78 from table 10(13212) DEBUG: delete transaction 0x402e1e78 10(13212) DEBUG: wait_handler : done 10(13212) DEBUG: timer routine:2,tl=0x402e08b0 next=(nil) 10(13212) DEBUG: wait_handler : removing 0x402e0868 from table 10(13212) DEBUG: delete transaction 0x402e0868 10(13212) DEBUG: wait_handler : done 10(13212) DEBUG: timer routine:7,tl=0x402e2b58 next=(nil) 2(13160) udp_rcv_loop: probing packet received from 10.49.9.170 34820 4(13176) udp_rcv_loop: probing packet received from 10.49.8.8 50195 _______________________________________________ Serusers mailing list serusers(a)lists.iptel.org http://lists.iptel.org/mailman/listinfo/serusers