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@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@gkproxy01 sems_2004-07-27]# 3(2028) SIP Request:
3(2028) method: <INVITE>
3(2028) uri: <sip:6605454@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@call.millicom.com.pe]
3(2028) DEBUG: to body [<sip:6605454@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@200.110.2.131;ftag=3b00d2eea4;lr=on
3(2028) vm: first proxy has loose routing.
3(2028) vm: calculated route: <sip:6605454@200.110.2.131;ftag=3b00d2eea4;lr=on>
3(2028) vm: next r-uri: sip:6603000@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@millicom.com.pe
call.millicom.com.pe
200.110.2.131
5090
sip:6605454@call.millicom.com.pe:5090
sip:6603000@10.0.0.236
<sip:6603000@call.millicom.com.pe>
<sip:6605454@call.millicom.com.pe>
3bdd9800-8a85-d2ac-82ee-0002a40055b2@10.0.0.236
3b00d2eea4
.
212
24289:1288922012
<sip:6605454@200.110.2.131;ftag=3b00d2eea4;lr=on>
sip:6605454@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@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@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@call.millicom.com.pe]
4(2029) DEBUG: to body [<sip:6605454@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@gkproxy01 sems_2004-07-27]#
[root@gkproxy01 sems_2004-07-27]#
[root@gkproxy01 sems_2004-07-27]#
[root@gkproxy01 sems_2004-07-27]#
[root@gkproxy01 sems_2004-07-27]#
[root@gkproxy01 sems_2004-07-27]#
[root@gkproxy01 sems_2004-07-27]#
[root@gkproxy01 sems_2004-07-27]# 9(2038) fifo_get_method: method: 'BYE'
9(2038) DEBUG: fifo_get_ruri: 'sip:6603000@10.0.0.236'
9(2038) DEBUG: fifo_get_nexthop: hop: 'sip:6605454@200.110.2.131;ftag=3b00d2eea4;lr=on'
9(2038) fifo_get_headers: headers: From: <sip:6605454@call.millicom.com.pe>;tag=0000078C0EA8250E
To: <sip:6603000@call.millicom.com.pe>;tag=3b00d2eea4
CSeq: 213 BYE
Call-ID: 3bdd9800-8a85-d2ac-82ee-0002a40055b2@10.0.0.236
Contact: <sip:6605454@200.110.2.131:5090>
Route: <sip:6605454@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@call.millicom.com.pe]
9(2038) DEBUG: to body [<sip:6603000@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@call.millicom.com.pe]
1(2024) DEBUG: to body
[<sip:6603000@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@10.0.0.236'
9(2038) DEBUG: fifo_get_nexthop: hop: 'sip:6605454@200.110.2.131;ftag=3b00d2eea4;lr=on'
9(2038) fifo_get_headers: headers: From: <sip:6605454@call.millicom.com.pe>;tag=0000078C0EA8250E
To: <sip:6603000@call.millicom.com.pe>;tag=3b00d2eea4
CSeq: 214 BYE
Call-ID: 3bdd9800-8a85-d2ac-82ee-0002a40055b2@10.0.0.236
Contact: <sip:6605454@200.110.2.131:5090>
Route: <sip:6605454@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@call.millicom.com.pe]
9(2038) DEBUG: to body [<sip:6603000@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@call.millicom.com.pe]
4(2029) DEBUG: to body
[<sip:6603000@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
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