[SR-Users] sanity module checks fail for ACK with parameters in RURI - possible bug?

George Diamantopoulos georgediam at gmail.com
Wed Jul 8 14:36:02 CEST 2020


Hello Daniel,

I have forwarded the requested capture files to your private email address.
Thanks!

Best regards,
George

On Wed, 8 Jul 2020 at 13:06, Daniel-Constantin Mierla <miconda at gmail.com>
wrote:

> 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 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
>>>>
>>>> --
> 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/6015eb28/attachment.htm>


More information about the sr-users mailing list