16 Nov
2005
16 Nov
'05
11:13 a.m.
Hi,
In my lab we have SER (0.9.4) running, collocated in the same box with
SEMS, communicating via the fifo.
An abstraction of the config:
//identify traffic for SEMS
//send to route[x]
route[x] {
if( !t_newtran() ) { ..... }
if( method == "ACK" ) { break;} //drop local acks ...
t_reply("100", "msg");
send via fifo to sems ...
}
I have stumbled against some problems:
P1) Local ACKs from the phone are not being dropped.
P2) to-tag in replies from SER from sl_send_reply and OK message change
P3) the t_newtran does not stop sending OKs, even it receives ACKs to them
They all seem to be related ...
the ACK from the phone back to SER, which are local(right?), are not
dropped for two reasons: the sl_timeout is not updated, as i don't
have an sl_send_reply in the route[x] block.
I can fix the above by adding an sl_send_reply("183", "sems session in
progress") ... but then, the second problem appears.
Adding the sl_send_reply(183, ) adds a to-tag to the 183-reply, but
then the following OK has a completely different to-tag ... which is
the one used by my UA to create the ACK. As the to-tag in the ACK is
different to that from the 183-reply ... the sl_filter_ack does not
recognize the ACK as local, and does not filter it.
In any case, this would not solve the problem of the t_newtran sending
OK replies to the phone, even it receives ACKs to them.
What can i do? should i use t_release somewhere? are these ACKs
"local"? if not, where should these ACKs be routed to, to the route[x]
block?
Tks in advance,
Cesc
23 Nov
23 Nov
8:17 a.m.
Hi Cesc,
I haven't seen a response to your post?! Are you sure the ACKs are not
caught by loose routing?
I would suggest setting up a separate ser instance on ex. port 5062 and
dedicate it to sems interfacing. Then in your main ser you just correctly
forwards the INVITEs to the sems ser instance. Also remember to run
fix_nated_sdp("3") for NATed clients (SEMS support active media. Both sems
and SER-SEMS should run on a public IP.
g-)
----- Original Message -----
From: "Cesc" <cesc.santa(a)gmail.com>
To: "SER-Users" <serusers(a)lists.iptel.org>
Sent: Wednesday, November 16, 2005 11:13 AM
Subject: [Serusers] Local ACKs for SER-SEMS
Hi,
In my lab we have SER (0.9.4) running, collocated in the same box with
SEMS, communicating via the fifo.
An abstraction of the config:
//identify traffic for SEMS
//send to route[x]
route[x] {
if( !t_newtran() ) { ..... }
if( method == "ACK" ) { break;} //drop local acks ...
t_reply("100", "msg");
send via fifo to sems ...
}
I have stumbled against some problems:
P1) Local ACKs from the phone are not being dropped.
P2) to-tag in replies from SER from sl_send_reply and OK message change
P3) the t_newtran does not stop sending OKs, even it receives ACKs to them
They all seem to be related ...
the ACK from the phone back to SER, which are local(right?), are not
dropped for two reasons: the sl_timeout is not updated, as i don't
have an sl_send_reply in the route[x] block.
I can fix the above by adding an sl_send_reply("183", "sems session in
progress") ... but then, the second problem appears.
Adding the sl_send_reply(183, ) adds a to-tag to the 183-reply, but
then the following OK has a completely different to-tag ... which is
the one used by my UA to create the ACK. As the to-tag in the ACK is
different to that from the 183-reply ... the sl_filter_ack does not
recognize the ACK as local, and does not filter it.
In any case, this would not solve the problem of the t_newtran sending
OK replies to the phone, even it receives ACKs to them.
What can i do? should i use t_release somewhere? are these ACKs
"local"? if not, where should these ACKs be routed to, to the route[x]
block?
Tks in advance,
Cesc
_______________________________________________
Serusers mailing list
serusers(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serusers
10:38 a.m.
Hi Greger,
First, the last half of your email ... i cannot run a dedicated
instance of SER. We run an embedded system, thus not much space and
power to spare.
As for the NAT ... we have no NAT in our network (lucky us :D ).
As for the first part ... i had not seen a response either :)
Actually, i lost the email in gmail folders, could not find it
anywhere ... tks for replying, now i found it again.
As for the ACK ... i tried using t_lookup_request ... it turns out
that it does find a transaction, but it identifies them as e2e (i
guess ... end2end) ... i will investigate further ... and i will
provide a trace.
Tks!
Cesc
On 11/23/05, Greger V. Teigre <greger(a)teigre.com> wrote:
Hi Cesc,
I haven't seen a response to your post?! Are you sure the ACKs are not
caught by loose routing?
I would suggest setting up a separate ser instance on ex. port 5062 and
dedicate it to sems interfacing. Then in your main ser you just correctly
forwards the INVITEs to the sems ser instance. Also remember to run
fix_nated_sdp("3") for NATed clients (SEMS support active media. Both sems
and SER-SEMS should run on a public IP.
g-)
----- Original Message -----
From: "Cesc" <cesc.santa(a)gmail.com>
To: "SER-Users" <serusers(a)lists.iptel.org>
Sent: Wednesday, November 16, 2005 11:13 AM
Subject: [Serusers] Local ACKs for SER-SEMS
Hi,
In my lab we have SER (0.9.4) running, collocated in the same box with
SEMS, communicating via the fifo.
An abstraction of the config:
//identify traffic for SEMS
//send to route[x]
route[x] {
if( !t_newtran() ) { ..... }
if( method == "ACK" ) { break;} //drop local acks ...
t_reply("100", "msg");
send via fifo to sems ...
}
I have stumbled against some problems:
P1) Local ACKs from the phone are not being dropped.
P2) to-tag in replies from SER from sl_send_reply and OK message change
P3) the t_newtran does not stop sending OKs, even it receives ACKs to them
They all seem to be related ...
the ACK from the phone back to SER, which are local(right?), are not
dropped for two reasons: the sl_timeout is not updated, as i don't
have an sl_send_reply in the route[x] block.
I can fix the above by adding an sl_send_reply("183", "sems session in
progress") ... but then, the second problem appears.
Adding the sl_send_reply(183, ) adds a to-tag to the 183-reply, but
then the following OK has a completely different to-tag ... which is
the one used by my UA to create the ACK. As the to-tag in the ACK is
different to that from the 183-reply ... the sl_filter_ack does not
recognize the ACK as local, and does not filter it.
In any case, this would not solve the problem of the t_newtran sending
OK replies to the phone, even it receives ACKs to them.
What can i do? should i use t_release somewhere? are these ACKs
"local"? if not, where should these ACKs be routed to, to the route[x]
block?
Tks in advance,
Cesc
_______________________________________________
Serusers mailing list
serusers(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serusers
10:53 a.m.
Actually I've seen the mail but did not have yet time to look into it
(I have it on my todo list).
When communicating with applications like sems over the fifo or unix
sockets, SER takes care of ACK processing (that also means generating
local e2e ACKs on behalf of sems). This is a hack because tm has to do
all the dialog-related logic (such as route processing, loose/strict
routing and so on).
Inside tm end-to-end ACKs are matched with the original INVITE
transaction. This was needed for accounting purposes, if I recall it correctly.
In any case full tm traces would be helpful, especially for P3.
Jan.
On 23-11-2005 10:38, Cesc wrote:
Hi Greger,
First, the last half of your email ... i cannot run a dedicated
instance of SER. We run an embedded system, thus not much space and
power to spare.
As for the NAT ... we have no NAT in our network (lucky us :D ).
As for the first part ... i had not seen a response either :)
Actually, i lost the email in gmail folders, could not find it
anywhere ... tks for replying, now i found it again.
As for the ACK ... i tried using t_lookup_request ... it turns out
that it does find a transaction, but it identifies them as e2e (i
guess ... end2end) ... i will investigate further ... and i will
provide a trace.
Tks!
Cesc
On 11/23/05, Greger V. Teigre <greger(a)teigre.com> wrote:
Hi Cesc,
I haven't seen a response to your post?! Are you sure the ACKs are not
caught by loose routing?
I would suggest setting up a separate ser instance on ex. port 5062 and
dedicate it to sems interfacing. Then in your main ser you just correctly
forwards the INVITEs to the sems ser instance. Also remember to run
fix_nated_sdp("3") for NATed clients (SEMS support active media. Both sems
and SER-SEMS should run on a public IP.
g-)
----- Original Message -----
From: "Cesc" <cesc.santa(a)gmail.com>
To: "SER-Users" <serusers(a)lists.iptel.org>
Sent: Wednesday, November 16, 2005 11:13 AM
Subject: [Serusers] Local ACKs for SER-SEMS
_______________________________________________
Serusers mailing list
serusers(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serusers Hi,
In my lab we have SER (0.9.4) running, collocated in the same box with
SEMS, communicating via the fifo.
An abstraction of the config:
//identify traffic for SEMS
//send to route[x]
route[x] {
if( !t_newtran() ) { ..... }
if( method == "ACK" ) { break;} //drop local acks ...
t_reply("100", "msg");
send via fifo to sems ...
}
I have stumbled against some problems:
P1) Local ACKs from the phone are not being dropped.
P2) to-tag in replies from SER from sl_send_reply and OK message change
P3) the t_newtran does not stop sending OKs, even it receives ACKs to them
They all seem to be related ...
the ACK from the phone back to SER, which are local(right?), are not
dropped for two reasons: the sl_timeout is not updated, as i don't
have an sl_send_reply in the route[x] block.
I can fix the above by adding an sl_send_reply("183", "sems session in
progress") ... but then, the second problem appears.
Adding the sl_send_reply(183, ) adds a to-tag to the 183-reply, but
then the following OK has a completely different to-tag ... which is
the one used by my UA to create the ACK. As the to-tag in the ACK is
different to that from the 183-reply ... the sl_filter_ack does not
recognize the ACK as local, and does not filter it.
In any case, this would not solve the problem of the t_newtran sending
OK replies to the phone, even it receives ACKs to them.
What can i do? should i use t_release somewhere? are these ACKs
"local"? if not, where should these ACKs be routed to, to the route[x]
block?
Tks in advance,
Cesc
_______________________________________________
Serusers mailing list
serusers(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serusers
12:31 p.m.
Hi,
I attach a tar'd.gz file with: a snippet of the ser.cfg file, a ser
log and the messages (INV and OK) passed from-to ser-sems unix socket.
I attach directly to this email a short version of the ser.log file
and ser.cfg, for easyness ... hopefully it will go through ...
Hope it helps,
Cesc
=============================================
=============================================
=====================================================
== ON THE UNIX SOCK (INVITE FROM SER)
=============================================
0.3
sip_request.intercom
INVITE
10033
cafes.org
192.0.1.150
.
sip:10033@cafes.org
sip:jos@192.0.1.250:6060;transport=UDP
<sip:jos@cafes.org>
<sip:10033@cafes.org>
1832198372(a)192.0.1.250
1455248939
301
64360:678404969
.
.
P-MsgFlags: 0
Content-Type: application/sdp
.
v=0
o=- 3344 3344 IN IP4 192.0.1.250
s=Minisip Session
c=IN IP4 192.0.1.250
t=0 0
m=audio 33958 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
---ON THE UNIX SOCK (OK FROM SEMS)--------------------------------
200
OK
64360:678404969
00002EE029403E89
Contact: <sip:10033@192.0.1.150:5060>
Content-Type: application/sdp
Accept-Encoding: application/sdp, text/plain
Accept: INVITE, ACK, OPTIONS, BYE, CANCEL, MESSAGE
.
v=0
o=sems 1515487739 872624585 IN IP4 192.0.1.150
s=-
t=0 0
m=audio 7534 RTP/AVP 0
c=IN IP4 192.0.1.150
a=rtpmap:0 PCMU/8000
.
=============================================
=============================================
=============================================
#
#
# SER config file.
#
#
##################################################################################
# ----------- global configuration parameters ------------------------
fork=yes
children=2
disable_core_dump=yes
log_stderror=yes
debug=2
memlog=1000
listen=IP_LOCAL_SER
/* If not compiled with tls support, this param does not exhist */
disable_tls=0
/* See the first line of main route for another tls very important parameter!*/
tls_certificate="INSTALL_PATH/certs/MU_cert.pem"
tls_private_key="INSTALL_PATH/private/MU_prik.pem"
tls_ca_list="INSTALL_PATH/certs/ca_list.pem"
tls_ciphers_list="NULL-SHA:NULL-MD5:AES256-SHA:AES128-SHA"
#Related to force_tcp_alias (see below)
tcp_accept_aliases = yes
#Port to listen to ... this is the standard port where phones also listen ..
# Make sure that if any phone running in this same computer, uses
another port.
port=5060
#hostnames matching an alias that will satisfy the condition uri==myself
alias="DOMAIN_NAME"
alias="DOMAIN_SUB_PREFIX.DOMAIN_NAME"
check_via=no # (cmd. line: -v)
dns=no # (cmd. line: -r)
rev_dns=no # (cmd. line: -R)
# ------------------------- request routing logic -------------------
##################################################################################
#
# main routing logic
#
route{ #start route[ROUTE.MAIN]
==================================================
# initial sanity checks -- messages with max_forwards==0, or
excessively long requests
if (!mf_process_maxfwd_header("10")) {
sl_send_reply("483","Too Many Hops");
break;
};
if (msg:len >= max_len ) {
sl_send_reply("513", "Message too big");
break;
};
force_tcp_alias();
if (!method=="REGISTER" && !method=="CANCEL" &&
!method=="ACK" ) {
#record_route();
log(2, "LOG: Record route ... IP_LOCAL_SER\n");
record_route(); /*"IP_LOCAL_SER:5060");*/
};
if (loose_route()) {
# mark routing logic in request
log(2, "LOG: RR-enforced!\n");
append_hf("P-hint: rr-enforced\r\n");
setflag(FL_ROUTE_LOOSE); /* set source routed flag */
/* FIXME: It would be nice to have a way to authenticate loose
routed messages ... maybe with TLS ...
* but for now, just do nothing ... it only causes havoc */
log(2, "log: fixme!!! routed message ... \n");
route(ROUTE_RELAY); /* route to ROUTE.RELAY */
break;
};
#Forward messages not directed to us ...
if( ! (uri == myself) and ! is_uri_host_local() ) {
log( 2, "LOG: Message not for any of our domains ...\n");
XXXX
}; /*ends if ( ! uri == myself ...*/
if (method == "REGISTER" ) {
route(ROUTE_REGISTER_MESSAGE);
break;
}; #end if method is REGISTER
#REGISTER messages never go beyond this part
#Route Conference/SEMS related traffic
if ( message_needs_to_be_routed_to_sems ){
route( ROUTE_SEMS_TRAFFIC );
break;
#CONFERENCE related request should not go beyond this point
};
route(ROUTE_RELAY);
break;
} #ends route[ROUTE MAIN] =====================================================
route[ROUTE_RELAY] /*ROUTE RELAY*/
{
log( 2, "LOG: relaying default case ...\n");
lookup("aliases");
if( ! lookup("location") ) {
sl_send_reply("404", "Not Found");
break;
}
if (!t_relay()) {
log(2, "LOG: t_relay error!\n");
sl_reply_error();
break;
};
} /* #ends route[ROUTE_RELAY] */
route [ROUTE_REGISTER_MESSAGE] { /*ROUTE REGISTER MESSAGE*/
} /* ends route [ROUTE_REGISTER_MESSAGE]*/
###################################################################################
# All SEMS related traffic comes here
# Here non-REGISTER messages, such as INV and BYE are treated, and
# forwarded to sems.
#
route [ROUTE_SEMS_TRAFFIC] { /* ROUTE SEMS TRAFFIC*/
log(2, "LOG: request related to a CONFERENCE\n");
#switch to stateful mode
if(!t_newtran()){
sl_send_reply("500","colud not create transaction");
break;
};
log( 2, "LOG: Transaction created.\n");
if(method=="ACK"){
#absorb ACKs, SER's stateful transaction previously created
#will handle the ACK appropriately without passing them to SEMS
break;
};
t_reply("100", "Trying to contact Conference Server");
log( 2, "LOG: Provisional Response sent.\n");
if (method==INVITE || method==REFER || method==NOTIFY ||
method==SUBSCRIBE || method==OPTIONS || method==MESSAGE){
#assumes that Sems coinfiguration parameter 'fifo_name='
#has been set to /tmp/sems_fifo
if (!t_write_unix("/tmp/sems_sock","semsheaders")){
t_reply("500","error contacting sems");
};
break;
}else{
if(method==BYE || method==CANCEL){
#Sems should already know which plug-in is handling that call.
#"bye is no plug-in name. It is a reserved name which tells Sems
#to terminate the call
if (!t_write_unix("/tmp/sems_sock","bye")){
t_reply("500","error contacting sems");
};
break;
};
};
break;
}
#Terminate with at least one empty line, pliz
=============================================
=============================================
=============================================
=============================================
============================================================
[Wed Nov 23 11:31:49 2005]
2(11986) XLOG: xl_print_log: final buffer length 25
2(11986) [192.0.1.250 ## 11986]
2(11986) XLOG: xl_print_log: final buffer length 561
2(11986)
INVITE sip:10033@cafes.org SIP/2.0
From: <sip:jos@cafes.org>;tag=1455248939
To: <sip:10033@cafes.org>
Call-ID: 1832198372(a)192.0.1.250
CSeq: 301 INVITE
Contact: <sip:jos@192.0.1.250:6060;transport=UDP>;expires=1000
User-Agent: Minisip-Cafes-Tcnl
Content-Type: application/sdp
Via: SIP/2.0/UDP 192.0.1.250:6060;branch=z9hG4bK1238405167
Content-Length: 192
v=0
o=- 3344 3344 IN IP4 192.0.1.250
s=Minisip Session
c=IN IP4 192.0.1.250
t=0 0
m=audio 33958 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2(11986) parse_headers: flags=128
2(11986) DEBUG: get_hdr_body : content_length=192
2(11986) found end of header
2(11986) DEBUG: is_maxfwd_present: max_forwards header not found!
2(11986) LOG: Record route ... 192.0.1.150
2(11986) DEBUG: add_param: tag=1455248939
2(11986) end of header reached, state=29
2(11986) parse_headers: flags=256
2(11986) find_first_route: No Route headers found
2(11986) loose_route: There is no Route HF
2(11986) grep_sock_info - checking if host==us: 9==11 && [cafes.org]
== [192.0.1.150]
2(11986) grep_sock_info - checking if port 5060 matches port 5060
2(11986) grep_sock_info - checking if host==us: 9==10 && [cafes.org]
== [230.0.1.75]
2(11986) grep_sock_info - checking if port 5060 matches port 5060
2(11986) grep_sock_info - checking if host==us: 9==9 && [cafes.org]
== [127.0.0.1]
2(11986) grep_sock_info - checking if port 5060 matches port 5060
2(11986) grep_sock_info - checking if host==us: 9==11 && [cafes.org]
== [192.0.1.150]
2(11986) grep_sock_info - checking if port 5060 matches port 5060
2(11986) grep_sock_info - checking if host==us: 9==9 && [cafes.org]
== [127.0.0.1]
2(11986) grep_sock_info - checking if port 5060 matches port 5060
2(11986) grep_sock_info - checking if host==us: 9==11 && [cafes.org]
== [192.0.1.150]
2(11986) grep_sock_info - checking if port 5061 matches port 5060
2(11986) LOG: Identifying tags ... local, any, all, grp, conf ...
2(11986) LOG: identifying tag: conf.id@domain
2(11986) LOG: request related to a CONFERENCE
2(11986) sl_send_reply: start
2(11986) parse_headers: flags=-1
2(11986) check_via_address(192.0.1.250, 192.0.1.250, 0)
2(11986) sl_send_reply:(1) sl_timeout=get_ticks()+SL_RPL_WAIT_TIME=602734
2(11986) sl_send_reply:(2) sl_timeout=get_ticks()+SL_RPL_WAIT_TIME=602762
2(11986) DEBUG: t_newtran: msg id=1393 , global msg id=1392 , T on
entrance=0xffffffff
2(11986) parse_headers: flags=-1
2(11986) parse_headers: flags=60
2(11986) t_lookup_request: start searching: hash=64360, isACK=0
2(11986) DEBUG: RFC3261 transaction matching failed
2(11986) DEBUG: t_lookup_request: no transaction found
2(11986) LOG: Transaction created.
2(11986) LOG: Provisional Response sent.
2(11986) parse_headers: flags=-1
2(11986) DEBUG: t_check: msg id=1393 global id=1393 T start=0x4042900c
2(11986) DEBUG: t_check: T already found!
2(11986) assemble_msg: calculated route:
2(11986) assemble_msg: next r-uri: sip:jos@192.0.1.250:6060;transport=UDP
2(11986) parse_headers: flags=-1
2(11986) parse_headers: flags=-1
2(11986) DEBUG: add_to_tail_of_timer[0]: 0x40429134
2(11986) DEBUG:destroy_avp_list: destroying list (nil)
2(11986) receive_msg: cleaning up
1(11985) INFO: Deleting entry (location,10033)
1(11985) get_timeout: timeout: '5'
1(11985) get_method: method: 'REGISTER'
1(11985) get_ruri: 'sip:230.0.1.75'
1(11985) get_nexthop: next hop empty
1(11985) get_headers: From: <sip:10033@cafes.org>;tag=00002EE009A1E851
To: <sip:10033@cafes.org>
CSeq: 1 REGISTER
Call-ID: 00002EE07B210D73(a)192.0.1.150
1(11985) parse_headers: flags=-1
1(11985) end of header reached, state=9
1(11985) DEBUG: get_hdr_field: <To> [23]; uri=[sip:10033@cafes.org]
1(11985) DEBUG: to body [<sip:10033@cafes.org>
]
1(11985) get_hdr_field: cseq <CSeq>: <1> <REGISTER>
1(11985) get_body_lines:
1(11985) DEBUG: add_param: tag=00002EE009A1E851
1(11985) end of header reached, state=29
1(11985) uac_unixsock: set_loc_timers: transaction avp parameters set to 5
1(11985) DEBUG:tm:t_uac: next_hop=<sip:230.0.1.75>
1(11985) DEBUG: mk_proxy: doing DNS lookup...
1(11985) DEBUG:destroy_avp_list: destroying list (nil)
1(11985) DEBUG: dlg2hash: 34757
1(11985) DEBUG: add_to_tail_of_timer[4]: 0x40433f6c
1(11985) DEBUG: add_to_tail_of_timer[0]: 0x40433f7c
4(11988) SIP Request:
4(11988) method: <REGISTER>
4(11988) uri: <sip:230.0.1.75>
4(11988) version: <SIP/2.0>
4(11988) parse_headers: flags=1
4(11988) Found param type 232, <branch> = <z9hG4bK5c78.6c8171b3.0>; state=16
4(11988) end of header reached, state=5
4(11988) parse_headers: Via found, flags=1
4(11988) parse_headers: this is the first via
4(11988) After parse_msg...
4(11988) preparing to run routing scripts...
4(11988) CESC: exec_pre_cb: start calling precallback scripts!!!
4(11988) CESC: exec_pre_cb: pre script callback called!!
4(11988) TIC:tic_response_callback: starting
4(11988) DEBUG : tic_response_callback : only checking replies
4(11988) TIC:tic_response_callback: No operation
4(11988) CESC: exec_pre_cb: pre script callback called!!
4(11988) CESC: exec_pre_cb: pre script callback called!!
4(11988) LOG: ERROR: We got a message looped back from the multicast
address, sent by ourselves.
4(11988) LOG: ERROR: Discarding this message
4(11988) parse_headers: flags=8
4(11988) end of header reached, state=9
4(11988) DEBUG: get_hdr_field: <To> [23]; uri=[sip:10033@cafes.org]
4(11988) DEBUG: to body [<sip:10033@cafes.org>
]
4(11988) DEBUG: add_param: tag=00002EE009A1E851
4(11988) end of header reached, state=29
4(11988) XLOG: xl_print_log: final buffer length 96
4(11988)
REGISTER 230.0.1.75
From: sip:10033@cafes.org;00002EE009A1E851
To: sip:10033@cafes.org;<null>
4(11988) DEBUG:destroy_avp_list: destroying list (nil)
4(11988) receive_msg: cleaning up
1(11985) parse_transid: hash_index=64360 label=678404969
1(11985) lineset: Contact: <sip:10033@192.0.1.150:5060>
Content-Type: application/sdp
Accept-Encoding: application/sdp, text/plain
Accept: INVITE, ACK, OPTIONS, BYE, CANCEL, MESSAGE
1(11985) body: v=0
o=sems 1515487739 872624585 IN IP4 192.0.1.150
s=-
t=0 0
m=audio 7534 RTP/AVP 0
c=IN IP4 192.0.1.150
a=rtpmap:0 PCMU/8000
1(11985) DEBUG: t_lookup_ident: transaction found
1(11985) parse_headers: flags=-1
1(11985) check_via_address(192.0.1.250, 192.0.1.250, 0)
1(11985) DEBUG: cleanup_uac_timers: RETR/FR timers reset
1(11985) DEBUG: add_to_tail_of_timer[4]: 0x404290b8
1(11985) DEBUG: add_to_tail_of_timer[0]: 0x404290c8
1(11985) DEBUG: reply sent out. buf=0x820bd04: SIP/2.0 2...,
shmem=0x40431bd4: SIP/2.0 2
1(11985) DEBUG: _reply_light: finished
3(11987) SIP Request:
3(11987) method: <ACK>
3(11987) uri: <sip:10033@192.0.1.150:5060>
3(11987) version: <SIP/2.0>
3(11987) parse_headers: flags=1
3(11987) DEBUG: add_param: tag=00002EE029403E89
3(11987) end of header reached, state=29
3(11987) DEBUG: get_hdr_field: <To> [44]; uri=[sip:10033@cafes.org]
3(11987) DEBUG: to body [<sip:10033@cafes.org>]
3(11987) get_hdr_field: cseq <CSeq>: <301> <ACK>
3(11987) Found param type 232, <branch> = <z9hG4bK1238405167>; state=16
3(11987) end of header reached, state=5
3(11987) parse_headers: Via found, flags=1
3(11987) parse_headers: this is the first via
3(11987) After parse_msg...
3(11987) preparing to run routing scripts...
3(11987) CESC: exec_pre_cb: start calling precallback scripts!!!
3(11987) CESC: exec_pre_cb: pre script callback called!!
3(11987) TIC:tic_response_callback: starting
3(11987) DEBUG : tic_response_callback : only checking replies
3(11987) TIC:tic_response_callback: No operation
3(11987) CESC: exec_pre_cb: pre script callback called!!
3(11987) CESC: exec_pre_cb: pre script callback called!!
3(11987) ERROR : SL_FILTER_ACK: *(sl_timeout)=602762, get_ticks()=602760
3(11987) parse_headers: flags=4
3(11987) ERROR : SL_FILTER_ACK: before if(msg->to)
3(11987) ERROR : SL_FILTER_ACK: inside if(msg->to)
3(11987) ERROR : SL_FILTER_ACK: tag_str.len=16, TOTAG_VALUE_LEN=37
3(11987) ERROR : SL_FILTER_ACK: tag_str.s=00002EE029403E89;
sl_tag.s=f0ecfd42b179c81ffc953dd05dc8350b.ba0d
3(11987) ERROR : sl_filter_ACK : NO local ACK found
3(11987) XLOG: xl_print_log: final buffer length 91
3(11987)
============================================================
[Wed Nov 23 11:31:49 2005]
3(11987) XLOG: xl_print_log: final buffer length 25
3(11987) [192.0.1.250 ## 11987]
3(11987) XLOG: xl_print_log: final buffer length 280
3(11987)
ACK sip:10033@192.0.1.150:5060 SIP/2.0
Max-Forwards: 70
From: <sip:jos@cafes.org>;tag=1455248939
To: <sip:10033@cafes.org>;tag=00002EE029403E89
Call-ID: 1832198372(a)192.0.1.250
CSeq: 301 ACK
Via: SIP/2.0/UDP 192.0.1.250:6060;branch=z9hG4bK1238405167
Content-Length: 0
3(11987) DEBUG:maxfwd:is_maxfwd_present: value = 70
3(11987) DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16
3(11987) parse_headers: flags=256
3(11987) DEBUG: get_hdr_body : content_length=0
3(11987) found end of header
3(11987) find_first_route: No Route headers found
3(11987) loose_route: There is no Route HF
3(11987) grep_sock_info - checking if host==us: 11==11 &&
[192.0.1.150] == [192.0.1.150]
3(11987) grep_sock_info - checking if port 5060 matches port 5060
3(11987) LOG: Identifying tags ... local, any, all, grp, conf ...
3(11987) LOG: identifying tag: conf.id@domain
3(11987) LOG: request related to a CONFERENCE
3(11987) sl_send_reply: start
3(11987) Warning: sl_send_reply: I won't send a reply for ACK!!
3(11987) LOG: ACK intercom received ...
3(11987) DEBUG: t_check: msg id=1674 global id=1673 T start=0xffffffff
3(11987) parse_headers: flags=-1
3(11987) parse_headers: flags=60
3(11987) t_lookup_request: start searching: hash=64360, isACK=1
3(11987) parse_headers: flags=28
3(11987) DEBUG: add_param: tag=1455248939
3(11987) end of header reached, state=29
3(11987) DEBUG: t_lookup_request: e2e proxy ACK found
3(11987) DEBUG: t_check: msg id=1674 global id=1674 T end=(nil)
3(11987) LOG: ACK intercom transaction DOES NOT exhist ... simply absorbing
3(11987) DEBUG:destroy_avp_list: destroying list (nil)
3(11987) receive_msg: cleaning up
8(11992) timer_ticker()!!!
8(11992) DEBUG: timer routine:0,tl=0x40429134 next=(nil)
8(11992) DEBUG: timer routine:4,tl=0x40433f6c next=0x404290b8
8(11992) DEBUG: retransmission_handler : request resending
(t=0x40433e54, REGISTER ... )
8(11992) DEBUG: add_to_tail_of_timer[5]: 0x40433f6c
8(11992) DEBUG: retransmission_handler : done
8(11992) DEBUG: timer routine:4,tl=0x404290b8 next=(nil)
8(11992) DEBUG: retransmission_handler : reply resending
(t=0x4042900c, SIP/2.0 2 ... )
8(11992) DEBUG: reply retransmitted. buf=0x401a4620: SIP/2.0 2...,
shmem=0x40431bd4: SIP/2.0 2
8(11992) DEBUG: add_to_tail_of_timer[5]: 0x404290b8
8(11992) DEBUG: retransmission_handler : done
=====================================================
On 11/23/05, Jan Janak <jan(a)iptel.org> wrote:
Actually I've seen the mail but did not have yet
time to look into it
(I have it on my todo list).
When communicating with applications like sems over the fifo or unix
sockets, SER takes care of ACK processing (that also means generating
local e2e ACKs on behalf of sems). This is a hack because tm has to do
all the dialog-related logic (such as route processing, loose/strict
routing and so on).
Inside tm end-to-end ACKs are matched with the original INVITE
transaction. This was needed for accounting purposes, if I recall it correctly.
In any case full tm traces would be helpful, especially for P3.
Jan.
On 23-11-2005 10:38, Cesc wrote:
Hi Greger,
First, the last half of your email ... i cannot run a dedicated
instance of SER. We run an embedded system, thus not much space and
power to spare.
As for the NAT ... we have no NAT in our network (lucky us :D ).
As for the first part ... i had not seen a response either :)
Actually, i lost the email in gmail folders, could not find it
anywhere ... tks for replying, now i found it again.
As for the ACK ... i tried using t_lookup_request ... it turns out
that it does find a transaction, but it identifies them as e2e (i
guess ... end2end) ... i will investigate further ... and i will
provide a trace.
Tks!
Cesc
On 11/23/05, Greger V. Teigre <greger(a)teigre.com> wrote:
Hi Cesc,
I haven't seen a response to your post?! Are you sure the ACKs are not
caught by loose routing?
I would suggest setting up a separate ser instance on ex. port 5062 and
dedicate it to sems interfacing. Then in your main ser you just correctly
forwards the INVITEs to the sems ser instance. Also remember to run
fix_nated_sdp("3") for NATed clients (SEMS support active media. Both sems
and SER-SEMS should run on a public IP.
g-)
----- Original Message -----
From: "Cesc" <cesc.santa(a)gmail.com>
To: "SER-Users" <serusers(a)lists.iptel.org>
Sent: Wednesday, November 16, 2005 11:13 AM
Subject: [Serusers] Local ACKs for SER-SEMS
_______________________________________________
Serusers mailing list
serusers(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serusers Hi,
In my lab we have SER (0.9.4) running, collocated in the same box with
SEMS, communicating via the fifo.
An abstraction of the config:
//identify traffic for SEMS
//send to route[x]
route[x] {
if( !t_newtran() ) { ..... }
if( method == "ACK" ) { break;} //drop local acks ...
t_reply("100", "msg");
send via fifo to sems ...
}
I have stumbled against some problems:
P1) Local ACKs from the phone are not being dropped.
P2) to-tag in replies from SER from sl_send_reply and OK message change
P3) the t_newtran does not stop sending OKs, even it receives ACKs to them
They all seem to be related ...
the ACK from the phone back to SER, which are local(right?), are not
dropped for two reasons: the sl_timeout is not updated, as i don't
have an sl_send_reply in the route[x] block.
I can fix the above by adding an sl_send_reply("183", "sems session in
progress") ... but then, the second problem appears.
Adding the sl_send_reply(183, ) adds a to-tag to the 183-reply, but
then the following OK has a completely different to-tag ... which is
the one used by my UA to create the ACK. As the to-tag in the ACK is
different to that from the 183-reply ... the sl_filter_ack does not
recognize the ACK as local, and does not filter it.
In any case, this would not solve the problem of the t_newtran sending
OK replies to the phone, even it receives ACKs to them.
What can i do? should i use t_release somewhere? are these ACKs
"local"? if not, where should these ACKs be routed to, to the route[x]
block?
Tks in advance,
Cesc
_______________________________________________
Serusers mailing list
serusers(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serusers
24 Nov
24 Nov
10:23 a.m.
Cesc,
I've tried to find some meaning in what you sent, but I don't really know
the details of the ACK hack (pun not intended) Jan mentioned. To me it looks
like the ACK is absorbed correctly. However, the REGISTER messages confuses
me a bit. Also, you don't record_route CANCELs and ACKs, why?
g-)
----- Original Message -----
From: "Cesc" <cesc.santa(a)gmail.com>
To: "Cesc" <cesc.santa(a)gmail.com>om>; "Greger V. Teigre"
<greger(a)teigre.com>om>;
"SER-Users" <serusers(a)lists.iptel.org>
Sent: Wednesday, November 23, 2005 12:31 PM
Subject: Re: [Serusers] Local ACKs for SER-SEMS
Hi,
I attach a tar'd.gz file with: a snippet of the ser.cfg file, a ser
log and the messages (INV and OK) passed from-to ser-sems unix socket.
I attach directly to this email a short version of the ser.log file
and ser.cfg, for easyness ... hopefully it will go through ...
Hope it helps,
Cesc
=============================================
=============================================
=====================================================
== ON THE UNIX SOCK (INVITE FROM SER)
=============================================
0.3
sip_request.intercom
INVITE
10033
cafes.org
192.0.1.150
.
sip:10033@cafes.org
sip:jos@192.0.1.250:6060;transport=UDP
<sip:jos@cafes.org>
<sip:10033@cafes.org>
1832198372(a)192.0.1.250
1455248939
301
64360:678404969
.
.
P-MsgFlags: 0
Content-Type: application/sdp
.
v=0
o=- 3344 3344 IN IP4 192.0.1.250
s=Minisip Session
c=IN IP4 192.0.1.250
t=0 0
m=audio 33958 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
---ON THE UNIX SOCK (OK FROM SEMS)--------------------------------
200
OK
64360:678404969
00002EE029403E89
Contact: <sip:10033@192.0.1.150:5060>
Content-Type: application/sdp
Accept-Encoding: application/sdp, text/plain
Accept: INVITE, ACK, OPTIONS, BYE, CANCEL, MESSAGE
.
v=0
o=sems 1515487739 872624585 IN IP4 192.0.1.150
s=-
t=0 0
m=audio 7534 RTP/AVP 0
c=IN IP4 192.0.1.150
a=rtpmap:0 PCMU/8000
.
=============================================
=============================================
=============================================
#
#
# SER config file.
#
#
##################################################################################
# ----------- global configuration parameters ------------------------
fork=yes
children=2
disable_core_dump=yes
log_stderror=yes
debug=2
memlog=1000
listen=IP_LOCAL_SER
/* If not compiled with tls support, this param does not exhist */
disable_tls=0
/* See the first line of main route for another tls very important
parameter!*/
tls_certificate="INSTALL_PATH/certs/MU_cert.pem"
tls_private_key="INSTALL_PATH/private/MU_prik.pem"
tls_ca_list="INSTALL_PATH/certs/ca_list.pem"
tls_ciphers_list="NULL-SHA:NULL-MD5:AES256-SHA:AES128-SHA"
#Related to force_tcp_alias (see below)
tcp_accept_aliases = yes
#Port to listen to ... this is the standard port where phones also listen ..
# Make sure that if any phone running in this same computer, uses
another port.
port=5060
#hostnames matching an alias that will satisfy the condition uri==myself
alias="DOMAIN_NAME"
alias="DOMAIN_SUB_PREFIX.DOMAIN_NAME"
check_via=no # (cmd. line: -v)
dns=no # (cmd. line: -r)
rev_dns=no # (cmd. line: -R)
# ------------------------- request routing logic -------------------
##################################################################################
#
# main routing logic
#
route{ #start route[ROUTE.MAIN]
==================================================
# initial sanity checks -- messages with max_forwards==0, or
excessively long requests
if (!mf_process_maxfwd_header("10")) {
sl_send_reply("483","Too Many Hops");
break;
};
if (msg:len >= max_len ) {
sl_send_reply("513", "Message too big");
break;
};
force_tcp_alias();
if (!method=="REGISTER" && !method=="CANCEL" &&
!method=="ACK" ) {
#record_route();
log(2, "LOG: Record route ... IP_LOCAL_SER\n");
record_route(); /*"IP_LOCAL_SER:5060");*/
};
if (loose_route()) {
# mark routing logic in request
log(2, "LOG: RR-enforced!\n");
append_hf("P-hint: rr-enforced\r\n");
setflag(FL_ROUTE_LOOSE); /* set source routed flag */
/* FIXME: It would be nice to have a way to authenticate loose
routed messages ... maybe with TLS ...
* but for now, just do nothing ... it only causes havoc */
log(2, "log: fixme!!! routed message ... \n");
route(ROUTE_RELAY); /* route to ROUTE.RELAY */
break;
};
#Forward messages not directed to us ...
if( ! (uri == myself) and ! is_uri_host_local() ) {
log( 2, "LOG: Message not for any of our domains ...\n");
XXXX
}; /*ends if ( ! uri == myself ...*/
if (method == "REGISTER" ) {
route(ROUTE_REGISTER_MESSAGE);
break;
}; #end if method is REGISTER
#REGISTER messages never go beyond this part
#Route Conference/SEMS related traffic
if ( message_needs_to_be_routed_to_sems ){
route( ROUTE_SEMS_TRAFFIC );
break;
#CONFERENCE related request should not go beyond this point
};
route(ROUTE_RELAY);
break;
} #ends route[ROUTE MAIN]
=====================================================
route[ROUTE_RELAY] /*ROUTE RELAY*/
{
log( 2, "LOG: relaying default case ...\n");
lookup("aliases");
if( ! lookup("location") ) {
sl_send_reply("404", "Not Found");
break;
}
if (!t_relay()) {
log(2, "LOG: t_relay error!\n");
sl_reply_error();
break;
};
} /* #ends route[ROUTE_RELAY] */
route [ROUTE_REGISTER_MESSAGE] { /*ROUTE REGISTER MESSAGE*/
} /* ends route [ROUTE_REGISTER_MESSAGE]*/
###################################################################################
# All SEMS related traffic comes here
# Here non-REGISTER messages, such as INV and BYE are treated, and
# forwarded to sems.
#
route [ROUTE_SEMS_TRAFFIC] { /* ROUTE SEMS TRAFFIC*/
log(2, "LOG: request related to a CONFERENCE\n");
#switch to stateful mode
if(!t_newtran()){
sl_send_reply("500","colud not create transaction");
break;
};
log( 2, "LOG: Transaction created.\n");
if(method=="ACK"){
#absorb ACKs, SER's stateful transaction previously created
#will handle the ACK appropriately without passing them to SEMS
break;
};
t_reply("100", "Trying to contact Conference Server");
log( 2, "LOG: Provisional Response sent.\n");
if (method==INVITE || method==REFER || method==NOTIFY ||
method==SUBSCRIBE || method==OPTIONS || method==MESSAGE){
#assumes that Sems coinfiguration parameter 'fifo_name='
#has been set to /tmp/sems_fifo
if (!t_write_unix("/tmp/sems_sock","semsheaders")){
t_reply("500","error contacting sems");
};
break;
}else{
if(method==BYE || method==CANCEL){
#Sems should already know which plug-in is handling that call.
#"bye is no plug-in name. It is a reserved name which tells Sems
#to terminate the call
if (!t_write_unix("/tmp/sems_sock","bye")){
t_reply("500","error contacting sems");
};
break;
};
};
break;
}
#Terminate with at least one empty line, pliz
=============================================
=============================================
=============================================
=============================================
============================================================
[Wed Nov 23 11:31:49 2005]
2(11986) XLOG: xl_print_log: final buffer length 25
2(11986) [192.0.1.250 ## 11986]
2(11986) XLOG: xl_print_log: final buffer length 561
2(11986)
INVITE sip:10033@cafes.org SIP/2.0
From: <sip:jos@cafes.org>;tag=1455248939
To: <sip:10033@cafes.org>
Call-ID: 1832198372(a)192.0.1.250
CSeq: 301 INVITE
Contact: <sip:jos@192.0.1.250:6060;transport=UDP>;expires=1000
User-Agent: Minisip-Cafes-Tcnl
Content-Type: application/sdp
Via: SIP/2.0/UDP 192.0.1.250:6060;branch=z9hG4bK1238405167
Content-Length: 192
v=0
o=- 3344 3344 IN IP4 192.0.1.250
s=Minisip Session
c=IN IP4 192.0.1.250
t=0 0
m=audio 33958 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000/1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2(11986) parse_headers: flags=128
2(11986) DEBUG: get_hdr_body : content_length=192
2(11986) found end of header
2(11986) DEBUG: is_maxfwd_present: max_forwards header not found!
2(11986) LOG: Record route ... 192.0.1.150
2(11986) DEBUG: add_param: tag=1455248939
2(11986) end of header reached, state=29
2(11986) parse_headers: flags=256
2(11986) find_first_route: No Route headers found
2(11986) loose_route: There is no Route HF
2(11986) grep_sock_info - checking if host==us: 9==11 && [cafes.org]
== [192.0.1.150]
2(11986) grep_sock_info - checking if port 5060 matches port 5060
2(11986) grep_sock_info - checking if host==us: 9==10 && [cafes.org]
== [230.0.1.75]
2(11986) grep_sock_info - checking if port 5060 matches port 5060
2(11986) grep_sock_info - checking if host==us: 9==9 && [cafes.org]
== [127.0.0.1]
2(11986) grep_sock_info - checking if port 5060 matches port 5060
2(11986) grep_sock_info - checking if host==us: 9==11 && [cafes.org]
== [192.0.1.150]
2(11986) grep_sock_info - checking if port 5060 matches port 5060
2(11986) grep_sock_info - checking if host==us: 9==9 && [cafes.org]
== [127.0.0.1]
2(11986) grep_sock_info - checking if port 5060 matches port 5060
2(11986) grep_sock_info - checking if host==us: 9==11 && [cafes.org]
== [192.0.1.150]
2(11986) grep_sock_info - checking if port 5061 matches port 5060
2(11986) LOG: Identifying tags ... local, any, all, grp, conf ...
2(11986) LOG: identifying tag: conf.id@domain
2(11986) LOG: request related to a CONFERENCE
2(11986) sl_send_reply: start
2(11986) parse_headers: flags=-1
2(11986) check_via_address(192.0.1.250, 192.0.1.250, 0)
2(11986) sl_send_reply:(1) sl_timeout=get_ticks()+SL_RPL_WAIT_TIME=602734
2(11986) sl_send_reply:(2) sl_timeout=get_ticks()+SL_RPL_WAIT_TIME=602762
2(11986) DEBUG: t_newtran: msg id=1393 , global msg id=1392 , T on
entrance=0xffffffff
2(11986) parse_headers: flags=-1
2(11986) parse_headers: flags=60
2(11986) t_lookup_request: start searching: hash=64360, isACK=0
2(11986) DEBUG: RFC3261 transaction matching failed
2(11986) DEBUG: t_lookup_request: no transaction found
2(11986) LOG: Transaction created.
2(11986) LOG: Provisional Response sent.
2(11986) parse_headers: flags=-1
2(11986) DEBUG: t_check: msg id=1393 global id=1393 T start=0x4042900c
2(11986) DEBUG: t_check: T already found!
2(11986) assemble_msg: calculated route:
2(11986) assemble_msg: next r-uri: sip:jos@192.0.1.250:6060;transport=UDP
2(11986) parse_headers: flags=-1
2(11986) parse_headers: flags=-1
2(11986) DEBUG: add_to_tail_of_timer[0]: 0x40429134
2(11986) DEBUG:destroy_avp_list: destroying list (nil)
2(11986) receive_msg: cleaning up
1(11985) INFO: Deleting entry (location,10033)
1(11985) get_timeout: timeout: '5'
1(11985) get_method: method: 'REGISTER'
1(11985) get_ruri: 'sip:230.0.1.75'
1(11985) get_nexthop: next hop empty
1(11985) get_headers: From: <sip:10033@cafes.org>;tag=00002EE009A1E851
To: <sip:10033@cafes.org>
CSeq: 1 REGISTER
Call-ID: 00002EE07B210D73(a)192.0.1.150
1(11985) parse_headers: flags=-1
1(11985) end of header reached, state=9
1(11985) DEBUG: get_hdr_field: <To> [23]; uri=[sip:10033@cafes.org]
1(11985) DEBUG: to body [<sip:10033@cafes.org>
]
1(11985) get_hdr_field: cseq <CSeq>: <1> <REGISTER>
1(11985) get_body_lines:
1(11985) DEBUG: add_param: tag=00002EE009A1E851
1(11985) end of header reached, state=29
1(11985) uac_unixsock: set_loc_timers: transaction avp parameters set to 5
1(11985) DEBUG:tm:t_uac: next_hop=<sip:230.0.1.75>
1(11985) DEBUG: mk_proxy: doing DNS lookup...
1(11985) DEBUG:destroy_avp_list: destroying list (nil)
1(11985) DEBUG: dlg2hash: 34757
1(11985) DEBUG: add_to_tail_of_timer[4]: 0x40433f6c
1(11985) DEBUG: add_to_tail_of_timer[0]: 0x40433f7c
4(11988) SIP Request:
4(11988) method: <REGISTER>
4(11988) uri: <sip:230.0.1.75>
4(11988) version: <SIP/2.0>
4(11988) parse_headers: flags=1
4(11988) Found param type 232, <branch> = <z9hG4bK5c78.6c8171b3.0>;
state=16
4(11988) end of header reached, state=5
4(11988) parse_headers: Via found, flags=1
4(11988) parse_headers: this is the first via
4(11988) After parse_msg...
4(11988) preparing to run routing scripts...
4(11988) CESC: exec_pre_cb: start calling precallback scripts!!!
4(11988) CESC: exec_pre_cb: pre script callback called!!
4(11988) TIC:tic_response_callback: starting
4(11988) DEBUG : tic_response_callback : only checking replies
4(11988) TIC:tic_response_callback: No operation
4(11988) CESC: exec_pre_cb: pre script callback called!!
4(11988) CESC: exec_pre_cb: pre script callback called!!
4(11988) LOG: ERROR: We got a message looped back from the multicast
address, sent by ourselves.
4(11988) LOG: ERROR: Discarding this message
4(11988) parse_headers: flags=8
4(11988) end of header reached, state=9
4(11988) DEBUG: get_hdr_field: <To> [23]; uri=[sip:10033@cafes.org]
4(11988) DEBUG: to body [<sip:10033@cafes.org>
]
4(11988) DEBUG: add_param: tag=00002EE009A1E851
4(11988) end of header reached, state=29
4(11988) XLOG: xl_print_log: final buffer length 96
4(11988)
REGISTER 230.0.1.75
From: sip:10033@cafes.org;00002EE009A1E851
To: sip:10033@cafes.org;<null>
4(11988) DEBUG:destroy_avp_list: destroying list (nil)
4(11988) receive_msg: cleaning up
1(11985) parse_transid: hash_index=64360 label=678404969
1(11985) lineset: Contact: <sip:10033@192.0.1.150:5060>
Content-Type: application/sdp
Accept-Encoding: application/sdp, text/plain
Accept: INVITE, ACK, OPTIONS, BYE, CANCEL, MESSAGE
1(11985) body: v=0
o=sems 1515487739 872624585 IN IP4 192.0.1.150
s=-
t=0 0
m=audio 7534 RTP/AVP 0
c=IN IP4 192.0.1.150
a=rtpmap:0 PCMU/8000
1(11985) DEBUG: t_lookup_ident: transaction found
1(11985) parse_headers: flags=-1
1(11985) check_via_address(192.0.1.250, 192.0.1.250, 0)
1(11985) DEBUG: cleanup_uac_timers: RETR/FR timers reset
1(11985) DEBUG: add_to_tail_of_timer[4]: 0x404290b8
1(11985) DEBUG: add_to_tail_of_timer[0]: 0x404290c8
1(11985) DEBUG: reply sent out. buf=0x820bd04: SIP/2.0 2...,
shmem=0x40431bd4: SIP/2.0 2
1(11985) DEBUG: _reply_light: finished
3(11987) SIP Request:
3(11987) method: <ACK>
3(11987) uri: <sip:10033@192.0.1.150:5060>
3(11987) version: <SIP/2.0>
3(11987) parse_headers: flags=1
3(11987) DEBUG: add_param: tag=00002EE029403E89
3(11987) end of header reached, state=29
3(11987) DEBUG: get_hdr_field: <To> [44]; uri=[sip:10033@cafes.org]
3(11987) DEBUG: to body [<sip:10033@cafes.org>]
3(11987) get_hdr_field: cseq <CSeq>: <301> <ACK>
3(11987) Found param type 232, <branch> = <z9hG4bK1238405167>; state=16
3(11987) end of header reached, state=5
3(11987) parse_headers: Via found, flags=1
3(11987) parse_headers: this is the first via
3(11987) After parse_msg...
3(11987) preparing to run routing scripts...
3(11987) CESC: exec_pre_cb: start calling precallback scripts!!!
3(11987) CESC: exec_pre_cb: pre script callback called!!
3(11987) TIC:tic_response_callback: starting
3(11987) DEBUG : tic_response_callback : only checking replies
3(11987) TIC:tic_response_callback: No operation
3(11987) CESC: exec_pre_cb: pre script callback called!!
3(11987) CESC: exec_pre_cb: pre script callback called!!
3(11987) ERROR : SL_FILTER_ACK: *(sl_timeout)=602762, get_ticks()=602760
3(11987) parse_headers: flags=4
3(11987) ERROR : SL_FILTER_ACK: before if(msg->to)
3(11987) ERROR : SL_FILTER_ACK: inside if(msg->to)
3(11987) ERROR : SL_FILTER_ACK: tag_str.len=16, TOTAG_VALUE_LEN=37
3(11987) ERROR : SL_FILTER_ACK: tag_str.s=00002EE029403E89;
sl_tag.s=f0ecfd42b179c81ffc953dd05dc8350b.ba0d
3(11987) ERROR : sl_filter_ACK : NO local ACK found
3(11987) XLOG: xl_print_log: final buffer length 91
3(11987)
============================================================
[Wed Nov 23 11:31:49 2005]
3(11987) XLOG: xl_print_log: final buffer length 25
3(11987) [192.0.1.250 ## 11987]
3(11987) XLOG: xl_print_log: final buffer length 280
3(11987)
ACK sip:10033@192.0.1.150:5060 SIP/2.0
Max-Forwards: 70
From: <sip:jos@cafes.org>;tag=1455248939
To: <sip:10033@cafes.org>;tag=00002EE029403E89
Call-ID: 1832198372(a)192.0.1.250
CSeq: 301 ACK
Via: SIP/2.0/UDP 192.0.1.250:6060;branch=z9hG4bK1238405167
Content-Length: 0
3(11987) DEBUG:maxfwd:is_maxfwd_present: value = 70
3(11987) DBG:maxfwd:process_maxfwd_header: value 70 decreased to 16
3(11987) parse_headers: flags=256
3(11987) DEBUG: get_hdr_body : content_length=0
3(11987) found end of header
3(11987) find_first_route: No Route headers found
3(11987) loose_route: There is no Route HF
3(11987) grep_sock_info - checking if host==us: 11==11 &&
[192.0.1.150] == [192.0.1.150]
3(11987) grep_sock_info - checking if port 5060 matches port 5060
3(11987) LOG: Identifying tags ... local, any, all, grp, conf ...
3(11987) LOG: identifying tag: conf.id@domain
3(11987) LOG: request related to a CONFERENCE
3(11987) sl_send_reply: start
3(11987) Warning: sl_send_reply: I won't send a reply for ACK!!
3(11987) LOG: ACK intercom received ...
3(11987) DEBUG: t_check: msg id=1674 global id=1673 T start=0xffffffff
3(11987) parse_headers: flags=-1
3(11987) parse_headers: flags=60
3(11987) t_lookup_request: start searching: hash=64360, isACK=1
3(11987) parse_headers: flags=28
3(11987) DEBUG: add_param: tag=1455248939
3(11987) end of header reached, state=29
3(11987) DEBUG: t_lookup_request: e2e proxy ACK found
3(11987) DEBUG: t_check: msg id=1674 global id=1674 T end=(nil)
3(11987) LOG: ACK intercom transaction DOES NOT exhist ... simply absorbing
3(11987) DEBUG:destroy_avp_list: destroying list (nil)
3(11987) receive_msg: cleaning up
8(11992) timer_ticker()!!!
8(11992) DEBUG: timer routine:0,tl=0x40429134 next=(nil)
8(11992) DEBUG: timer routine:4,tl=0x40433f6c next=0x404290b8
8(11992) DEBUG: retransmission_handler : request resending
(t=0x40433e54, REGISTER ... )
8(11992) DEBUG: add_to_tail_of_timer[5]: 0x40433f6c
8(11992) DEBUG: retransmission_handler : done
8(11992) DEBUG: timer routine:4,tl=0x404290b8 next=(nil)
8(11992) DEBUG: retransmission_handler : reply resending
(t=0x4042900c, SIP/2.0 2 ... )
8(11992) DEBUG: reply retransmitted. buf=0x401a4620: SIP/2.0 2...,
shmem=0x40431bd4: SIP/2.0 2
8(11992) DEBUG: add_to_tail_of_timer[5]: 0x404290b8
8(11992) DEBUG: retransmission_handler : done
=====================================================
On 11/23/05, Jan Janak <jan(a)iptel.org> wrote:
Actually I've seen the mail but did not have yet
time to look into it
(I have it on my todo list).
When communicating with applications like sems over the fifo or unix
sockets, SER takes care of ACK processing (that also means generating
local e2e ACKs on behalf of sems). This is a hack because tm has to do
all the dialog-related logic (such as route processing, loose/strict
routing and so on).
Inside tm end-to-end ACKs are matched with the original INVITE
transaction. This was needed for accounting purposes, if I recall it
correctly.
In any case full tm traces would be helpful, especially for P3.
Jan.
On 23-11-2005 10:38, Cesc wrote:
Hi Greger,
First, the last half of your email ... i cannot run a dedicated
instance of SER. We run an embedded system, thus not much space and
power to spare.
As for the NAT ... we have no NAT in our network (lucky us :D ).
As for the first part ... i had not seen a response either :)
Actually, i lost the email in gmail folders, could not find it
anywhere ... tks for replying, now i found it again.
As for the ACK ... i tried using t_lookup_request ... it turns out
that it does find a transaction, but it identifies them as e2e (i
guess ... end2end) ... i will investigate further ... and i will
provide a trace.
Tks!
Cesc
On 11/23/05, Greger V. Teigre <greger(a)teigre.com> wrote:
Hi Cesc,
I haven't seen a response to your post?! Are you sure the ACKs are not
caught by loose routing?
I would suggest setting up a separate ser instance on ex. port 5062
and
dedicate it to sems interfacing. Then in your main ser you just
correctly
forwards the INVITEs to the sems ser instance. Also remember to run
fix_nated_sdp("3") for NATed clients (SEMS support active media. Both
sems
and SER-SEMS should run on a public IP.
g-)
----- Original Message -----
From: "Cesc" <cesc.santa(a)gmail.com>
To: "SER-Users" <serusers(a)lists.iptel.org>
Sent: Wednesday, November 16, 2005 11:13 AM
Subject: [Serusers] Local ACKs for SER-SEMS
_______________________________________________
Serusers mailing list
serusers(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serusers Hi,
In my lab we have SER (0.9.4) running, collocated in the same box
with
SEMS, communicating via the fifo.
An abstraction of the config:
//identify traffic for SEMS
//send to route[x]
route[x] {
if( !t_newtran() ) { ..... }
if( method == "ACK" ) { break;} //drop local acks ...
t_reply("100", "msg");
send via fifo to sems ...
}
I have stumbled against some problems:
P1) Local ACKs from the phone are not being dropped.
P2) to-tag in replies from SER from sl_send_reply and OK message
change
P3) the t_newtran does not stop sending OKs, even it receives ACKs
to them
They all seem to be related ...
the ACK from the phone back to SER, which are local(right?), are not
dropped for two reasons: the sl_timeout is not updated, as i don't
have an sl_send_reply in the route[x] block.
I can fix the above by adding an sl_send_reply("183", "sems session
in
progress") ... but then, the second problem appears.
Adding the sl_send_reply(183, ) adds a to-tag to the 183-reply, but
then the following OK has a completely different to-tag ... which is
the one used by my UA to create the ACK. As the to-tag in the ACK is
different to that from the 183-reply ... the sl_filter_ack does not
recognize the ACK as local, and does not filter it.
In any case, this would not solve the problem of the t_newtran
sending
OK replies to the phone, even it receives ACKs to them.
What can i do? should i use t_release somewhere? are these ACKs
"local"? if not, where should these ACKs be routed to, to the
route[x]
block?
Tks in advance,
Cesc
_______________________________________________
Serusers mailing list
serusers(a)lists.iptel.org
http://lists.iptel.org/mailman/listinfo/serusers
2:39 p.m.
See inline ...
On 11/24/05, Greger V. Teigre <greger(a)teigre.com> wrote:
Cesc,
I've tried to find some meaning in what you sent, but I don't really know
the details of the ACK hack (pun not intended) Jan mentioned. To me it looks
like the ACK is absorbed correctly.
In the logs provided, the acks are not absorbed at all (well, yes, due
to a hack in my config file ... but otherwise not).
However, the REGISTER messages confuses
me a bit. Also, you don't record_route CANCELs and ACKs, why?
I don't know :) So far it worked fine. Do you think that
record-routing the ACKs may solve this problem? ( See the following
paragraph for a strange development )
Also, we checked yesterday and ... surprise! :)
We discovered this "feature" after upgrading from ser_0.9.0 to
ser_0.9.4 ... we still have some pcs with ser_0.9.0 (ser.cfg and sems
are the same overall), and they don't show this behavior (OK/ACK being
resent for a while). This only happens in the newer setups with
ser_0.9.4
Cesc
26 Nov
26 Nov
9:35 a.m.
I've tried
to find some meaning in what you sent, but I don't really know
the details of the ACK hack (pun not intended) Jan mentioned. To me it
looks
like the ACK is absorbed correctly.
In the logs provided, the acks are not absorbed at all (well, yes, due
to a hack in my config file ... but otherwise not). However, the
REGISTER messages confuses
me a bit. Also, you don't record_route CANCELs and ACKs, why?
I don't know :) So far it worked fine. Do you think that
record-routing the ACKs may solve this problem? ( See the following
paragraph for a strange development )
Also, we checked yesterday and ... surprise! :)
We discovered this "feature" after upgrading from ser_0.9.0 to
ser_0.9.4 ... we still have some pcs with ser_0.9.0 (ser.cfg and sems
are the same overall), and they don't show this behavior (OK/ACK being
resent for a while). This only happens in the newer setups with
ser_0.9.4
28 Nov
28 Nov
11:11 a.m.
Hi Greger,
Tks for taking sometime on my problem ... i appreciate it.
I have to apologize ... i think i sent a log file which does not
correspond "exactly" to the ser.cfg file attached :) Also, some of
the questions you rise are because i removed several parts from the
ser.cfg (they are "top secret" ;D ). But the differences are minimal
...
On 11/26/05, Greger V. Teigre <greger(a)teigre.com> wrote:
? Hm, I saw some debug lines on ACK absorbed...?! Do you mean the "3(11987)
LOG: ACK intercom transaction DOES NOT
exhist ... simply absorbing"? this is from a log message that i
removed from the config ... it it in the route (SEMS) ... there was an
if( method==ACK) { break; }
Hm. Strange. I'm not enough on-top-of diffs from 0.9.0 to say anything smart
about that :-)
I tend to think more and more that this is the key ... i will take a
look today in detail ...
Jan, or any other ... where should i look? where does the ACK cancel
the retransmission timer? are you aware of any changes from 0.9.0 to
0.9.4 that could cause this?
I've tried to find some meaning in what you sent,
but I don't really know
the details of the ACK hack (pun not intended) Jan mentioned. To me it
looks
like the ACK is absorbed correctly.
In the logs provided, the acks are not absorbed at all (well, yes, due
to a hack in my config file ... but otherwise not). However,
the REGISTER messages confuses
me a bit. Also, you don't record_route CANCELs and ACKs, why?
I don't know :) So far it worked fine. Do you think that
record-routing the ACKs may solve this problem? ( See the following
paragraph for a strange development )
Also, we checked yesterday and ... surprise! :)
We discovered this "feature" after upgrading from ser_0.9.0 to
ser_0.9.4 ... we still have some pcs with ser_0.9.0 (ser.cfg and sems
are the same overall), and they don't show this behavior (OK/ACK being
resent for a while). This only happens in the newer setups with
ser_0.9.4 You had some strange messages in there about message
with multicast address
looped back.
Ok ... got me ... i use multicast ... the message being loop'd
back is
just a side effect ... but it is no problem. Those messages are
discarded at the top of the ser.cfg (not shown in the one i sent).
You alsoe have this:
Warning: sl_send_reply: I won't send a reply for ACK!!
Which normally means that an ACK hits an sl_send_reply() somewhere in your
script.
There was an sl_send_reply in the route(SEMS) ... which is not there
anymore ... i was trying things ...
And now that I had another look at your config, I see
that you loose_route
to ROUTE_RELAY, but then you do lookup before t_relay(). Loose routing is
NOT looking up and ACKs with Route should not be looked up, but just
t_relayed. That may introduce some problems.
I would guess that the Warning for ACK above is due to this:
if( ! lookup("location") ) {
sl_send_reply("404", "Not Found");
break;
}
in your ROUTE_RELAY.
Again, i removed some parts from the ser.cfg ... but the loose-routed
msgs are simply t_relayed, nothing else. See that on the if(
loose_route() ) ... i set a flag, which on a part not shown from
route(RELAY) simply t_relay() those flagged messages. Sorry for the
confusion ...
Cesc
6:51 p.m.
Hi,
I found it ... now it works. There is a pseudo-patch at the end of the
message (pseudo because it cannot directly be applied ... it is just
to mark the three lines i needed to change ... ). The patch is for
ser-rel-0.9.4 (i send it to openser-devel ... i did not look, but
probably the problem is there too).
It is just a small bug ... from 0.9.0 to 0.9.4 a part of the loop was
moved outside the loop, to the end of the function ... and in a place
where there used to be a return now the loop would just continue ...
Then, the matching_3261 function would, if a transaction matching the
ACK was found, would always return e2e ack ... even though the
ack_matching function returned it as a local transaction ...
For me, this patch fixes it ... but as it is a delicate part, i am not
sure if it affects other parts ... i don't think so, but ...
Tks for all who took a look at the problem (greger, jan, samuel, ... )!
Regards,
Cesc
PS - This should affect anyone using SEMS ... so, if no one saw it ...
does it mean there is really a few people using it? what a pitty ...
Index: modules/tm/t_lookup.c
===================================================================
--- modules/tm/t_lookup.c (revision 8)
+++ modules/tm/t_lookup.c (working copy)
@@ -292,9
struct via_body *via1;
int is_ack;
int dlg_parsed;
- int ret;
+ int ret = 0;
struct cell *e2e_ack_trans;
e2e_ack_trans=0;
via1=p_msg->via1;
is_ack=p_msg->REQ_METHOD==METHOD_ACK;
@@ -327,16
if (is_ack && p_cell->uas.status<300 && e2e_ack_trans==0) {
/* make sure we have parsed all things we need for dialog
* matching */
if (!dlg_parsed) {
dlg_parsed=1;
if (!parse_dlg(p_msg)) {
LOG(L_ERR, "ERROR: matching_3261: dlg parsing failed\n");
return 0;
}
}
ret=ack_matching(p_cell /* t w/invite */, p_msg /* ack */);
if (ret>0) {
e2e_ack_trans=p_cell;
+ break;
}
/* this ACK is neither local "negative" one, nor a proxied
* end-2-end one, nor an end-2-end one for a UAS transaction
@@ -358,9
/* just check if it we found an e2e ACK previously */
if (e2e_ack_trans) {
*trans=e2e_ack_trans;
- return 2;
+ return ret;
}
DBG("DEBUG: RFC3261 transaction matching failed\n");
return 0;
}
9:42 p.m.
Cesc,
Great work! I have been working on SEMS the last few days, evaluating SEMS
for use in ONsip.org Getting Started. So, I tried to replicate your problem,
which I successfully did. I applied your patch and it seems to be working.
:-)
g-)
----- Original Message -----
From: "Cesc" <cesc.santa(a)gmail.com>
To: "Greger V. Teigre" <greger(a)teigre.com>om>; "SER.Jan Janak"
<jan(a)iptel.org>
Cc: "SER-Users" <serusers(a)lists.iptel.org>rg>; "OpenSER-dev"
<devel(a)openser.org>
Sent: Monday, November 28, 2005 6:51 PM
Subject: Re: [Serusers] Local ACKs for SER-SEMS
Hi,
I found it ... now it works. There is a pseudo-patch at the end of the
message (pseudo because it cannot directly be applied ... it is just
to mark the three lines i needed to change ... ). The patch is for
ser-rel-0.9.4 (i send it to openser-devel ... i did not look, but
probably the problem is there too).
It is just a small bug ... from 0.9.0 to 0.9.4 a part of the loop was
moved outside the loop, to the end of the function ... and in a place
where there used to be a return now the loop would just continue ...
Then, the matching_3261 function would, if a transaction matching the
ACK was found, would always return e2e ack ... even though the
ack_matching function returned it as a local transaction ...
For me, this patch fixes it ... but as it is a delicate part, i am not
sure if it affects other parts ... i don't think so, but ...
Tks for all who took a look at the problem (greger, jan, samuel, ... )!
Regards,
Cesc
PS - This should affect anyone using SEMS ... so, if no one saw it ...
does it mean there is really a few people using it? what a pitty ...
Index: modules/tm/t_lookup.c
===================================================================
--- modules/tm/t_lookup.c (revision 8)
+++ modules/tm/t_lookup.c (working copy)
@@ -292,9
struct via_body *via1;
int is_ack;
int dlg_parsed;
- int ret;
+ int ret = 0;
struct cell *e2e_ack_trans;
e2e_ack_trans=0;
via1=p_msg->via1;
is_ack=p_msg->REQ_METHOD==METHOD_ACK;
@@ -327,16
if (is_ack && p_cell->uas.status<300 && e2e_ack_trans==0) {
/* make sure we have parsed all things we need for dialog
* matching */
if (!dlg_parsed) {
dlg_parsed=1;
if (!parse_dlg(p_msg)) {
LOG(L_ERR, "ERROR: matching_3261: dlg parsing failed\n");
return 0;
}
}
ret=ack_matching(p_cell /* t w/invite */, p_msg /* ack */);
if (ret>0) {
e2e_ack_trans=p_cell;
+ break;
}
/* this ACK is neither local "negative" one, nor a proxied
* end-2-end one, nor an end-2-end one for a UAS transaction
@@ -358,9
/* just check if it we found an e2e ACK previously */
if (e2e_ack_trans) {
*trans=e2e_ack_trans;
- return 2;
+ return ret;
}
DBG("DEBUG: RFC3261 transaction matching failed\n");
return 0;
}
29 Nov
29 Nov
1:41 p.m.
Great, thanks a lot. I just commited your fix.
Jan.
On 28-11-2005 18:51, Cesc wrote:
Hi,
I found it ... now it works. There is a pseudo-patch at the end of the
message (pseudo because it cannot directly be applied ... it is just
to mark the three lines i needed to change ... ). The patch is for
ser-rel-0.9.4 (i send it to openser-devel ... i did not look, but
probably the problem is there too).
It is just a small bug ... from 0.9.0 to 0.9.4 a part of the loop was
moved outside the loop, to the end of the function ... and in a place
where there used to be a return now the loop would just continue ...
Then, the matching_3261 function would, if a transaction matching the
ACK was found, would always return e2e ack ... even though the
ack_matching function returned it as a local transaction ...
For me, this patch fixes it ... but as it is a delicate part, i am not
sure if it affects other parts ... i don't think so, but ...
Tks for all who took a look at the problem (greger, jan, samuel, ... )!
Regards,
Cesc
PS - This should affect anyone using SEMS ... so, if no one saw it ...
does it mean there is really a few people using it? what a pitty ...
Index: modules/tm/t_lookup.c
===================================================================
--- modules/tm/t_lookup.c (revision 8)
+++ modules/tm/t_lookup.c (working copy)
@@ -292,9
struct via_body *via1;
int is_ack;
int dlg_parsed;
- int ret;
+ int ret = 0;
struct cell *e2e_ack_trans;
e2e_ack_trans=0;
via1=p_msg->via1;
is_ack=p_msg->REQ_METHOD==METHOD_ACK;
@@ -327,16
if (is_ack && p_cell->uas.status<300 && e2e_ack_trans==0) {
/* make sure we have parsed all things we need for dialog
* matching */
if (!dlg_parsed) {
dlg_parsed=1;
if (!parse_dlg(p_msg)) {
LOG(L_ERR, "ERROR: matching_3261: dlg parsing failed\n");
return 0;
}
}
ret=ack_matching(p_cell /* t w/invite */, p_msg /* ack */);
if (ret>0) {
e2e_ack_trans=p_cell;
+ break;
}
/* this ACK is neither local "negative" one, nor a proxied
* end-2-end one, nor an end-2-end one for a UAS transaction
@@ -358,9
/* just check if it we found an e2e ACK previously */
if (e2e_ack_trans) {
*trans=e2e_ack_trans;
- return 2;
+ return ret;
}
DBG("DEBUG: RFC3261 transaction matching failed\n");
return 0;
}
6735
days inactive
6748
days old
11 comments
4 participants
participants (4)
-
Cesc -
Greger V. Teigre -
Jan Janak -
SER.Jan Janak