I'm using latest CVS version of asterisk and I have one problem - I start ser this way:
ser -dddddddddddddddddddddddddd
So when user is calling another user there is INVITE - everything is ok. But when user hang up call is
finished but I don't see BYE... So this way I can't use acc module to calculate call time.
Somebody can help me?
Thanks in advance.
 
 
P.S.
 
root@sip:/var/www/sw#  9(12166) SIP Request:
 9(12166)  method:  <INVITE>
 9(12166)  uri:     <sip:piem@192.168.2.14>
 9(12166)  version: <SIP/2.0>
 9(12166) parse_headers: flags=1
 9(12166) Found param type 235, <rport> = <n/a>; state=6
 9(12166) Found param type 232, <branch> = <z9hG4bK05DA6E2E759C4BFEBA57195FC350EE17>; state=16
 9(12166) end of header reached, state=5
 9(12166) parse_headers: Via found, flags=1
 9(12166) parse_headers: this is the first via
 9(12166) After parse_msg...
 9(12166) preparing to run routing scripts...
 9(12166) parse_headers: flags=128
 9(12166) end of header reached, state=9
 9(12166) DEBUG: get_hdr_field: <To> [25]; uri=[sip:piem@192.168.2.14]
 9(12166) DEBUG: to body [<sip:piem@192.168.2.14>
]
 9(12166) get_hdr_field: cseq <CSeq>: <45242> <INVITE>
 9(12166) DEBUG:maxfwd:is_maxfwd_present: value = 70
 9(12166) DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16
 9(12166) parse_headers: flags=256
 9(12166) DEBUG: get_hdr_body : content_length=295
 9(12166) found end of header
 9(12166) find_first_route(): No Route headers found
 9(12166) loose_route(): There is no Route HF
 9(12166) check_self - checking if host==us: 12==12 &&  [192.168.2.14] == [192.168.2.14]
 9(12166) check_self - checking if port 5060 matches port 5060
 9(12166) rewrite(): Rewriting Request-URI with 'sip:piem@192.168.2.2:5060'
 9(12166) DEBUG: t_newtran: msg id=5 , global msg id=3 , T on entrance=0xffffffff
 9(12166) parse_headers: flags=-1
 9(12166) parse_headers: flags=60
 9(12166) t_lookup_request: start searching: hash=23406, isACK=0
 9(12166) DEBUG: RFC3261 transaction matching failed
 9(12166) DEBUG: t_lookup_request: no transaction found
 9(12166) DEBUG: add_param: tag=4060601702
 9(12166) end of header reached, state=29
 9(12166) DBG: trans=0x4043e0f8, callback type 1, id 0 entered
 9(12166) SER: new INVITE
 9(12166) parse_headers: flags=-1
 9(12166) check_via_address(192.168.2.111, 192.168.2.111, 3)
 9(12166) WARNING:vqm_resize: resize(0) called
 9(12166) DEBUG: reply sent out. buf=0x80ff2a0: SIP/2.0 1..., shmem=0x4043f9f0: SIP/2.0 1
 9(12166) DEBUG: _reply_light: finished
 9(12166) DEBUG: mk_proxy: doing DNS lookup...
 9(12166) check_via_address(192.168.2.111, 192.168.2.111, 3)
 9(12166) DEBUG: add_timer_unsafe[4]: 0x4043e210
 9(12166) DEBUG: add_timer_unsafe[0]: 0x4043e220
 9(12166) SER: new transaction fwd'ed
 9(12166) parse_headers: flags=44
 9(12166) DEBUG:destroy_avp_list: destroying list (nil)
 9(12166) receive_msg: cleaning up
 4(12158) SIP Reply  (status):
 4(12158)  version: <SIP/2.0>
 4(12158)  status:  <100>
 4(12158)  reason:  <Trying>
 4(12158) parse_headers: flags=1
 4(12158) Found param type 232, <branch> = <z9hG4bKe6b5.2905a5f7.0>; state=16
 4(12158) end of header reached, state=5
 4(12158) parse_headers: Via found, flags=1
 4(12158) parse_headers: this is the first via
 4(12158) After parse_msg...
 4(12158) forward_reply: found module tm, passing reply to it
 4(12158) DEBUG: t_check: msg id=2 global id=0 T start=0xffffffff
 4(12158) parse_headers: flags=17
 4(12158) Found param type 235, <rport> = <5060>; state=6
 4(12158) Found param type 232, <branch> = <z9hG4bK05DA6E2E759C4BFEBA57195FC350EE17>; state=16
 4(12158) end of header reached, state=5
 4(12158) parse_headers: Via found, flags=17
 4(12158) parse_headers: this is the second via
 4(12158) DEBUG: add_param: tag=2313100209
 4(12158) end of header reached, state=29
 4(12158) DEBUG: get_hdr_field: <To> [40]; uri=[sip:piem@192.168.2.14]
 4(12158) DEBUG: to body [<sip:piem@192.168.2.14>]
 4(12158) get_hdr_field: cseq <CSeq>: <45242> <INVITE>
 4(12158) parse_headers: flags=4
 4(12158) DEBUG: t_reply_matching: hash 23406 label 2136625298 branch 0
 4(12158) DEBUG: t_reply_matching: reply matched (T=0x4043e0f8)!
 4(12158) DEBUG: t_check: msg id=2 global id=2 T end=0x4043e0f8
 4(12158) DEBUG: reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1)
 4(12158) ->>>>>>>>> T_code=100, new_code=100
 4(12158) DEBUG: relay_reply: branch=0, save=0, relay=-1
 4(12158) DEBUG: add_timer_unsafe[1]: 0x4043e220
 4(12158) DEBUG:destroy_avp_list: destroying list (nil)
 4(12158) receive_msg: cleaning up
 4(12158) SIP Reply  (status):
 4(12158)  version: <SIP/2.0>
 4(12158)  status:  <180>
 4(12158)  reason:  <Ringing>
 4(12158) parse_headers: flags=1
 4(12158) Found param type 232, <branch> = <z9hG4bKe6b5.2905a5f7.0>; state=16
 4(12158) end of header reached, state=5
 4(12158) parse_headers: Via found, flags=1
 4(12158) parse_headers: this is the first via
 4(12158) After parse_msg...
 4(12158) forward_reply: found module tm, passing reply to it
 4(12158) DEBUG: t_check: msg id=3 global id=2 T start=0xffffffff
 4(12158) parse_headers: flags=17
 4(12158) Found param type 235, <rport> = <5060>; state=6
 4(12158) Found param type 232, <branch> = <z9hG4bK05DA6E2E759C4BFEBA57195FC350EE17>; state=16
 4(12158) end of header reached, state=5
 4(12158) parse_headers: Via found, flags=17
 4(12158) parse_headers: this is the second via
 4(12158) DEBUG: add_param: tag=2313100209
 4(12158) end of header reached, state=29
 4(12158) DEBUG: get_hdr_field: <To> [40]; uri=[sip:piem@192.168.2.14]
 4(12158) DEBUG: to body [<sip:piem@192.168.2.14>]
 4(12158) get_hdr_field: cseq <CSeq>: <45242> <INVITE>
 4(12158) parse_headers: flags=4
 4(12158) DEBUG: t_reply_matching: hash 23406 label 2136625298 branch 0
 4(12158) DEBUG: t_reply_matching: reply matched (T=0x4043e0f8)!
 4(12158) DEBUG: t_check: msg id=3 global id=3 T end=0x4043e0f8
 4(12158) DEBUG: reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1)
 4(12158) ->>>>>>>>> T_code=100, new_code=180
 4(12158) DEBUG: relay_reply: branch=0, save=0, relay=0
 4(12158)  old size: 438, new size: 377
 4(12158) build_res_from_sip_res: copied size: orig:82, new: 21, rest: 356 msg=
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.2.111:5060;rport=5060;branch=z9hG4bK05DA6E2E759C4BFEBA57195FC350EE17
From: pi <sip:pi@192.168.2.14>;tag=4060601702
To: <sip:piem@192.168.2.14>;tag=2313100209
Contact: <sip:piem@192.168.2.2:5060>
Call-ID: B6387609-0B3E-4F5E-A9C2-BFFF87EF4F86@192.168.2.111
CSeq: 45242 INVITE
Server: X-Lite release 1103m
Content-Length: 0
 

 4(12158) DEBUG: reply relayed. buf=0x80ff088: SIP/2.0 1..., shmem=0x4043f410: SIP/2.0 1
 4(12158) DEBUG: add_timer_unsafe[1]: 0x4043e220
 4(12158) DEBUG:destroy_avp_list: destroying list (nil)
 4(12158) receive_msg: cleaning up
