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@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 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@voip.domain.com - sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered DEBUG: {1 <null> 172.30.154.189 102 ACK 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@voip.domain.com - sanity [sanity.c:305]: check_required_headers(): check_required_headers entered DEBUG: {1 <null> 172.30.154.189 102 ACK 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
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@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@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@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@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@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 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@voip.domain.com - sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered DEBUG: {1 <null> 172.30.154.189 102 ACK 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@voip.domain.com - sanity [sanity.c:305]: check_required_headers(): check_required_headers entered DEBUG: {1 <null> 172.30.154.189 102 ACK 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
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@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@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@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@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@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@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@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@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@lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
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@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@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@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@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@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@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@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@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@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@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@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@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 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@voip.domain.com - sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered DEBUG: {1 <null> 172.30.154.189 102 ACK 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@voip.domain.com - sanity [sanity.c:305]: check_required_headers(): check_required_headers entered DEBUG: {1 <null> 172.30.154.189 102 ACK 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 Listsr-users@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
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@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@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@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@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@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@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@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: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@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@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@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@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@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@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@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@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@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
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@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@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@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@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@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@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@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@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@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@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@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@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@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 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@voip.domain.com - sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered DEBUG: {1 <null> 172.30.154.189 102 ACK 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@voip.domain.com - sanity [sanity.c:305]: check_required_headers(): check_required_headers entered DEBUG: {1 <null> 172.30.154.189 102 ACK 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 Listsr-users@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 -
George Diamantopoulos