[OpenSIPS-Users] Mediaproxy 2.1.0: dispatcher - relay problems
Magnus Burman
magnus.burman at adamoeurope.com
Tue Dec 9 02:01:38 CET 2008
Having some troubles getting Mediaproxy 2.1.0 working. I'm on a VPS with
a fresh Debian Etch, running OpenSips 1.4.3 (which log below is for,
also tried Kamailio 1.4.1 earlier [separate debian installation], log
was pretty much identical).
The log is from a 'tail -f /var/log/syslog | grep media' when making a
call from a sip ua over a sip trunk via pstn gw to a cell phone. The
same setup works well if engage_media_proxy is removed, except for
CANCEL:s where the 487 is never sent (and it thus keeps ringing).
I'm all out of ideas of what to test next and could really need a
pointer to where the fault could be. Is it my config or some software
dependencies missing / being faulty? I'm sorry for the long email, but I
wanted to get as much info as I could in here. The routing, unless I'm
missing something, goes through down to REGISTER-clause, hops to
route[3], hops to route[10], hops to route[4] which rewrites it to the
sip trunk and hops to route[1]. All IP:s are public.
Many thanks to anyone willing to have a quick look; all suggestions are
much welcomed!
Best Regards,
Magnus
--- syslog ---
Dec 9 01:28:24 ada-bcn-sips001 media-dispatcher[14252]: [-] Log opened.
Dec 9 01:28:24 ada-bcn-sips001 media-dispatcher[14252]: [-] Starting
MediaProxy Dispatcher 2.1.0
Dec 9 01:28:24 ada-bcn-sips001 media-dispatcher[14252]: [-] Twisted is
using epollreactor
Dec 9 01:28:24 ada-bcn-sips001 media-dispatcher[14252]: [-]
mediaproxy.dispatcher.RelayFactory starting on 25060
Dec 9 01:28:24 ada-bcn-sips001 media-dispatcher[14252]: [-]
mediaproxy.dispatcher.OpenSIPSControlFactory starting on
"'/var/run/mediaproxy/dispatcher.sock'"
Dec 9 01:28:24 ada-bcn-sips001 media-dispatcher[14252]: [-]
mediaproxy.dispatcher.ManagementControlFactory starting on 25061
Dec 9 01:28:30 ada-bcn-sips001 media-relay[14266]: [-] Log opened.
Dec 9 01:28:30 ada-bcn-sips001 media-relay[14266]: [-] Starting
MediaProxy Relay 2.1.0
Dec 9 01:28:30 ada-bcn-sips001 media-relay[14266]: [-] Set resource
limit for maximum open file descriptors to 11000
Dec 9 01:28:30 ada-bcn-sips001 media-relay[14266]: [-] Adding new
dispatcher at <opensips ip>:25060
Dec 9 01:28:30 ada-bcn-sips001 media-dispatcher[14252]:
[mediaproxy.dispatcher.RelayFactory] Connection from relay at <opensips ip>
Dec 9 01:28:30 ada-bcn-sips001 media-dispatcher[14252]:
[RelayServerProtocol,0,<opensips ip>] Issuing "sessions" command to
relay at <opensips ip>
Dec 9 01:28:31 ada-bcn-sips001 media-relay[14266]: [Uninitialized]
Connected to dispatcher at <opensips ip>:25060
...
Dec 9 01:01:28 host001 media-dispatcher[2466]:
[OpenSIPSControlProtocol,33,] Issuing "update" command to relay at
<opensips ip>
Dec 9 01:01:28 host001 media-relay[2492]: [RelayClientProtocol,client]
Received new SDP offer
Dec 9 01:01:28 host001 media-relay[2492]: [RelayClientProtocol,client]
mediaproxy.mediacontrol.StreamListenerProtocol starting on 50004
Dec 9 01:01:28 host001 media-relay[2492]: [RelayClientProtocol,client]
mediaproxy.mediacontrol.StreamListenerProtocol starting on 50005
Dec 9 01:01:28 host001 media-relay[2492]: [RelayClientProtocol,client]
mediaproxy.mediacontrol.StreamListenerProtocol starting on 50006
Dec 9 01:01:28 host001 media-relay[2492]: [RelayClientProtocol,client]
mediaproxy.mediacontrol.StreamListenerProtocol starting on 50007
Dec 9 01:01:28 host001 media-relay[2492]: [RelayClientProtocol,client]
Added new stream: (audio) <ua ip>:10000 (RTP: Unknown, RTCP: Unknown)
<-> <opensips ip>:50004 <-> <opensips ip>:50006 <-> Unknown (RTP:
Unknown, RTCP: Unknown)
Dec 9 01:01:28 host001 media-relay[2492]: [RelayClientProtocol,client]
created new session 6C8F-F261-420242003-D5889592E170-0007@<ua ip>: <from
uri>@<opensips ip> (XG6525p2-186fd447-658964802) --> <to uri>@<opensips ip>
Dec 9 01:01:28 host001 media-relay[2492]:
[mediaproxy.mediacontrol.StreamListenerProtocol (UDP)] Got traffic
information for stream: (audio) <ua ip>:10000 (RTP: Unknown, RTCP:
Unknown) <-> <opensips ip>:50004 <-> <opensips ip>:50006 <-> Unknown
(RTP: Unknown, RTCP: <siptrunk ip>:21189)
Dec 9 01:01:28 host001 media-relay[2492]:
[mediaproxy.mediacontrol.StreamListenerProtocol (UDP)] Got traffic
information for stream: (audio) <ua ip>:10000 (RTP: Unknown, RTCP:
Unknown) <-> <opensips ip>:50004 <-> <opensips ip>:50006 <-> Unknown
(RTP: <siptrunk ip>:21188, RTCP: <siptrunk ip>:21189)
Dec 9 01:01:30 host001 media-dispatcher[2466]:
[OpenSIPSControlProtocol,46,] Issuing "update" command to relay at
<opensips ip>
Dec 9 01:01:30 host001 media-relay[2492]: [RelayClientProtocol,client]
error: Required header "from_tag" for command "update" not found
Dec 9 01:01:32 host001 /usr/local/sbin/opensips[10729]:
ERROR:mediaproxy:send_command: did timeout waiting for an answer
Dec 9 01:01:32 host001 media-dispatcher[2466]:
[OpenSIPSControlProtocol,46,] Connection to OpenSIPS lost: Connection
was closed cleanly.
Dec 9 01:01:32 host001 media-relay[2492]:
[mediaproxy.mediacontrol.StreamListenerProtocol (UDP)] Got traffic
information for stream: (audio) <ua ip>:10000 (RTP: Unknown, RTCP: <ua
ip>:10001) <-> <opensips ip>:50004 <-> <opensips ip>:50006 <-> Unknown
(RTP: <siptrunk ip>:21188, RTCP: <siptrunk ip>:21189)
Dec 9 01:01:35 host001 media-dispatcher[2466]: [-] error: Error
processing request: Relay at <opensips ip> timed out
Dec 9 01:01:40 host001 media-dispatcher[2466]:
[OpenSIPSControlProtocol,45,] Issuing "update" command to relay at
<opensips ip>
Dec 9 01:01:40 host001 media-relay[2492]: [RelayClientProtocol,client]
error: Unable to parse header: update 3
Dec 9 01:01:40 host001 media-relay[2492]: [RelayClientProtocol,client]
Traceback (most recent call last):
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] File
"/usr/lib/python2.5/site-packages/twisted/python/log.py", line 51, in
callWithLogger
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] return callWithContext({"system":
lp}, func, *args, **kw)
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] File
"/usr/lib/python2.5/site-packages/twisted/python/log.py", line 36, in
callWithContext
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] return context.call({ILogContext:
newCtx}, func, *args, **kw)
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] File
"/usr/lib/python2.5/site-packages/twisted/python/context.py", line 59,
in callWithContext
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] return
self.currentContext().callWithContext(ctx, func, *args, **kw)
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] File
"/usr/lib/python2.5/site-packages/twisted/python/context.py", line 37,
in callWithContext
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] return func(*args,**kw)
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] --- <exception caught here> ---
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] File
"/usr/lib/python2.5/site-packages/twisted/internet/epollreactor.py",
line 231, in _doReadOrWrite
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] why = selectable.doRead()
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] File
"/var/lib/python-support/python2.5/gnutls/interfaces/twisted/__init__.py",
line 82, in doRead
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] return tcp.Connection.doRead(self)
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] File
"/usr/lib/python2.5/site-packages/twisted/internet/tcp.py", line 362, in
doRead
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] return self.protocol.dataReceived(data)
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] File
"/usr/lib/python2.5/site-packages/twisted/protocols/basic.py", line 148,
in dataReceived
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] self.lineReceived(line)
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] File
"/usr/lib/python2.5/site-packages/mediaproxy/relay.py", line 157, in
lineReceived
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] self.headers[name] = value
Dec 9 01:01:40 host001 media-relay[2492]:
[RelayClientProtocol,client] exceptions.UnboundLocalError: local
variable 'value' referenced before assignment
Dec 9 01:01:40 host001 media-relay[2492]: [RelayClientProtocol,client]
error: Connection with dispatcher at <opensips ip>:25060 was lost: local
variable 'value' referenced before assignment
Dec 9 01:01:40 host001 media-dispatcher[2466]:
[mediaproxy.dispatcher.RelayFactory] Connection from relay at <opensips ip>
Dec 9 01:01:40 host001 media-dispatcher[2466]:
[mediaproxy.dispatcher.RelayFactory] error: Connection to relay
<opensips ip> is already present, disconnecting
Dec 9 01:01:40 host001 media-dispatcher[2466]:
[RelayServerProtocol,1,<opensips ip>] error: Connection with relay at
<opensips ip> was lost: A TLS packet with unexpected length was received.
Dec 9 01:01:40 host001 media-dispatcher[2466]:
[RelayServerProtocol,1,<opensips ip>] error: Error processing request:
Relay at <opensips ip> disconnected
Dec 9 01:01:40 host001 media-relay[2492]: [Uninitialized] error: Could
not connect to dispatcher at <opensips ip>:25060 (retrying in 10
seconds): A TLS packet with unexpected length was received.
Dec 9 01:01:40 host001 /usr/local/sbin/opensips[10728]:
ERROR:mediaproxy:use_media_proxy: mediaproxy returned error
Dec 9 01:01:48 host001 media-relay[2492]: [-] expired session
6C8F-F261-420171336-84E598E2DB21-0004@<ua ip>: <from uri>@<opensips ip>
(XG6525p2-f96460f0-1677721184) --> <to uri>@<opensips ip>
Dec 9 01:01:48 host001 media-relay[2492]: [-] warning: dispatcher for
expired session is no longer online, statistics are lost!
Dec 9 01:01:48 host001 media-relay[2492]: [-] (Port 50000 Closed)
Dec 9 01:01:48 host001 media-relay[2492]: [-] (Port 50001 Closed)
Dec 9 01:01:48 host001 media-relay[2492]: [-] (Port 50002 Closed)
Dec 9 01:01:48 host001 media-relay[2492]: [-] (Port 50003 Closed)
Dec 9 01:01:49 host001 media-dispatcher[2466]:
[OpenSIPSControlProtocol,47,] error: Error processing request: Relay for
this session (<opensips ip>) is no longer connected
Dec 9 01:01:50 host001 media-dispatcher[2466]:
[mediaproxy.dispatcher.RelayFactory] Connection from relay at <opensips ip>
Dec 9 01:01:50 host001 media-dispatcher[2466]:
[RelayServerProtocol,2,<opensips ip>] Issuing "sessions" command to
relay at <opensips ip>
Dec 9 01:01:50 host001 media-relay[2492]: [Uninitialized] Connected to
dispatcher at <opensips ip>:25060
Dec 9 01:01:50 host001 media-dispatcher[2466]:
[RelayServerProtocol,2,<opensips ip>] warning: Session
6C8F-F261-420171336-84E598E2DB21-0004@<ua ip> is not longer on relay
<opensips ip>, statistics are probably lost
Dec 9 01:02:58 host001 media-dispatcher[2466]:
[RelayServerProtocol,3,<opensips ip>] Got statistics: {'from_tag':
'XG6525p2-186fd447-658964802', 'callee_packets': {'audio': 16},
'dialog_id': '5:23556094', 'start_time': None, 'timed_out': True,
'caller_bytes': {'audio': 84}, 'callee_bytes': {'audio': 1408},
'call_id': '6C8F-F261-420242003-D5889592E170-0007@<ua ip>', 'to_tag':
None, 'streams': [{'status': 'no traffic timeout', 'caller_codec':
'Unknown', 'pdd': 0.056584119796800003, 'callee_codec': 'G711u',
'start_time': None, 'caller_bytes': 0, 'callee_bytes': 0,
'callee_remote': '<siptrunk ip>:21188', 'caller_remote': 'Unknown',
'media_type': 'audio', 'callee_local': '<opensips ip>:50006',
'timeout_wait': 90, 'caller_local': '<opensips ip>:50004', 'end_time':
None}], 'caller_packets': {'audio': 1}, 'duration': 0, 'to_uri': '<to
uri>@<opensips ip>', 'from_uri': '<from uri>@<opensips ip>',
'callee_ua': 'Unknown', 'caller_ua': 'XAVi/XG6525p2-1.6.7'}
--- /etc/mediaproxy/config.ini ---
[Relay]
dispatchers = <opensips ip>:25060
relay_ip = <opensips ip>
[Dispatcher]
socket_path = /var/run/mediaproxy/dispatcher.sock
listen = <opensips ip>:25060
listen_management = <opensips ip>:25061
;tried yes!
management_use_tls = no
[TLS]
certs_path = /etc/mediaproxy/tls
[Database]
[Radius]
[OpenSIPS]
socket_path = '/var/run/opensips/mi_datagram.sock
--- /usr/local/etc/opensips/opensips.cfg ---
debug=4 # debug level (cmd line: -dddddddddd)
fork=yes
log_stderror=no # (cmd line: -E)
children=4
port=5060
dns=no
rev_dns=no
mpath="/usr/local/lib/opensips/modules/"
loadmodule "db_mysql.so"
loadmodule "sl.so"
loadmodule "tm.so"
loadmodule "rr.so"
loadmodule "maxfwd.so"
loadmodule "usrloc.so"
loadmodule "registrar.so"
loadmodule "textops.so"
loadmodule "mi_fifo.so"
loadmodule "uri_db.so"
loadmodule "uri.so"
loadmodule "xlog.so"
loadmodule "acc.so"
loadmodule "domain.so"
loadmodule "permissions.so"
loadmodule "auth.so"
loadmodule "auth_db.so"
loadmodule "alias_db.so"
loadmodule "mediaproxy.so"
loadmodule "avpops.so"
loadmodule "dialog.so"
loadmodule "mi_datagram.so"
modparam("auth_db|permissions|uri_db|usrloc|alias_db|domain|dialog|acc","db_url","mysql://opensips:opensipspw@<opensips
ip>/opensips")
modparam("mi_fifo", "fifo_name", "/tmp/opensips_fifo")
modparam("rr", "enable_full_lr", 1)
modparam("usrloc", "db_mode", 2)
modparam("auth_db", "calculate_ha1", yes)
modparam("auth_db", "password_column", "password")
modparam("permissions", "db_mode", 1)
modparam("permissions", "trusted_table", "trusted")
modparam("avpops", "avp_url", "mysql://opensips:opensipspw@<opensips
ip>/opensips")
modparam("avpops", "avp_table", "avptable")
modparam("dialog", "enable_stats", 1)
modparam("dialog", "table_name", "dialog")
modparam("dialog", "db_mode", 1)
modparam("dialog", "dlg_flag", 1)
modparam("mediaproxy", "mediaproxy_timeout", 2000)
modparam("mi_datagram", "socket_name", "/var/run/opensips/mi_datagram.sock")
modparam("mediaproxy", "mediaproxy_socket",
"/var/run/mediaproxy/dispatcher.sock")
modparam("acc", "failed_transaction_flag", 1)
modparam("acc", "report_cancels", 0)
modparam("acc", "report_ack", 0)
modparam("acc", "early_media", 0)
modparam("acc", "log_level", 7)
modparam("acc", "db_flag", 1)
modparam("acc", "db_extra", "to_uri=$rU; from_uri=$fU")
route{
if (!mf_process_maxfwd_header("10")) {
sl_send_reply("483","Too Many Hops");
exit;
};
if (msg:len >= 2048 ) {
sl_send_reply("513", "Message too big");
exit;
};
if (!method=="REGISTER") record_route();
if (loose_route()) {
append_hf("P-hint: rr-enforced\r\n");
if(method=="BYE") {
setflag(1);
}
route(1);
};
if (method==INVITE && !has_totag()) {
engage_media_proxy();
}
if(method=="INVITE") {
setflag(1);
}
if (has_totag()) {
if (loose_route()) {
if (method=="INVITE" && (!allow_trusted())) {
if (!proxy_authorize("", "subscriber")) {
proxy_challenge("", "1");
exit;
} else if (!check_from()) {
sl_send_reply("403", "Fobidden, use From=ID");
exit;
}
}
route(1);
} else {
sl_send_reply("404", "Not here");
}
exit;
}
if (is_method("CANCEL") || is_method("ACK")) {
if (t_check_trans()) {
setflag(1);
if(!t_relay()) {
sl_reply_error();
}
}
exit;
};
t_check_trans();
if (method=="REGISTER") {
route(2);
} else {
route(3);
};
}
route[1] {
## Forward statefully
# Find users caller-id
if(avp_db_query("select call_id from subscriber_extras where
username = '$fU'", "$avp(s:cid)")) {
remove_hf("From");
append_hf("From: <sip:$avp(s:cid)@<opensips ip>>\r\n", "To");
}
setflag(1);
if (!t_relay()) {
sl_reply_error();
};
exit;
}
route[2] {
## Register request handler
if (is_uri_host_local()) {
if (!www_authorize("", "subscriber")) {
www_challenge("", "1");
exit;
};
if (!check_to()) {
sl_send_reply("403", "Forbidden");
exit;
};
save("location");
exit;
} else if {
sl_send_reply("403", "Forbidden");
};
}
route[3] {
## INVITE request handler
if (is_from_local()){
if(!allow_trusted()){
if (!proxy_authorize("","subscriber")) {
proxy_challenge("","1");
exit;
} else if (!check_from()) {
sl_send_reply("403", "Forbidden, use From=ID");
exit;
};
} else {
log("Request bypassed the auth.using allow_trusted");
};
consume_credentials();
alias_db_lookup("dbaliases");
if (is_uri_host_local()) {
route(10);
} else {
route(11);
};
} else {
alias_db_lookup("dbaliases");
if (is_uri_host_local()) {
route(12);
} else {
route(13);
};
};
}
route[4] {
# routing to the public network
rewritehostport("<siptrunk ip>");
route(1);
}
route[10] {
append_hf("P-hint: inbound->inbound \r\n");
# Simplefied regular expression for routing to pstn
if(uri=~"^sip:[0-9]+@") {
route(4);
exit;
}
if (!lookup("location")) {
sl_send_reply("404", "Not Found");
exit;
};
route(1);
}
route[11] {
append_hf("P-hint: inbound->outbound \r\n");
route(1);
}
route[12] {
strip_tail(1);
alias_db_lookup("dbaliases");
if (!lookup("location")) {
sl_send_reply("404", "Not Found");
exit;
};
route(1);
}
route[13] {
append_hf("P-hint: outbound->inbound \r\n");
sl_send_reply("403", "Forbidden 3");
exit;
}
More information about the Users
mailing list