[Serusers] Voicemail and sems help
Rafael J. Risco G.V
rafael_rgv at yahoo.com
Sat Aug 21 04:20:10 CEST 2004
Hi
You are right, it is not necessary vm in first instance..., now I have a new problem, recently I am receiving this error in sems debug:
[root at gkproxy01 answer_machine]# (1932) ERROR: bye (AmRequest.cpp:238): AmRequest::bye: 481 Call Leg/Transaction Does Not Exist
(1932) ERROR: bye (AmRequest.cpp:238): AmRequest::bye: 481 Call Leg/Transaction Does Not Exist
I can listen the announcement but do not receive any mail...
this is the Voicemail debug:
[root at gkproxy01 sems_2004-07-27]# 3(2028) SIP Request:
3(2028) method: <INVITE>
3(2028) uri: <sip:6605454 at call.millicom.com.pe:5090>
3(2028) version: <SIP/2.0>
3(2028) parse_headers: flags=1
3(2028) Found param type 232, <branch> = <z9hG4bK1ee5.e67a562.0>; state=16
3(2028) end of header reached, state=5
3(2028) parse_headers: Via found, flags=1
3(2028) parse_headers: this is the first via
3(2028) After parse_msg...
3(2028) preparing to run routing scripts...
3(2028) DEBUG : is_maxfwd_present: searching for max_forwards header
3(2028) parse_headers: flags=128
3(2028) Found param type 232, <branch> = <z9hG4bK3b00d2eea4212>; state=16
3(2028) end of header reached, state=5
3(2028) parse_headers: Via found, flags=128
3(2028) parse_headers: this is the second via
3(2028) end of header reached, state=9
3(2028) DEBUG: get_hdr_field: <To> [36]; uri=[sip:6605454 at call.millicom.com.pe]
3(2028) DEBUG: to body [<sip:6605454 at call.millicom.com.pe>
]
3(2028) get_hdr_field: cseq <CSeq>: <212> <INVITE>
3(2028) DEBUG: get_hdr_body : content_length=182
3(2028) DEBUG: is_maxfwd_present: value = 69
3(2028) check_self - checking if host==us: 20==13 && [call.millicom.com.pe] == [200.110.2.131]
3(2028) check_self - checking if port 5090 matches port 5090
3(2028) check_self - checking if host==us: 20==9 && [call.millicom.com.pe] == [127.0.0.1]
3(2028) check_self - checking if port 5090 matches port 5090
3(2028) DEBUG: t_addifnew: msg id=2 , global msg id=1 , T on entrance=0xffffffff
3(2028) parse_headers: flags=-1
3(2028) found end of header
3(2028) parse_headers: flags=60
3(2028) t_lookup_request: start searching: hash=24289, isACK=0
3(2028) DEBUG: RFC3261 transaction matching failed
3(2028) DEBUG: t_lookup_request: no transaction found
3(2028) DEBUG: add_param: tag=3b00d2eea4
3(2028) end of header reached, state=29
3(2028) DEBUG: t_check: msg id=2 global id=2 T start=0x422b8d30
3(2028) DEBUG: t_check: T alredy found!
3(2028) parse_headers: flags=-1
3(2028) check_via_address(200.110.2.131, 200.110.2.131, 0)
3(2028) WARNING:vqm_resize: resize(0) called
3(2028) DEBUG: reply sent out. buf=0x80dbd58: SIP/2.0 1..., shmem=0x422b68b0: SIP/2.0 1
3(2028) DEBUG: t_reply: finished
3(2028) **************** vm start - begin ******************
3(2028) parse_headers: flags=-1
3(2028) DEBUG: t_check: msg id=2 global id=2 T start=0x422b8d30
3(2028) DEBUG: t_check: T alredy found!
3(2028) record_route->nameaddr.uri: sip:6605454 at 200.110.2.131;ftag=3b00d2eea4;lr=on
3(2028) vm: first proxy has loose routing.
3(2028) vm: calculated route: <sip:6605454 at 200.110.2.131;ftag=3b00d2eea4;lr=on>
3(2028) vm: next r-uri: sip:6603000 at 10.0.0.236
3(2028) parse_headers: flags=-1
3(2028) query="select email_address from subscriber where username='6605454'"
3(2028) vm: write_to_vm_fifo: <0.2
sip_request.voicemail
INVITE
6605454
rrisco at millicom.com.pe
call.millicom.com.pe
200.110.2.131
5090
sip:6605454 at call.millicom.com.pe:5090
sip:6603000 at 10.0.0.236
<sip:6603000 at call.millicom.com.pe>
<sip:6605454 at call.millicom.com.pe>
3bdd9800-8a85-d2ac-82ee-0002a40055b2 at 10.0.0.236
3b00d2eea4
.
212
24289:1288922012
<sip:6605454 at 200.110.2.131;ftag=3b00d2eea4;lr=on>
sip:6605454 at 200.110.2.131;ftag=3b00d2eea4;lr=on
P-MsgFlags: 0
Min-SE: 1800
Date: Sun, 26 Apr 1970 22:48:27 GMT
.
v=0
o=- 10018107 10018107 IN IP4 10.0.0.236
s=AddPac Gateway SDP
c=IN IP4 10.0.0.236
t=0 0
m=audio 23562 RTP/AVP 4 18 0 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
>
3(2028) DEBUG: write_to_vm_fifo: write completed
3(2028) DEBUG: add_to_tail_of_timer[0]: 0x422b8e6c
3(2028) **************** vm start - end ******************
3(2028) DEBUG:destroy_avp_list: destroing list (nil)
3(2028) receive_msg: cleaning up
9(2038) DEBUG: fifo_t_reply: ############### begin ##############
9(2038) DEBUG: fifo_t_reply: trans_id=24289:1288922012
9(2038) DEBUG: fifo_t_reply: hash_index=24289 label=1288922012
9(2038) DEBUG: fifo_t_reply: to-tag: 0000078C0EA8250E
9(2038) DEBUG: fifo_t_reply: new headers: Contact: <sip:6605454 at 200.110.2.131:5090>
Content-Type: application/sdp
9(2038) DEBUG: fifo_t_reply: body: v=0
o=username 0 0 IN IP4 200.110.2.131
s=session
c=IN IP4 200.110.2.131
t=0 0
m=audio 1296 RTP/AVP 0
a=rtpmap:0 /
9(2038) DEBUG: t_lookup_ident: transaction found
9(2038) parse_headers: flags=-1
9(2038) check_via_address(200.110.2.131, 200.110.2.131, 0)
9(2038) t_reply_with_body: buffer computed
9(2038) DEBUG: cleanup_uacs: RETR/FR timers reset
9(2038) DEBUG: add_to_tail_of_timer[4]: 0x422b8de4
9(2038) DEBUG: add_to_tail_of_timer[0]: 0x422b8df8
9(2038) DEBUG: reply sent out. buf=0x80dbe20: SIP/2.0 2..., shmem=0x422b6c20: SIP/2.0 2
9(2038) DEBUG: t_reply: finished
9(2038) DEBUG: fifo_t_reply: ################ end ##############
10(2040) DEBUG: timer routine:0,tl=0x422b8e6c next=(nil)
10(2040) DEBUG: timer routine:4,tl=0x422b8de4 next=(nil)
10(2040) DEBUG: retransmission_handler : reply resending (t=0x422b8d30, SIP/2.0 2 ... )
10(2040) DEBUG: reply retransmitted. buf=0x4416b400: SIP/2.0 2..., shmem=0x422b6c20: SIP/2.0 2
10(2040) DEBUG: add_to_tail_of_timer[5]: 0x422b8de4
10(2040) DEBUG: retransmission_handler : done
4(2029) SIP Request:
4(2029) method: <ACK>
4(2029) uri: <sip:6605454 at call.millicom.com.pe:5090>
4(2029) version: <SIP/2.0>
4(2029) parse_headers: flags=1
4(2029) Found param type 232, <branch> = <0>; state=16
4(2029) end of header reached, state=5
4(2029) parse_headers: Via found, flags=1
4(2029) parse_headers: this is the first via
4(2029) After parse_msg...
4(2029) preparing to run routing scripts...
4(2029) DEBUG : sl_filter_ACK: to late to be a local ACK!
4(2029) DEBUG : is_maxfwd_present: searching for max_forwards header
4(2029) parse_headers: flags=128
4(2029) Found param type 232, <branch> = <z9hG4bK3b00d2eea4212>; state=16
4(2029) end of header reached, state=5
4(2029) parse_headers: Via found, flags=128
4(2029) parse_headers: this is the second via
4(2029) DEBUG: add_param: tag=0000078C0EA8250E
4(2029) end of header reached, state=29
4(2029) DEBUG: get_hdr_field: <To> [57]; uri=[sip:6605454 at call.millicom.com.pe]
4(2029) DEBUG: to body [<sip:6605454 at call.millicom.com.pe>]
4(2029) get_hdr_field: cseq <CSeq>: <212> <ACK>
4(2029) DEBUG: get_hdr_body : content_length=0
4(2029) DEBUG: is_maxfwd_present: value = 69
4(2029) check_self - checking if host==us: 20==13 && [call.millicom.com.pe] == [200.110.2.131]
4(2029) check_self - checking if port 5090 matches port 5090
4(2029) check_self - checking if host==us: 20==9 && [call.millicom.com.pe] == [127.0.0.1]
4(2029) check_self - checking if port 5090 matches port 5090
4(2029) DEBUG: t_addifnew: msg id=4 , global msg id=3 , T on entrance=0xffffffff
4(2029) parse_headers: flags=-1
4(2029) found end of header
4(2029) parse_headers: flags=60
4(2029) t_lookup_request: start searching: hash=24289, isACK=1
4(2029) DEBUG: proceeding to pre-RFC3261 transaction matching
4(2029) DEBUG: t_lookup_request: transaction found (T=0x422b8d30)
4(2029) DEBUG: cleanup_uacs: RETR/FR timers reset
4(2029) DEBUG: add_to_tail_of_timer[2]: 0x422b8d78
4(2029) DEBUG:destroy_avp_list: destroing list (nil)
4(2029) receive_msg: cleaning up
10(2040) DEBUG: timer routine:0,tl=0x422b8df8 next=(nil)
10(2040) DEBUG: timer routine:5,tl=0x422b8de4 next=(nil)
10(2040) DEBUG: timer routine:2,tl=0x422b8d78 next=(nil)
10(2040) DEBUG: wait_handler : removing 0x422b8d30 from table
10(2040) DEBUG: delete transaction 0x422b8d30
10(2040) DEBUG: wait_handler : done
[root at gkproxy01 sems_2004-07-27]#
[root at gkproxy01 sems_2004-07-27]#
[root at gkproxy01 sems_2004-07-27]#
[root at gkproxy01 sems_2004-07-27]#
[root at gkproxy01 sems_2004-07-27]#
[root at gkproxy01 sems_2004-07-27]#
[root at gkproxy01 sems_2004-07-27]#
[root at gkproxy01 sems_2004-07-27]# 9(2038) fifo_get_method: method: 'BYE'
9(2038) DEBUG: fifo_get_ruri: 'sip:6603000 at 10.0.0.236'
9(2038) DEBUG: fifo_get_nexthop: hop: 'sip:6605454 at 200.110.2.131;ftag=3b00d2eea4;lr=on'
9(2038) fifo_get_headers: headers: From: <sip:6605454 at call.millicom.com.pe>;tag=0000078C0EA8250E
To: <sip:6603000 at call.millicom.com.pe>;tag=3b00d2eea4
CSeq: 213 BYE
Call-ID: 3bdd9800-8a85-d2ac-82ee-0002a40055b2 at 10.0.0.236
Contact: <sip:6605454 at 200.110.2.131:5090>
Route: <sip:6605454 at 200.110.2.131;ftag=3b00d2eea4;lr=on>
9(2038) parse_headers: flags=-1
9(2038) DEBUG: add_param: tag=3b00d2eea4
9(2038) end of header reached, state=29
9(2038) DEBUG: get_hdr_field: <To> [51]; uri=[sip:6603000 at call.millicom.com.pe]
9(2038) DEBUG: to body [<sip:6603000 at call.millicom.com.pe>]
9(2038) get_hdr_field: cseq <CSeq>: <213> <BYE>
9(2038) DEBUG: fifo_uac: parse_headers succeeded
9(2038) fifo_get_body: body:
9(2038) DEBUG: add_param: tag=0000078C0EA8250E
9(2038) end of header reached, state=29
9(2038) DEBUG: get_hf_block: one more hf processed
9(2038) DEBUG: get_hf_block: one more hf processed
9(2038) DEBUG: fifo_uac: EoL -- proceeding to transaction creation
9(2038) DEBUG: mk_proxy: doing DNS lookup...
9(2038) DEBUG: dlg2hash: 24290
9(2038) DEBUG: add_to_tail_of_timer[4]: 0x422b8e58
9(2038) DEBUG: add_to_tail_of_timer[0]: 0x422b8e6c
1(2024) SIP Reply (status):
1(2024) version: <SIP/2.0>
1(2024) status: <481>
1(2024) reason: <Call Leg/Transaction Does Not Exist>
1(2024) parse_headers: flags=1
1(2024) Found param type 232, <branch> = <z9hG4bK2ee5.0b7fc205.0>; state=16
1(2024) end of header reached, state=5
1(2024) parse_headers: Via found, flags=1
1(2024) parse_headers: this is the first via
1(2024) After parse_msg...
1(2024) forward_reply: found module tm, passing reply to it
1(2024) DEBUG: t_check: msg id=3 global id=2 T start=0xffffffff
1(2024) parse_headers: flags=17
1(2024) DEBUG: add_param: tag=3b00d2eea4
1(2024) end of header reached, state=29
1(2024) DEBUG: get_hdr_field: <To> [51]; uri=[sip:6603000 at call.millicom.com.pe]
1(2024) DEBUG: to body [<sip:6603000 at call.millicom.com.pe>]
1(2024) get_hdr_field: cseq <CSeq>: <213> <BYE>
1(2024) DEBUG: t_reply_matching: hash 24290 label 1345124272 branch 0
1(2024) DEBUG: t_reply_matching: reply matched (T=0x422b8d30)!
1(2024) DEBUG: t_check: msg id=3 global id=3 T end=0x422b8d30
1(2024) DEBUG: t_on_reply: org. status uas=0, uac[0]=0 local=1 is_invite=0)
1(2024) ->>>>>>>>> T_code=0, new_code=481
1(2024) DEBUG: local_reply: branch=0, save=0, winner=0
1(2024) DEBUG: local transaction completed
1(2024) !!!!! ref_counter: 1
1(2024) DEBUG: fifo UAC completed with status 481
1(2024) DEBUG: fifo_callback sucesssfuly completed
1(2024) DEBUG: cleanup_uacs: RETR/FR timers reset
1(2024) DEBUG: add_to_tail_of_timer[2]: 0x422b8d78
1(2024) DEBUG:destroy_avp_list: destroing list (nil)
1(2024) receive_msg: cleaning up
10(2040) DEBUG: timer routine:0,tl=0x422b8e6c next=(nil)
10(2040) DEBUG: timer routine:4,tl=0x422b8e58 next=(nil)
9(2038) fifo_get_method: method: 'BYE'
9(2038) DEBUG: fifo_get_ruri: 'sip:6603000 at 10.0.0.236'
9(2038) DEBUG: fifo_get_nexthop: hop: 'sip:6605454 at 200.110.2.131;ftag=3b00d2eea4;lr=on'
9(2038) fifo_get_headers: headers: From: <sip:6605454 at call.millicom.com.pe>;tag=0000078C0EA8250E
To: <sip:6603000 at call.millicom.com.pe>;tag=3b00d2eea4
CSeq: 214 BYE
Call-ID: 3bdd9800-8a85-d2ac-82ee-0002a40055b2 at 10.0.0.236
Contact: <sip:6605454 at 200.110.2.131:5090>
Route: <sip:6605454 at 200.110.2.131;ftag=3b00d2eea4;lr=on>
9(2038) parse_headers: flags=-1
9(2038) DEBUG: add_param: tag=3b00d2eea4
9(2038) end of header reached, state=29
9(2038) DEBUG: get_hdr_field: <To> [51]; uri=[sip:6603000 at call.millicom.com.pe]
9(2038) DEBUG: to body [<sip:6603000 at call.millicom.com.pe>]
9(2038) get_hdr_field: cseq <CSeq>: <214> <BYE>
9(2038) DEBUG: fifo_uac: parse_headers succeeded
9(2038) fifo_get_body: body:
9(2038) DEBUG: add_param: tag=0000078C0EA8250E
9(2038) end of header reached, state=29
9(2038) DEBUG: get_hf_block: one more hf processed
9(2038) DEBUG: get_hf_block: one more hf processed
9(2038) DEBUG: fifo_uac: EoL -- proceeding to transaction creation
9(2038) DEBUG: mk_proxy: doing DNS lookup...
9(2038) DEBUG: dlg2hash: 24287
9(2038) DEBUG: add_to_tail_of_timer[4]: 0x422b82a0
9(2038) DEBUG: add_to_tail_of_timer[0]: 0x422b82b4
4(2029) SIP Reply (status):
4(2029) version: <SIP/2.0>
4(2029) status: <481>
4(2029) reason: <Call Leg/Transaction Does Not Exist>
4(2029) parse_headers: flags=1
4(2029) Found param type 232, <branch> = <z9hG4bKfde5.d3b83bb7.0>; state=16
4(2029) end of header reached, state=5
4(2029) parse_headers: Via found, flags=1
4(2029) parse_headers: this is the first via
4(2029) After parse_msg...
4(2029) forward_reply: found module tm, passing reply to it
4(2029) DEBUG: t_check: msg id=5 global id=4 T start=0xffffffff
4(2029) parse_headers: flags=17
4(2029) DEBUG: add_param: tag=3b00d2eea4
4(2029) end of header reached, state=29
4(2029) DEBUG: get_hdr_field: <To> [51]; uri=[sip:6603000 at call.millicom.com.pe]
4(2029) DEBUG: to body [<sip:6603000 at call.millicom.com.pe>]
4(2029) get_hdr_field: cseq <CSeq>: <214> <BYE>
4(2029) DEBUG: t_reply_matching: hash 24287 label 2075364157 branch 0
4(2029) DEBUG: t_reply_matching: reply matched (T=0x422b8178)!
4(2029) DEBUG: t_check: msg id=5 global id=5 T end=0x422b8178
4(2029) DEBUG: t_on_reply: org. status uas=0, uac[0]=0 local=1 is_invite=0)
4(2029) ->>>>>>>>> T_code=0, new_code=481
4(2029) DEBUG: local_reply: branch=0, save=0, winner=0
4(2029) DEBUG: local transaction completed
4(2029) !!!!! ref_counter: 1
4(2029) DEBUG: fifo UAC completed with status 481
4(2029) DEBUG: fifo_callback sucesssfuly completed
4(2029) DEBUG: cleanup_uacs: RETR/FR timers reset
4(2029) DEBUG: add_to_tail_of_timer[2]: 0x422b81c0
4(2029) DEBUG:destroy_avp_list: destroing list (nil)
4(2029) receive_msg: cleaning up
10(2040) DEBUG: timer routine:0,tl=0x422b82b4 next=(nil)
10(2040) DEBUG: timer routine:4,tl=0x422b82a0 next=(nil)
10(2040) DEBUG: timer routine:2,tl=0x422b8d78 next=(nil)
10(2040) DEBUG: wait_handler : removing 0x422b8d30 from table
10(2040) DEBUG: delete transaction 0x422b8d30
10(2040) DEBUG: wait_handler : done
10(2040) DEBUG: timer routine:2,tl=0x422b81c0 next=(nil)
10(2040) DEBUG: wait_handler : removing 0x422b8178 from table
10(2040) DEBUG: delete transaction 0x422b8178
10(2040) DEBUG: wait_handler : done
Bogdan-Andrei IANCU <iancu at fokus.fraunhofer.de> wrote:
Rafael J. Risco G.V wrote:
> hi
> I am answering myself... :
>
> 1. it is necessary to load VM module in the first ser instance too.
actually you don't need VM in first instance. My guess is you mixed up
the fifo files used by both server (maybe they have the same name) and
SEMS fifo commands reach the first instance, instead the second.
bogdan
> 2.- In voicemail.cfg the fifo value is fifo="/tmp/vm_ser_fifo"
> 3.- In Sems.cfg: the value of 'ser_fifo_name' is "/tmp/vm_ser_fifo"
> instead of "/tmp/ser_fifo" ( ser_fifo_name=/tmp/vm_ser_fifo )
>
> now it works perfectly.
>
> Rafael
---------------------------------
Do You Yahoo!?
Todo lo que quieres saber de Estados Unidos, América Latina y el resto del Mundo.
Visíta Yahoo! Noticias.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20040820/47ebf92b/attachment.htm>
More information about the sr-users
mailing list