Hi,

I've been trying to setup a openser + asterisk server following the tutorial here: http://www.voip-info.org/wiki/view/Realtime+Integration+Of+Asterisk+With+Ope... and with that openser configuration example.

The only difference in my setup is that I am using openser 1.1.

For some reason it doesn't seem to be working, the call is not established.

This is the debugging output:

/usr/sbin/openser[26006]: SIP Request: /usr/sbin/openser[26006]: method: <INVITE> /usr/sbin/openser[26006]: uri: sip:101@217.73.174.13 /usr/sbin/openser[26006]: version: <SIP/2.0> /usr/sbin/openser[26006]: parse_headers: flags=2 /usr/sbin/openser[26006]: Found param type 235, <rport> = <n/a>; state=6 /usr/sbin/openser[26006]: Found param type 232, <branch> = <z9hG4bKapseucta>; state=16 /usr/sbin/openser[26006]: end of header reached, state=5 /usr/sbin/openser[26006]: parse_headers: Via found, flags=2 /usr/sbin/openser[26006]: parse_headers: this is the first via /usr/sbin/openser[26006]: After parse_msg... /usr/sbin/openser[26006]: preparing to run routing scripts... /usr/sbin/openser[26006]: parse_headers: flags=100 /usr/sbin/openser[26006]: DEBUG:maxfwd:is_maxfwd_present: value = 70 /usr/sbin/openser[26006]: parse_headers: flags=10 /usr/sbin/openser[26006]: DEBUG:parse_to:end of header reached, state=10 /usr/sbin/openser[26006]: DBUG:parse_to: display={}, ruri={sip:101@217.73.174.13} /usr/sbin/openser[26006]: DEBUG: get_hdr_field: <To> [25]; uri=[sip:101@217.73.174.13] /usr/sbin/openser[26006]: DEBUG: to body [sip:101@217.73.174.13^M ] /usr/sbin/openser[26006]: DEBUG: add_param: tag=hsiim /usr/sbin/openser[26006]: DEBUG:parse_to:end of header reached, state=29 /usr/sbin/openser[26006]: DBUG:parse_to: display={"Radu Spineanu"}, ruri={sip:100@217.73.174.13} /usr/sbin/openser[26006]: parse_headers: flags=200 /usr/sbin/openser[26006]: get_hdr_field: cseq <CSeq>: <797> <INVITE> /usr/sbin/openser[26006]: DEBUG: get_hdr_body : content_length=303 /usr/sbin/openser[26006]: found end of header /usr/sbin/openser[26006]: find_first_route: No Route headers found /usr/sbin/openser[26006]: loose_route: There is no Route HF /usr/sbin/openser[26006]: grep_sock_info - checking if host==us: 13==13 && [217.73.174.13] == [217.73.174.13] /usr/sbin/openser[26006]: grep_sock_info - checking if port 5060 matches port 5060 /usr/sbin/openser[26006]: grep_sock_info - checking if host==us: 13==13 && [217.73.174.13] == [217.73.174.13] /usr/sbin/openser[26006]: grep_sock_info - checking if port 5060 matches port 5060 /usr/sbin/openser[26006]: DEBUG: has_totag: no totag /usr/sbin/openser[26006]: DEBUG: has_totag: no totag /usr/sbin/openser[26006]: is_user_in(): User is not in group 'voicemail' /usr/sbin/openser[26006]: rewrite_uri: Rewriting Request-URI with 'sip:101@82.79.243.82:5068' /usr/sbin/openser[26006]: parse_headers: flags=ffffffffffffffff /usr/sbin/openser[26006]: DEBUG: t_newtran: msg id=2 , global msg id=0 , T on entrance=0xffffffffffffffff /usr/sbin/openser[26006]: parse_headers: flags=ffffffffffffffff /usr/sbin/openser[26006]: parse_headers: flags=78 /usr/sbin/openser[26006]: t_lookup_request: start searching: hash=18702, isACK=0 /usr/sbin/openser[26006]: DEBUG: RFC3261 transaction matching failed /usr/sbin/openser[26006]: DEBUG: t_lookup_request: no transaction found /usr/sbin/openser[26006]: DEBUG:tm:t_relay: new INVITE /usr/sbin/openser[26006]: parse_headers: flags=ffffffffffffffff /usr/sbin/openser[26006]: check_via_address(217.73.174.16, 82.79.243.82, 0) /usr/sbin/openser[26006]: WARNING:vqm_resize: resize(0) called /usr/sbin/openser[26006]: DEBUG:tm:_reply_light: reply sent out. buf=0x5e6458: SIP/2.0 1..., shmem=0x2b05574b9fb8: SIP/2.0 1 /usr/sbin/openser[26006]: DEBUG:tm:_reply_light: finished /usr/sbin/openser[26006]: DEBUG: mk_proxy: doing DNS lookup... /usr/sbin/openser[26006]: check_via_address(217.73.174.16, 82.79.243.82, 0) /usr/sbin/openser[26006]: DEBUG: add_to_tail_of_timer[4]: 0x2b05574b7ba0 /usr/sbin/openser[26006]: DEBUG: add_to_tail_of_timer[0]: 0x2b05574b7bc0 /usr/sbin/openser[26006]: SER: new transaction fwd'ed /usr/sbin/openser[26006]: DEBUG:tm:UNREF_UNSAFE: after is 0 /usr/sbin/openser[26006]: DEBUG:destroy_avp_list: destroying list (nil) /usr/sbin/openser[26006]: receive_msg: cleaning up /usr/sbin/openser[26012]: DEBUG: timer routine:4,tl=0x2b05574b7ba0 next=(nil) /usr/sbin/openser[26012]: DEBUG: retransmission_handler : request resending (t=0x2b05574b79c0, INVITE si ... ) /usr/sbin/openser[26012]: DEBUG: add_to_tail_of_timer[5]: 0x2b05574b7ba0 /usr/sbin/openser[26012]: DEBUG: retransmission_handler : done amy /usr/sbin/openser[26012]: DEBUG: timer routine:5,tl=0x2b05574b7ba0 next=(nil) amy /usr/sbin/openser[26012]: DEBUG: retransmission_handler : request resending (t=0x2b05574b79c0, INVITE si ... ) amy /usr/sbin/openser[26012]: DEBUG: add_to_tail_of_timer[6]: 0x2b05574b7ba0 amy /usr/sbin/openser[26012]: DEBUG: retransmission_handler : done [..] Jun 24 15:38:47 amy /usr/sbin/openser[26012]: DEBUG: timer routine:0,tl=0x2b05574b7bc0 next=(nil) /usr/sbin/openser[26012]: DEBUG: final_response_handler:stop retr. and send CANCEL (0x2b05574b79c0) /usr/sbin/openser[26012]: DEBUG:tm:t_should_relay_response: T_code=100, new_code=408 /usr/sbin/openser[26012]: DEBUG:tm:t_pick_branch: picked branch 0, code 408 /usr/sbin/openser[26012]: DEBUG:tm:relay_reply: branch=0, save=0, relay=0 /usr/sbin/openser[26012]: parse_headers: flags=ffffffffffffffff /usr/sbin/openser[26012]: check_via_address(217.73.174.16, 82.79.243.82, 0) /usr/sbin/openser[26012]: DEBUG: add_to_tail_of_timer[4]: 0x2b05574b7ae8 /usr/sbin/openser[26012]: DEBUG: add_to_tail_of_timer[0]: 0x2b05574b7b08 /usr/sbin/openser[26012]: DEBUG:tm:relay_reply: sent buf=0x5e4fb0: SIP/2.0 4..., shmem=0x2b05574b9fb8: SIP/2.0 4 /usr/sbin/openser[26012]: DEBUG: final_response_handler : done /usr/sbin/openser[26012]: DEBUG: timer routine:7,tl=0x2b05574b7ba0 next=(nil) /usr/sbin/openser[26006]: SIP Request: /usr/sbin/openser[26006]: method: <ACK> /usr/sbin/openser[26006]: uri: sip:101@217.73.174.13 /usr/sbin/openser[26006]: version: <SIP/2.0> /usr/sbin/openser[26006]: parse_headers: flags=2 /usr/sbin/openser[26006]: Found param type 235, <rport> = <n/a>; state=6 /usr/sbin/openser[26006]: Found param type 232, <branch> = <z9hG4bKapseucta>; state=16 /usr/sbin/openser[26006]: end of header reached, state=5 /usr/sbin/openser[26006]: parse_headers: Via found, flags=2 /usr/sbin/openser[26006]: parse_headers: this is the first via /usr/sbin/openser[26006]: After parse_msg... /usr/sbin/openser[26006]: preparing to run routing scripts... /usr/sbin/openser[26006]: DEBUG : sl_filter_ACK: to late to be a local ACK! /usr/sbin/openser[26006]: parse_headers: flags=100 /usr/sbin/openser[26006]: DEBUG:maxfwd:is_maxfwd_present: value = 70 /usr/sbin/openser[26006]: parse_headers: flags=10 /usr/sbin/openser[26006]: DEBUG: add_param: tag=90f6b651c515331ae78169ff327ec50d-6648 /usr/sbin/openser[26006]: DEBUG:parse_to:end of header reached, state=29 /usr/sbin/openser[26006]: DBUG:parse_to: display={}, ruri={sip:101@217.73.174.13} /usr/sbin/openser[26006]: DEBUG: get_hdr_field: <To> [67]; uri=[sip:101@217.73.174.13] /usr/sbin/openser[26006]: DEBUG: to body [sip:101@217.73.174.13] /usr/sbin/openser[26006]: DEBUG: add_param: tag=hsiim /usr/sbin/openser[26006]: DEBUG:parse_to:end of header reached, state=29 /usr/sbin/openser[26006]: DBUG:parse_to: display={"Radu Spineanu"}, ruri={sip:100@217.73.174.13} /usr/sbin/openser[26006]: parse_headers: flags=200 /usr/sbin/openser[26006]: get_hdr_field: cseq <CSeq>: <797> <ACK> /usr/sbin/openser[26006]: DEBUG: get_hdr_body : content_length=0 /usr/sbin/openser[26006]: found end of header /usr/sbin/openser[26006]: find_first_route: No Route headers found /usr/sbin/openser[26006]: loose_route: There is no Route HF /usr/sbin/openser[26006]: grep_sock_info - checking if host==us: 13==13 && [217.73.174.13] == [217.73.174.13] /usr/sbin/openser[26006]: grep_sock_info - checking if port 5060 matches port 5060 /usr/sbin/openser[26006]: grep_sock_info - checking if host==us: 13==13 && [217.73.174.13] == [217.73.174.13] /usr/sbin/openser[26006]: grep_sock_info - checking if port 5060 matches port 5060 /usr/sbin/openser[26006]: rewrite_uri: Rewriting Request-URI with 'sip:101@82.79.243.82:5068' /usr/sbin/openser[26006]: parse_headers: flags=ffffffffffffffff /usr/sbin/openser[26006]: DEBUG: t_newtran: msg id=3 , global msg id=2 , T on entrance=0xffffffffffffffff /usr/sbin/openser[26006]: parse_headers: flags=ffffffffffffffff /usr/sbin/openser[26006]: parse_headers: flags=78 /usr/sbin/openser[26006]: t_lookup_request: start searching: hash=18702, isACK=1 /usr/sbin/openser[26006]: DEBUG: RFC3261 transaction matched, tid=apseucta /usr/sbin/openser[26006]: DEBUG:tm:REF_UNSAFE: after is 1 /usr/sbin/openser[26006]: DEBUG: t_lookup_request: transaction found (T=0x2b05574b79c0) /usr/sbin/openser[26006]: DEBUG: cleanup_uac_timers: RETR/FR timers reset /usr/sbin/openser[26006]: DEBUG: add_to_tail_of_timer[2]: 0x2b05574b7a40 /usr/sbin/openser[26006]: DEBUG:tm:UNREF_UNSAFE: after is 0 /usr/sbin/openser[26006]: DEBUG:destroy_avp_list: destroying list (nil) /usr/sbin/openser[26006]: receive_msg: cleaning up /usr/sbin/openser[26012]: DEBUG: timer routine:0,tl=0x2b05574b7b08 next=(nil) /usr/sbin/openser[26012]: DEBUG: timer routine:4,tl=0x2b05574b7ae8 next=(nil) /usr/sbin/openser[26012]: DEBUG: timer routine:2,tl=0x2b05574b7a40 next=(nil) /usr/sbin/openser[26012]: DEBUG: wait_handler : removing 0x2b05574b79c0 from table /usr/sbin/openser[26012]: DEBUG: delete transaction 0x2b05574b79c0 /usr/sbin/openser[26012]: DEBUG: wait_handler : done

