8 Jul
2020
8 Jul
'20
6:06 a.m.
Can you send the pcap taken on kamailio server for such call (with all
request/replies)?
Cheers,
Daniel
On 08.07.20 11:49, George Diamantopoulos wrote:
Update: Disabling the topoh module on the proxy which
produces the
error seems to stop the failure from manifesting. I'll try using
topos_redis instead, but should this be treated as a bug?
BR,
George
On Wed, 8 Jul 2020 at 12:37, George Diamantopoulos
<georgediam(a)gmail.com <mailto:georgediam@gmail.com>> wrote:
Hello again,
Indeed $mb seems to contain garbage:
SCRIPT_MB: ACK <BC><EA><8F> SIP/2.0#015#012Via: SIP/2.0/UDP
172.30.154.189;TH=dcv;branch=z9hG4bK629b.6af9302cd78dc58dffe817e60124f4ed.0#015#012Route:
<sip:RJ2U2c7mrFzQjgG5SSvyE8RVS9omgAA=@172.30.155.1
<http://172.30.155.1>;lr;received=sip:2.2.2.2:32768;ob;r2=on>,<sip:RJ2U2c7mrFzQjgG5SSvyE8RVS9omgAA=@3.3.3.3
<http://3.3.3.3>;lr;received=sip:2.2.2.2:32768;ob;r2=on>#015#012Max-Forwards:
68#015#012From: "Anonymous" <sip:unknown@voip.domain.com
<mailto:sip%3Aunknown@voip.domain.com>>;tag=as4bc9e324#015#012To:
<sip:voip-test-user-02@voip.domain.com
<mailto:sip%3Avoip-test-user-02@voip.domain.com>>;tag=jw7z5s0zvc#015#012Call-ID:
0138c6370346d1dd7f1b47f604b01f92(a)voip.domain.com#015#012CSeq
<http://0138c6370346d1dd7f1b47f604b01f92@voip.domain.com#015%23012CSeq>:
102 ACK#015#012Content-Length: 0#015#012TH: dch#015#012#015#012
How can this be possible? Capturing traffic on wire shows the RURI
I pasted in my original message and there are no script operations
on the RURI before sanity_check() (message buffer above is printed
just before sanity_check() is run in REQINIT).
BR,
George
On Wed, 8 Jul 2020 at 11:18, George Diamantopoulos
<georgediam(a)gmail.com <mailto:georgediam@gmail.com>> wrote:
I'll post the message buffer ASAP, but in the meantime I don't
see how config operations could affect the RURI. Here's
everything that's happening until the sanity check involved:
request_route {
if(is_method("KDMQ")) {
dmq_handle_message();
}
# no connect for sending replies
set_reply_no_connect();
if($ua =~
"friendly-scanner|sipcli|sipvicious|VaxSIPUserAgent") {
# silent drop for scanners - uncomment next line if
want to reply
# sl_send_reply("200", "OK");
exit;
}
if (!mf_process_maxfwd_header("10")) {
force_rport();
sl_send_reply("483","Too Many Hops");
exit;
}
# OPTIONS and NOTIFYs directed to myself
if(is_method("OPTIONS|NOTIFY") && uri==myself &&
$rU==$null) {
force_rport();
sl_send_reply("200","Keepalive");
exit;
}
# All keep-alive methods regardless of destination
if ( $hdr(Event) == "keep-alive") {
force_rport();
sl_send_reply("200","Keepalive");
exit;
}
if(!sanity_check("17895", "7")) {
xlog("Malformed SIP request from $si:$sp\n");
exit;
}
BR,
George
On Wed, 8 Jul 2020 at 10:58, Daniel-Constantin Mierla
<miconda(a)gmail.com <mailto:miconda@gmail.com>> wrote:
Hello,
check your config operations, because the R-URI seems to
be the next string (without quotes):
"<BC><EA><8F>"
You can try to print $mb in such case to see the entire
SIP message buffer.
Cheers,
Daniel
On 08.07.20 09:48, George Diamantopoulos wrote:
--
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Funding: https://www.paypal.me/dcmierla
Hello Daniel,
Thanks for the reply. Indeed there is, not sure how I
managed to miss that. And it wasn't about the schema
after all:
Jul 7 18:42:11 lbpub0-stage-lhe0-cn1
/usr/sbin/kamailio[909]: DEBUG: {1 <null> 172.30.154.189
102 ACK 08679c4228983f9e65f3b47f767b6e07(a)voip.domain.com
<mailto:08679c4228983f9e65f3b47f767b6e07@voip.domain.com>
- sanity [sanity.c:277]: check_ruri_scheme():
check_ruri_scheme entered
Jul 7 18:42:11 lbpub0-stage-lhe0-cn1
/usr/sbin/kamailio[909]: DEBUG: {1 <null> 172.30.154.189
102 ACK 08679c4228983f9e65f3b47f767b6e07(a)voip.domain.com
<mailto:08679c4228983f9e65f3b47f767b6e07@voip.domain.com>
- <core> [core/parser/parse_uri.c:1254]: parse_uri(): uri
too short: <<BC><EA><8F>> (3)
Jul 7 18:42:11 lbpub0-stage-lhe0-cn1
/usr/sbin/kamailio[909]: DEBUG: {1 <null> 172.30.154.189
102 ACK 08679c4228983f9e65f3b47f767b6e07(a)voip.domain.com
<mailto:08679c4228983f9e65f3b47f767b6e07@voip.domain.com>
- <core> [core/parser/parse_uri.c:1328]:
parse_sip_msg_uri(): bad uri <<BC><EA><8F>>
Jul 7 18:42:11 lbpub0-stage-lhe0-cn1
/usr/sbin/kamailio[909]: WARNING: {1 <null>
172.30.154.189 102 ACK
08679c4228983f9e65f3b47f767b6e07(a)voip.domain.com
<mailto:08679c4228983f9e65f3b47f767b6e07@voip.domain.com>
- sanity [sanity.c:282]: check_ruri_scheme(): failed to
parse request uri [<BC><EA><8F>]
Jul 7 18:42:11 lbpub0-stage-lhe0-cn1
/usr/sbin/kamailio[909]: DEBUG: {1 <null> 172.30.154.189
102 ACK 08679c4228983f9e65f3b47f767b6e07(a)voip.domain.com
<mailto:08679c4228983f9e65f3b47f767b6e07@voip.domain.com>
- sanity [sanity_mod.c:254]: w_sanity_check(): sanity
checks result: 0
Jul 7 18:42:11 lbpub0-stage-lhe0-cn1
/usr/sbin/kamailio[909]: ERROR: {1 <null> 172.30.154.189
102 ACK 08679c4228983f9e65f3b47f767b6e07(a)voip.domain.com
<mailto:08679c4228983f9e65f3b47f767b6e07@voip.domain.com>
- <script>: Malformed SIP request from
172.30.154.189:5060 <http://172.30.154.189:5060>
Still, not sure what the problem is though...
BR,
George
On Wed, 8 Jul 2020 at 09:30, Daniel-Constantin Mierla
<miconda(a)gmail.com <mailto:miconda@gmail.com>> wrote:
Hello,
when the ruri scheme check fails, there should be
another debug message saying that. Have you pasted
all log messages for the failure case?
Cheers,
Daniel
On 07.07.20 22:23, George Diamantopoulos wrote:
--
Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com>
www.twitter.com/miconda <http://www.twitter.com/miconda> --
www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda>
Funding: https://www.paypal.me/dcmierla
Sorry, I realised I copy pasted
wrong log messages
for Call 1. Here's the relevant part showing success
for call 1 in contrast with Call 2:
grep 2a859fcc4e1c8f840191a81d7c16e76d kamailio.log |
egrep 'check_ruri_scheme|w_sanity_check' | grep ACK
Jul 7 18:42:11 lbpub0-stage-lhe0-cn1
/usr/sbin/kamailio[907]: DEBUG: {1 <null>
172.30.154.189 102 ACK
2a859fcc4e1c8f840191a81d7c16e76d(a)voip.domain.com
<mailto:2a859fcc4e1c8f840191a81d7c16e76d@voip.domain.com>
- sanity [sanity.c:277]: check_ruri_scheme():
check_ruri_scheme entered
Jul 7 18:42:11 lbpub0-stage-lhe0-cn1
/usr/sbin/kamailio[907]: DEBUG: {1 <null>
172.30.154.189 102 ACK
2a859fcc4e1c8f840191a81d7c16e76d(a)voip.domain.com
<mailto:2a859fcc4e1c8f840191a81d7c16e76d@voip.domain.com>
- sanity [sanity.c:297]: check_ruri_scheme():
check_ruri_scheme passed
Jul 7 18:42:11 lbpub0-stage-lhe0-cn1
/usr/sbin/kamailio[907]: DEBUG: {1 <null>
172.30.154.189 102 ACK
2a859fcc4e1c8f840191a81d7c16e76d(a)voip.domain.com
<mailto:2a859fcc4e1c8f840191a81d7c16e76d@voip.domain.com>
- sanity [sanity_mod.c:254]: w_sanity_check():
sanity checks result: 1
On Tue, 7 Jul 2020 at 21:34, George Diamantopoulos
<georgediam(a)gmail.com <mailto:georgediam@gmail.com>>
wrote:
Hello all,
I'm not 100% sure this is the only culprit in an
issue I'm investigating, but superficially it
appears that RURI scheme sanity module checks
from the default config (flags 17895in REQINIT)
fail if the RURI in an ACK following a 487
includes parameters. Example from two calls from
a kamailio instance acting as registrar/usrloc
server, INVITE RURIs are after usrloc lookup:
Call 1: INVITE
sip:voip-test-gd@172.17.173.14:5063
<http://sip:voip-test-gd@172.17.173.14:5063> SIP/2.0
Call 2: INVITE
sip:voip-test-user-02@10.2.24.142:32768;line=moo62e08
SIP/2.0
These INVITEs produce no complaints. Later, the
same registrar produces ACKs to acknowledge 487
(thus, same transaction ACKs) responses from the
next proxy in the path following a CANCEL:
Call 1: ACK sip:voip-test-gd@172.17.173.14:5063
<http://sip:voip-test-gd@172.17.173.14:5063> SIP/2.0
Call 2: ACK
sip:voip-test-user-02@10.2.24.142:32768;line=moo62e08
SIP/2.0
The next proxy (which produced/relayed the 487)
processes the ACK for Call 1 successfully, but
sanity_check at the proxy drops the request for
Call 2 with:
DEBUG: {1 <null> 172.30.154.189 102 ACK
08679c4228983f9e65f3b47f767b6e07(a)voip.domain.com
<mailto:08679c4228983f9e65f3b47f767b6e07@voip.domain.com>
- sanity [sanity.c:277]: check_ruri_scheme():
check_ruri_scheme entered
DEBUG: {1 <null> 172.30.154.189 102 ACK
08679c4228983f9e65f3b47f767b6e07(a)voip.domain.com
<mailto:08679c4228983f9e65f3b47f767b6e07@voip.domain.com>
- sanity [sanity_mod.c:254]: w_sanity_check():
sanity checks result: 0
whereas Call 1 seems OK:
DEBUG: {1 <null> 172.30.154.189 102 ACK
2a859fcc4e1c8f840191a81d7c16e76d(a)voip.domain.com
<mailto:2a859fcc4e1c8f840191a81d7c16e76d@voip.domain.com>
- sanity [sanity.c:305]:
check_required_headers(): check_required_headers
entered
DEBUG: {1 <null> 172.30.154.189 102 ACK
2a859fcc4e1c8f840191a81d7c16e76d(a)voip.domain.com
<mailto:2a859fcc4e1c8f840191a81d7c16e76d@voip.domain.com>
- sanity [sanity.c:313]:
check_required_headers(): check_required_headers
passed
Could this be a bug in sanity module? Is there
anything one can do in config which could result
in illegal ACKs being produced for hop-by-hop
transactions? schema appears to be sip: in both
cases...
Thank you. Best regards,
George
_______________________________________________
Kamailio (SER) - Users Mailing List
sr-users(a)lists.kamailio.org <mailto:sr-users@lists.kamailio.org>
https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
--
Daniel-Constantin Mierla -- www.asipto.com <http://www.asipto.com>
www.twitter.com/miconda <http://www.twitter.com/miconda> --
www.linkedin.com/in/miconda <http://www.linkedin.com/in/miconda>
Funding: https://www.paypal.me/dcmierla