10(12171) DEBUG: timer routine:4,tl=0x4043e210 next=(nil)
 8(12165) SIP Reply  (status):
 8(12165)  version: <SIP/2.0>
 8(12165)  status:  <200>
 8(12165)  reason:  <Ok>
 8(12165) parse_headers: flags=1
 8(12165) Found param type 232, <branch> = <z9hG4bKe6b5.2905a5f7.0>; state=16
 8(12165) end of header reached, state=5
 8(12165) parse_headers: Via found, flags=1
 8(12165) parse_headers: this is the first via
 8(12165) After parse_msg...
 8(12165) forward_reply: found module tm, passing reply to it
 8(12165) DEBUG: t_check: msg id=4 global id=0 T start=0xffffffff
 8(12165) parse_headers: flags=17
 8(12165) Found param type 235, <rport> = <5060>; state=6
 8(12165) Found param type 232, <branch> = <z9hG4bK05DA6E2E759C4BFEBA57195FC350EE17>; state=16
 8(12165) end of header reached, state=5
 8(12165) parse_headers: Via found, flags=17
 8(12165) parse_headers: this is the second via
 8(12165) DEBUG: add_param: tag=2313100209
 8(12165) end of header reached, state=29
 8(12165) DEBUG: get_hdr_field: <To> [40]; uri=[sip:piem@192.168.2.14]
 8(12165) DEBUG: to body [<sip:piem@192.168.2.14>]
 8(12165) get_hdr_field: cseq <CSeq>: <45242> <INVITE>
 8(12165) parse_headers: flags=4
 8(12165) DEBUG: t_reply_matching: hash 23406 label 2136625298 branch 0
 8(12165) DEBUG: t_reply_matching: reply matched (T=0x4043e0f8)!
 8(12165) parse_headers: flags=4
 8(12165) DEBUG: t_check: msg id=4 global id=4 T end=0x4043e0f8
 8(12165) DEBUG: reply_received: org. status uas=180, uac[0]=180 local=0 is_invite=1)
 8(12165) ->>>>>>>>> T_code=180, new_code=200
 8(12165) DEBUG: relay_reply: branch=0, save=0, relay=0
 8(12165)  old size: 735, new size: 674
 8(12165) build_res_from_sip_res: copied size: orig:77, new: 16, rest: 658 msg=
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 192.168.2.111:5060;rport=5060;branch=z9hG4bK05DA6E2E759C4BFEBA57195FC350EE17
From: pi <sip:pi@192.168.2.14>;tag=4060601702
To: <sip:piem@192.168.2.14>;tag=2313100209
Contact: <sip:piem@192.168.2.2:5060>
Call-ID: B6387609-0B3E-4F5E-A9C2-BFFF87EF4F86@192.168.2.111
CSeq: 45242 INVITE
Content-Type: application/sdp
Server: X-Lite release 1103m
Content-Length: 269
 
v=0
o=piem 101970734 101978031 IN IP4 192.168.2.2
s=X-Lite
c=IN IP4 192.168.2.2
t=0 0
m=audio 8000 RTP/AVP 8 3 98 97 101
a=rtpmap:8 pcma/8000
a=rtpmap:3 gsm/8000
a=rtpmap:98 iLBC/8000
a=rtpmap:97 speex/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
 
 8(12165) DEBUG: update_totag_set: new totag
 8(12165) DEBUG: reply relayed. buf=0x80ff110: SIP/2.0 2..., shmem=0x4043f410: SIP/2.0 2
 8(12165) DEBUG: cleanup_uac_timers: RETR/FR timers reset
 8(12165) DEBUG: add_timer_unsafe[2]: 0x4043e140
 8(12165) DEBUG:destroy_avp_list: destroying list (nil)
 8(12165) receive_msg: cleaning up
10(12171) DEBUG: timer routine:1,tl=0x4043e220 next=(nil)
10(12171) DEBUG: timer routine:2,tl=0x4043e140 next=(nil)
10(12171) DEBUG: wait_handler : removing 0x4043e0f8 from table
10(12171) DEBUG: delete transaction 0x4043e0f8
10(12171) DEBUG: wait_handler : done