And this an ngrep output:

U 217.73.174.16:5063 -> 217.73.174.13:5060 INVITE sip:101@217.73.174.13 SIP/2.0..Via: SIP/2.0/UDP 82.79.243.82:5063;rport;branch=z9hG4bKlejwtozv..Max-Forwards: 70..To: <sip:101@217 .73.174.13>..From: "Radu Spineanu" sip:100@217.73.174.13;tag=lewnx..Call-ID: pfysegloyvynryc@82.79.243.82..CSeq: 305 INVITE..Contact: < sip:100@82.79.243.82:5063>..Content-Type: application/sdp..Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO..Suppor ted: replaces,norefersub,100rel..User-Agent: Twinkle/1.0.1..Content-Length: 303....v=0..o=100 246106612 367660894 IN IP4 82.79.243.82..s= -..c=IN IP4 82.79.243.82..t=0 0..m=audio 8012 RTP/AVP 98 97 8 0 3 101..a=rtpmap:98 speex/16000..a=rtpmap:97 speex/8000..a=rtpmap:8 PCMA/8 000..a=rtpmap:0 PCMU/8000..a=rtpmap:3 GSM/8000..a=rtpmap:101 telephone-event/8000..a=fmtp:101 0-15..a=ptime:20.. # U 217.73.174.13:5060 -> 217.73.174.16:5063 SIP/2.0 100 trying -- your call is important to us..Via: SIP/2.0/UDP 82.79.243.82:5063;rport=5063;branch=z9hG4bKlejwtozv;received=217.73. 174.16..To: sip:101@217.73.174.13..From: "Radu Spineanu" sip:100@217.73.174.13;tag=lewnx..Call-ID: pfysegloyvynryc@82.79.243.82..CSeq : 305 INVITE..Server: OpenSer (1.1.0-notls (x86_64/linux))..Content-Length: 0..Warning: 392 217.73.174.13:5060 "Noisy feedback tells: pi d=26007 req_src_ip=217.73.174.16 req_src_port=5063 in_uri=sip:101@217.73.174.13 out_uri=sip:101@82.79.243.82:5068 via_cnt==1".... # U 217.73.174.13:5060 -> 82.79.243.82:5068 INVITE sip:101@82.79.243.82:5068 SIP/2.0..Record-Route: sip:217.73.174.13;lr=on;ftag=lewnx..Via: SIP/2.0/UDP 217.73.174.13;branch=z9hG4 bK4a11.a2772f67.0..Via: SIP/2.0/UDP 82.79.243.82:5063;received=217.73.174.16;rport=5063;branch=z9hG4bKlejwtozv..Max-Forwards: 69..To: <si p:101@217.73.174.13>..From: "Radu Spineanu" sip:100@217.73.174.13;tag=lewnx..Call-ID: pfysegloyvynryc@82.79.243.82..CSeq: 305 INVITE..C ontact: sip:100@82.79.243.82:5063..Content-Type: application/sdp..Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INF O..Supported: replaces,norefersub,100rel..User-Agent: Twinkle/1.0.1..Content-Length: 303..P-hint: usrloc applied....v=0..o=100 246106612 367660894 IN IP4 82.79.243.82..s=-..c=IN IP4 82.79.243.82..t=0 0..m=audio 8012 RTP/AVP 98 97 8 0 3 101..a=rtpmap:98 speex/16000..a=rtpmap :97 speex/8000..a=rtpmap:8 PCMA/8000..a=rtpmap:0 PCMU/8000..a=rtpmap:3 GSM/8000..a=rtpmap:101 telephone-event/8000..a=fmtp:101 0-15..a=pt ime:20.. # U 217.73.174.13:5060 -> 82.79.243.82:5068 INVITE sip:101@82.79.243.82:5068 SIP/2.0..Record-Route: sip:217.73.174.13;lr=on;ftag=lewnx..Via: SIP/2.0/UDP 217.73.174.13;branch=z9hG4 bK4a11.a2772f67.0..Via: SIP/2.0/UDP 82.79.243.82:5063;received=217.73.174.16;rport=5063;branch=z9hG4bKlejwtozv..Max-Forwards: 69..To: <si p:101@217.73.174.13>..From: "Radu Spineanu" sip:100@217.73.174.13;tag=lewnx..Call-ID: pfysegloyvynryc@82.79.243.82..CSeq: 305 INVITE..C ontact: sip:100@82.79.243.82:5063..Content-Type: application/sdp..Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INF O..Supported: replaces,norefersub,100rel..User-Agent: Twinkle/1.0.1..Content-Length: 303..P-hint: usrloc applied....v=0..o=100 246106612 367660894 IN IP4 82.79.243.82..s=-..c=IN IP4 82.79.243.82..t=0 0..m=audio 8012 RTP/AVP 98 97 8 0 3 101..a=rtpmap:98 speex/16000..a=rtpmap :97 speex/8000..a=rtpmap:8 PCMA/8000..a=rtpmap:0 PCMU/8000..a=rtpmap:3 GSM/8000..a=rtpmap:101 telephone-event/8000..a=fmtp:101 0-15..a=pt ime:20.. #

Initially I did the setup folowing http://www.openser.org/dokuwiki/doku.php/asterisk:realtime-integration which worked but didn't have voicemail redirection support.

Thanks and sorry for the long mail, Radu Spineanu