[kamailio/kamailio] Kamailio resets $ru in branch_route context, probably race condition (#2708)
### Description
Kamailio resets the $ru in a branch_route context, probably due a race condition and/or bug.
Scenario:
- Calls is established and answered with 404 - Kamailio enters failure_route - failure_route calls t_relay() - branch_route is entered - new branch is created with $ru = $ru; - next operation trying to access content of the $ru fails: Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: pv [pv_core.c:325]: pv_get_ruri_attr(): failed to parse the R-URI
### Troubleshooting
Happens on a production system, after upgrade from 5.2.x to 5.3.9. Research regarding similar bugs have not produced something useful so far.
#### Reproduction
Issue happens less than 10 times a day and so far could not be easily reproduced.
#### Debugging Data
Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: NOTICE: 7e8bb2ba47f5ccc |-----> Failure Code 404<- Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[Failure] c=[/etc/kamailio/kamailio.cfg] l=1720 a=5 n=route Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=703 a=16 n=if Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=699 a=25 n=is_method Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=702 a=16 n=if Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=701 a=25 n=t_is_set Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=701 a=25 n=t_on_branch Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=707 a=16 n=if Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=703 a=25 n=is_method Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=706 a=16 n=if Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=705 a=25 n=t_is_set Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=707 a=25 n=t_on_branch_failure Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=720 a=16 n=if Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=711 a=25 n=is_method Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=714 a=16 n=if Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=713 a=25 n=t_is_set Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=713 a=25 n=t_on_failure Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=742 a=16 n=if Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:failure_route=[RELAY] c=[/etc/kamailio/kamailio.cfg] l=720 a=24 n=t_relay Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:branch_route=[MANAGE_BRANCH] c=[/etc/kamailio/kamailio.cfg] l=2142 a=16 n=if Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:branch_route=[MANAGE_BRANCH] c=[/etc/kamailio/kamailio.cfg] l=2135 a=63 n=assign Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:branch_route=[MANAGE_BRANCH] c=[/etc/kamailio/kamailio.cfg] l=2147 a=16 n=if Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:branch_route=[MANAGE_BRANCH] c=[/etc/kamailio/kamailio.cfg] l=2142 a=25 n=is_method Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:branch_route=[MANAGE_BRANCH] c=[/etc/kamailio/kamailio.cfg] l=2142 a=63 n=assign Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: pv [pv_core.c:325]: pv_get_ruri_attr(): failed to parse the R-URI
#### Log Messages
See cfgtrace logging above.
#### SIP Traffic
Not easily to provide as its a productive system in a clustered setup.
### Possible Solutions
Ideas on how to further debug this error are welcome.
### Additional Information
* kamailio 5.3.9
Hello,
same behavior on 5.4.5
@miconda Do you have some ideas how to proceed with debugging this issue? It seems to happens only in certain circumstances.
I haven't encountered such situation. Is it parallel forking case or serial forking?
What is not clear for me is your remark: `new branch is created with $ru = $ru` -- is it done in failure route or branch route? If in branch route, what is the reason for it? In branch route it is not supposed to create new branches, only update the current outgoing branch.
As for troubleshooting, I would try to add some logs in the code to gather more details, maybe trying to figure out what are the cases/functions in your config when $ru may be updated (pv module, core functions, ...) and see if it is done when not expected. Also, catching the sip traffic should help to see if many messages in the same transaction are handled at the same time.
Thanks for the reply @miconda There was a mistake in the description. So the new branch is of course created in the failure_route, not in the branch_route.
The error is after an assignment done in the branch route:
``` Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: *** cfgtrace:branch_route=[MANAGE_BRANCH] c=[/etc/kamailio/kamailio.cfg] l=2142 a=63 n=assign Apr 13 11:44:39 proxy1 /usr/sbin/kamailio[2202]: ERROR: pv [pv_core.c:325]: pv_get_ruri_attr(): failed to parse the R-URI ``` What is there?
This should be the line in question:
`if (is_method ("INVITE")) $dlg_var(rU)=$rU;`
Hello Miconda,
Any ideas here?
@nicoonline - i gave some hints on troubleshooting in a comment above. Have you followed them?
Hi Miconda,
We have debugged with Henning and the line in cause is :
if (is_method ("INVITE")) $dlg_var(rU)=$rU; in a failure route.
@nicoonline - my hints were about adding debugging messages in the code, catch the traffic sip traffic to try to reproduce, ... when the line listed above is executed, the r-uri is no longer available, so it has to be figured out what changes it before.
This issue is stale because it has been open 6 weeks with no activity. Remove stale label or comment or this will be closed in 2 weeks.
Closed #2708 as not planned.
-
Daniel-Constantin Mierla -
github-actions[bot]
-
Henning Westerholt
-
nicoonline