[SR-Users] sanity module checks fail for ACK with parameters in RURI - possible bug?
George Diamantopoulos
georgediam at gmail.com
Wed Jul 8 11:49:46 CEST 2020
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 at 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
> ;lr;received=sip:2.2.2.2:32768
> ;ob;r2=on>,<sip:RJ2U2c7mrFzQjgG5SSvyE8RVS9omgAA=@3.3.3.3
> ;lr;received=sip:2.2.2.2:32768;ob;r2=on>#015#012Max-Forwards:
> 68#015#012From: "Anonymous" <sip:unknown at voip.domain.com>;tag=as4bc9e324#015#012To:
> <sip:voip-test-user-02 at voip.domain.com>;tag=jw7z5s0zvc#015#012Call-ID:
> 0138c6370346d1dd7f1b47f604b01f92 at 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 at 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 at 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:
>>>
>>> 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 at 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 at 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 at 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 at 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 at 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 at voip.domain.com - <script>: Malformed
>>> SIP request from 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 at 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:
>>>>
>>>> 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 at 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 at 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 at 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 at 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 17895 in 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 at 172.17.173.14:5063 SIP/2.0
>>>>> Call 2: INVITE sip:voip-test-user-02 at 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 at 172.17.173.14:5063 SIP/2.0
>>>>> Call 2: ACK sip:voip-test-user-02 at 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 at voip.domain.com - sanity
>>>>> [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered
>>>>> DEBUG: {1 <null> 172.30.154.189 102 ACK
>>>>> 08679c4228983f9e65f3b47f767b6e07 at 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 at voip.domain.com - sanity
>>>>> [sanity.c:305]: check_required_headers(): check_required_headers entered
>>>>> DEBUG: {1 <null> 172.30.154.189 102 ACK
>>>>> 2a859fcc4e1c8f840191a81d7c16e76d at 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 Listsr-users at lists.kamailio.orghttps://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
>>>>
>>>> --
>>>> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda
>>>> Funding: https://www.paypal.me/dcmierla
>>>>
>>>> --
>>> Daniel-Constantin Mierla -- www.asipto.comwww.twitter.com/miconda -- www.linkedin.com/in/miconda
>>> Funding: https://www.paypal.me/dcmierla
>>>
>>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20200708/9c633518/attachment.htm>
More information about the sr-users
mailing list