[kamailio/kamailio] rms_bridge() doesn't send out B-leg: run_onsend(): required parameters are not available - ignoring (#2524)
<!-- Kamailio Project uses GitHub Issues only for bugs in the code or feature requests. Please use this template only for bug reports.
If you have questions about using Kamailio or related to its configuration file, ask on sr-users mailing list:
* http://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
If you have questions about developing extensions to Kamailio or its existing C code, ask on sr-dev mailing list:
* http://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-dev
Please try to fill this template as much as possible for any issue. It helps the developers to troubleshoot the issue.
If there is no content to be filled in a section, the entire section can be removed.
You can delete the comments from the template sections when filling.
You can delete next line and everything above before submitting (it is a comment). -->
### Description
<!-- Explain what you did, what you expected to happen, and what actually happened. --> Testing out rtp_media_server module's `rms_bridge()` function with the intention of bridging A-leg to B-leg (an Asterisk conference server). The B-leg never gets sent out and after the call times out, this testing instance crashes.
Config slightly modified from https://github.com/kamailio/kamailio/blob/master/src/modules/rtp_media_serve... ``` ... loadmodule "uac.so"
event_route[rms:bridged] { xnotice("[rms:bridged] ...\n"); }
route { if (t_precheck_trans()) { t_check_trans(); exit; } t_check_trans();
if (is_method("REGISTER")) { save("location"); exit; }
xnotice("[$rm][$ci]\n"); if (is_method("INVITE") && !has_totag()) { fix_nated_contact();
if ($rU == "888") { $var(target) = "sip:conference@example.com:5080;"; if (!rms_bridge("$var(target)", "rms:bridged")) { send_reply("503", "server error"); xerr("rtp_media_server bridge error!\n"); } exit; } if (!rms_answer("rms:answered")) { t_reply("503", "server error"); xerr("rtp_media_server error!\n"); exit; } } if(rms_dialog_check()) rms_sip_request(); exit; } ``` ### Troubleshooting I added `loadmodule "uac.so"`, though I'm not sure it's required.
#### Reproduction
<!-- If the issue can be reproduced, describe how it can be done. -->
#### Debugging Data
<!-- If you got a core dump, use gdb to extract troubleshooting data - full backtrace, local variables and the list of the code at the issue location.
gdb /path/to/kamailio /path/to/corefile bt full info locals list
If you are familiar with gdb, feel free to attach more of what you consider to be relevant. --> I can only do a stack trace at the moment running this test in a systemd-nspawn container ``` Stack trace of thread 589: #0 0x00007fb449848518 n/a (/usr/lib64/kamailio/modules/rtp_media_server.so + 0x2f518) #1 0x00007fb44982682b n/a (/usr/lib64/kamailio/modules/rtp_media_server.so + 0xd82b) #2 0x00000000005cca6b n/a (/usr/sbin/kamailio + 0x1cca6b) #3 0x000000000041cf90 n/a (/usr/sbin/kamailio + 0x1cf90) #4 0x000000000041e9ea n/a (/usr/sbin/kamailio + 0x1e9ea) #5 0x0000000000421c65 n/a (/usr/sbin/kamailio + 0x21c65) #6 0x000000000042c61c n/a (/usr/sbin/kamailio + 0x2c61c) #7 0x0000000000434cbd n/a (/usr/sbin/kamailio + 0x34cbd) #8 0x00007fb44a8b0042 __libc_start_main (libc.so.6 + 0x27042) #9 0x000000000041bbde n/a (/usr/sbin/kamailio + 0x1bbde) ```
#### Log Messages
<!-- Check the syslog file and if there are relevant log messages printed by Kamailio, add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). -->
``` kamailio[275]: 10(275) INFO: rtp_media_server [rtp_media_server.c:254]: rms_dialog_action_check(): dialog action RMS_BRIDGING [0_3746724993@2001:db8::99] kamailio[275]: 10(275) INFO: rtp_media_server [rtp_media_server.c:583]: rms_bridging_call(): parsed[sip:conference@example.com:5080][0] kamailio[275]: 10(275) INFO: rtp_media_server [rtp_media_server.c:599]: rms_bridging_call(): si[0x7f83fddb78e0]call-id[0_3746724993@2001:db8::99]cseq[0]ruri[32|sip:conference@example.com:5080]remote_uri[sip:conference@example.com:5080]local_uri[sip:888@example.com] kamailio[275]: 10(275) DEBUG: tm [uac.c:450]: t_uac_prepare(): next_hop=sip:conference@example.com:508 kamailio[275]: 10(275) DEBUG: <core> [core/dns_cache.c:527]: _dns_hash_find(): (example.com(12), 1), h=205 kamailio[275]: 10(275) DEBUG: <core> [core/resolve.c:985]: get_record(): skipping 2 NS (p=0x9a0e6e, end=0x9a0ef2) kamailio[275]: 10(275) DEBUG: <core> [core/resolve.c:998]: get_record(): parsing 4 ARs (p=0x9a0e9a, end=0x9a0ef2) kamailio[275]: 10(275) DEBUG: <core> [core/dns_cache.c:1633]: dns_get_related(): (0x7f83fddbb878 (example.com, 1), 1, *0x7f8406d319f0) (0) kamailio[275]: 10(275) DEBUG: <core> [core/dns_cache.c:739]: dns_cache_add_unsafe(): adding example.com(12) 1 (flags=0) at 205 kamailio[275]: 10(275) DEBUG: tm [uac.c:158]: dlg2hash(): hashid 35754 kamailio[275]: 10(275) DEBUG: tm [uac.c:678]: send_prepared_request_impl(): uac: 0x7f83fddb9a10 branch: 0 to 10.77.79.3:508 kamailio[275]: 10(275) DEBUG: <core> [core/onsend.c:50]: run_onsend(): required parameters are not available - ignoring kamailio[275]: 10(275) ERROR: rtp_media_server [rtp_media_server.c:622]: rms_bridging_call(): tmb.t_request_within ok ```
#### SIP Traffic
<!-- If the issue is exposed by processing specific SIP messages, grab them with ngrep or save in a pcap file, then add them next, or attach to issue, or provide a link to download them (e.g., to a pastebin site). -->
There is no SIP traffic generated to `sip:conference@example.com:5080`
### Possible Solutions
<!-- If you found a solution or workaround for the issue, describe it. Ideally, provide a pull request with a fix. -->
### Additional Information
* **Kamailio Version** - output of `kamailio -v`
``` version: kamailio 5.4.1-8.gitd43872c11e.fc32.1 (x86_64/linux) 09fd6a flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: 09fd6a compiled on 00:00:00 Oct 21 2020 with gcc 10.2.1 ```
* **Operating System**:
<!-- Details about the operating system, the type: Linux (e.g.,: Debian 8.4, Ubuntu 16.04, CentOS 7.1, ...), MacOS, xBSD, Solaris, ...; Kernel details (output of `uname -a`) -->
``` Linux kamtest 5.8.16-200.fc32.x86_64 #1 SMP Mon Oct 19 14:17:16 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux ```
Thanks for testing this module, it is still experimental, however the libraries behind at stable and reliable. We can test more and make it more robust a lot of features will become available. I will reproduce shortly and see what can be done.
Just tested with the latest master, should be the same.
Are you sure the RURI as a `;` at the end in your test ?
``` $var(target) = "sip:conference@example.com:5080;"; ```
it seems it is not present looking at your logs : ``` kamailio[275]: 10(275) INFO: rtp_media_server [rtp_media_server.c:583]: rms_bridging_call(): parsed[sip:conference@example.com:5080][0] ```
versus mine ``` 5(520) INFO: rtp_media_server [rtp_media_server.c:581]: rms_bridging_call(): parsed[sip:conference@example.com:5080;][0] ```
I need to fix this pitfall in command arguments automatically ...
I have switched to just using IP addresses for simplicity, but I can confirm that `$var(target)` has the `;` at the end -- I originally thought that was a typo in the example config, but realized without it that the last char was stripped. Not sure what the reason for the extra `;` is though:
Current config: ``` ... } else if ($rU == "888") { $var(target)="sip:conference@10.77.79.3:5080;"; if (!rms_bridge("$var(target)", "rms:bridged")) { send_reply("503", "server error"); xerr("rtp_media_server bridge error!\n"); } exit; } ... ```
This will prevent this problem with the missing `;` it is needed by some other kamalio function used by the module.
I will merge it if it passes the Travis tests.
Is there a reason for the requirement of the `;` suffix to appear in the config file? It seems like that is something that could be handled in the module itself (if there is no `;` in the first parameter, then add `;`, since as you said it's necessary for other internal processing) -- seems like lots of adopters will see this as an issue.
Also FYI, before I apply your patch, this is what I have... ``` INFO: rtp_media_server [rtp_media_server.c:583]: rms_bridging_call(): parsed[sip:conference@10.77.79.3:5080;][0] INFO: rtp_media_server [rtp_media_server.c:599]: rms_bridging_call(): si[0x7f791c637a18]call-id[0_448469831@2001:db8::99]cseq[0]ruri[31|sip:conference@10.77.79.3:5080;]remote_uri[sip:conference@10.77.79.3:5080]local_uri[sip:888@example.com] DEBUG: tm [uac.c:450]: t_uac_prepare(): next_hop=sip:conference@10.77.79.3:5080 DEBUG: tm [uac.c:158]: dlg2hash(): hashid 29747 DEBUG: tm [uac.c:678]: send_prepared_request_impl(): uac: 0x7f791c639b40 branch: 0 to 10.77.79.3:5080 DEBUG: <core> [core/onsend.c:50]: run_onsend(): required parameters are not available - ignoring ERROR: rtp_media_server [rtp_media_server.c:622]: rms_bridging_call(): tmb.t_request_within ok ```
I rebuilt Kamailio and all the Belledonne Communications deps last night.
The error I see is related to https://github.com/kamailio/kamailio/blob/76bb9bb7cbdcd900339afa7192eaefd71f... -- some params are missing?
I see, there is still a problem, any chance you can share your config ?
This way I should be able to reproduce/debug.
``` debug=3 log_stderror=yes memdbg=5 memlog=5
# number of SIP routing processes children=5
loadmodule "ctl" loadmodule "tm" loadmodule "tmx" loadmodule "sl" loadmodule "rr" loadmodule "pv" loadmodule "textops" loadmodule "siputils" loadmodule "xlog" loadmodule "nathelper" #loadmodule "usrloc" #loadmodule "registrar"
loadmodule "rtp_media_server" modparam("rtp_media_server", "log_file_name", "/tmp/rms_transfer.log") modparam("tm", "wt_timer", 1000) listen=udp:10.77.79.148:5090 listen=udp:127.0.0.1:5090
event_route[rms:start] { xnotice("[rms:start] play ...\n"); # rms_play("/opt/voice_files/OSR_us_000_0010_8k.wav", "rms:after_play"); };
event_route[rms:bridge] { #$var(target) = "sip:456@localhost:5069;"; $var(target)="sip:888@127.0.0.1:5090;"; if (!rms_bridge("$var(target)", "rms:bridged")) { send_reply("604", "server error"); xerr("rtp_media_server bridge error!\n"); exit; } };
event_route[rms:play_bridge] { xnotice("[rms:play_bridge] play ...\n"); rms_play("/etc/kamailio/zombies.wav", "rms:bridge"); };
event_route[rms:after_play] { xnotice("[rms:after_play] play done...\n"); rms_hangup(); };
event_route[rms:bridged] { xnotice("[rms:bridged] ...\n"); }
event_route[rms:answered] { xnotice("[rms:answered] ...\n"); # rms_play("/opt/voice_files/OSR_us_000_0010_8k.wav", "rms:after_play"); }
route { if (t_precheck_trans()) { t_check_trans(); exit; } t_check_trans();
# if (is_method("REGISTER")) { # save("location"); # exit; # }
xnotice("[$rm][$ci]\n"); if (is_method("INVITE") && !has_totag()) { fix_nated_contact();
if ($rU == "456") { rms_answer("rms:play_bridge"); exit; } else if ($rU == "888") { $var(target)="sip:conference@10.77.79.3:5080;"; if (!rms_bridge("$var(target)", "rms:bridged")) { send_reply("503", "server error"); xerr("rtp_media_server bridge error!\n"); } exit; } if (!rms_answer("rms:answered")) { t_reply("503", "server error"); xerr("rtp_media_server error!\n"); exit; } } if(rms_dialog_check()) rms_sip_request(); exit;
} ```
Your config is working with me, I understand that the problem is now that the onsend callbacks can not be runned, this should be fixed but will not prevent bridging.
``` 5(5589) INFO: rtp_media_server [rtp_media_server.c:254]: rms_dialog_action_check(): dialog action RMS_BRIDGING [kc3geZ29cWlR5zGyJzdzQ8eXEZW-fIao] 5(5589) INFO: rtp_media_server [rtp_media_server.c:585]: rms_bridging_call(): parsed[sip:conference@10.77.79.3:5080;][0] 5(5589) INFO: rtp_media_server [rtp_media_server.c:601]: rms_bridging_call(): si[0x7fd0d0114fe0]call-id[kc3geZ29cWlR5zGyJzdzQ8eXEZW-fIao]cseq[0]ruri[31|sip:conference@10.77.79.3:5080;]remote_uri[sip:conference@10.77.79.3:5080]local_uri[sip:888@192.168.0.132] 5(5589) ERROR: rtp_media_server [rtp_media_server.c:624]: rms_bridging_call(): tmb.t_request_within ok 1(5585) WARNING: tm [t_reply.c:1017]: run_failure_handlers(): no UAC support (0, 17536) 1(5585) NOTICE: rtp_media_server [rtp_media_server.c:491]: bridge_cb(): COMPLETED [408]
```
``` 192.168.0.132:444 192.168.0.132:5090 10.77.79.3:5080 ──────────┬───────── ──────────┬───────── ──────────┬─ 15:40:34.851179 │ INVITE (SDP) │ │ +0.004474 │ ────────────────────────>>> │ │ 15:40:34.855653 │ 100 Trying │ │ +0.007837 │ <────────────────────────── │ │ 15:40:34.863490 │ │ INVITE (SDP) │ +0.480909 │ │ ──────────────────────────> │ 15:40:35.344399 │ │ INVITE (SDP) │ +1.000097 │ │ ────────────────────────>>> │ 15:40:36.344496 │ │ INVITE (SDP) │ +1.999749 │ │ ────────────────────────>>> │ 15:40:38.344245 │ │ INVITE (SDP) │ +4.000071 │ │ ────────────────────────>>> │ 15:40:42.344316 │ │ INVITE (SDP) │ +4.000141 │ │ ────────────────────────>>> │ 15:40:46.344457 │ │ INVITE (SDP) │ +3.999842 │ │ ────────────────────────>>> │ 15:40:50.344299 │ │ INVITE (SDP) │ +4.000059 │ │ ────────────────────────>>> │ 15:40:54.344358 │ │ INVITE (SDP) │ +3.999934 │ │ ────────────────────────>>> │ 15:40:58.344292 │ │ INVITE (SDP) │ +3.999936 │ │ ────────────────────────>>> │ 15:41:02.344228 │ │ INVITE (SDP) │ +2.500737 │ │ ────────────────────────>>> │ 15:41:04.844965 │ 408 Request Timeout │ │ +0.000519 │ <────────────────────────── │ │ 15:41:04.845484 │ ACK │ │ │ ──────────────────────────> │~ ``` ```
I did look into a more important fix that was required, the next thing I will do is to add testing tools to make sure we can modify and improve things without breaking the existing.
I failed to re-use the exiting dialog module in the past, I will continue with the custom alternate solution for now, this way, we can improve the rest of the code logic it will never be to later to change our mind about using an existing dialog module, this is only one very important building block but the rest of the code can still evolve to do something right.
I will have to look at the on_send call back, I guess this is the purpose of this issue now.
@jchavanton -- thank you. I have dug more into my trouble -- partly my issue was the firewall not having port 5090 open between testing machines and the timeout of the `rms_bridge()` when it couldn't reach the destination `$var(target)`. I look forward to testing this module, particularly the B2BUA functionality and the ability to handle REFER in the future.
I can now confirm that I can get `rms_bridge()` to work in its most basic form.
I did look into a more important fix that was required, the next thing I will do is to add testing tools to make sure we can modify and improve things without breaking the existing.
I failed to re-use the exiting dialog module in the past, I will continue with the custom alternate solution for now, this way, we can improve the rest of the code logic it will never be to later to change our mind about using an existing dialog module, this is only one very important building block but the rest of the code can still evolve to do something right.
I will have to look at the on_send call back, I guess this is the purpose of this issue now.
@jchavanton My suggestion would be to look into the dialog module if you need dialog state in your module. You really do not want to duplicate all this corner cases in this module etc.. Let me/us know if you need some pointers in getting to used the dialog API.
My conclusion is that it would require modifications to the dialog module, this is most likely the best option and we can do it later, but in the mean time, a working solution is required, we should be able to hope for "drop in" replacement.
I will try again soon to see how we could start to use it for states etc. It would indeed be great since we would benefit from the dialog modules features.
Closed #2524.
-
Anthony Messina -
Henning Westerholt
-
Julien Chavanton