manual compilation & running rtpengine

[Anshuman Rawat]

Hi,

rtpengine - rtpengine-mr11.5.1.9

system - 6.1.0-13-cloud-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.55-1 (2023-09-29) x86_64 GNU/Linux

I have been trying to build & run rtpengine manually, with kernel module. It builds & runs but I am unable to confirm if it's using kernel module. I have been trying to follow the instructions at https://github.com/sipwise/rtpengine/blob/master/docs/usage.md

The kernel module registers with some module taints.

[ 1855.215087] xt_RTPENGINE: loading out-of-tree module taints kernel.

[ 1855.220488] xt_RTPENGINE: module verification failed: signature and/or required key missing - tainting kernel
[ 1855.232505] Registering xt_RTPENGINE module - version 11.5.1.9+0~mr11.5.1.9 git-HEAD-24c3c3d0

I don't know if that's normal.

During the call, I see statements like below in the logs -

"023-10-12T11:44:54.028003+00:00 ip-20-1-14-3 rtpengine[6509]: INFO: [JDl8_K1iKQFQWVX-amhZow../99606678/1 port 25600]: [core] Kernelizing media stream: <IP>:53438 -> <IP>:25600 | <IP>:26426 -> <IP>:28210"

But a look at /proc/rtpengine/7/list  shows nothing (--table=7 option while starting the daemon). "nft list tables" also returns nothing.

I am starting the daemon manually as follows - 

"/usr/bin/rtpengine --table=7 --interface=internal/20.1.14.3 --interface=external/20.1.14.3\!54.197.180.220 --listen-ng=20.1.14.3:22000 -m 20000 -M 35000 -L 6 --log-facility=local5 --delete-delay=0"

Adding the options "--nftables-start" gives an error - Fatal error: Bad command line: Unknown option --nftables-start

It seems I am missing the part of creating rules in nftables chains but not sure how to.

Any pointers on how to set it up or what have i missed?

Thanks,

Anshuman

[Richard Fuchs]

On 12/10/2023 08.20, [EXT] Anshuman Rawat wrote:

rtpengine - rtpengine-mr11.5.1.9

system - 6.1.0-13-cloud-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.55-1 (2023-09-29) x86_64 GNU/Linux

I have been trying to build & run rtpengine manually, with kernel module. It builds & runs but I am unable to confirm if it's using kernel module. I have been trying to follow the instructions at https://github.com/sipwise/rtpengine/blob/master/docs/usage.md

You're looking at the wrong version of the instructions. These are for current master which uses nftables natively. But you're using 11.5 which doesn't and still uses the iptables backend.

So you need to read https://github.com/sipwise/rtpengine/blob/mr11.5.1/docs/usage.md instead.

The kernel module registers with some module taints.

[ 1855.215087] xt_RTPENGINE: loading out-of-tree module taints kernel.

[ 1855.220488] xt_RTPENGINE: module verification failed: signature and/or required key missing - tainting kernel
[ 1855.232505] Registering xt_RTPENGINE module - version 11.5.1.9+0~mr11.5.1.9 git-HEAD-24c3c3d0

I don't know if that's normal.

For non-installed kernel modules it is.

During the call, I see statements like below in the logs -

"023-10-12T11:44:54.028003+00:00 ip-20-1-14-3 rtpengine[6509]: INFO: [JDl8_K1iKQFQWVX-amhZow../99606678/1 port 25600]: [core] Kernelizing media stream: <IP>:53438 -> <IP>:25600 | <IP>:26426 -> <IP>:28210"

But a look at /proc/rtpengine/7/list  shows nothing (--table=7 option while starting the daemon).

That should get populated. If it remains empty make sure everything was compiled from the same sources and the same version (esp daemon and kernel module) and that there aren't any stray headers from other versions lying around.

It seems I am missing the part of creating rules in nftables chains but not sure how to.

Any pointers on how to set it up or what have i missed?

You're missing the iptables rule, see https://github.com/sipwise/rtpengine/blob/mr11.5.1/docs/usage.md#the-iptables-module

But as I said above, even with that missing, the /proc entry should get populated.

Cheers

[Anshuman Rawat]

Thank you for your response. I had been trying with that version (https://github.com/sipwise/rtpengine/blob/mr11.5.1/docs/usage.md) as well but no luck. And tried it again. Steps :

- make clean

- with_transcoding=no make with-kernel

- make install-with-kernel

- rmmod xt_RTPENGINE   #(to make sure any prev version is not loaded)

- modprobe xt_RTPENGINE

- iptables -I INPUT -p udp -j RTPENGINE --id 7

- iptables -L

Chain INPUT (policy ACCEPT)
target     prot opt source               destination        
RTPENGINE  udp  --  anywhere             anywhere             RTPENGINE id:7

Chain FORWARD (policy ACCEPT)
target     prot opt source               destination        

Chain OUTPUT (policy ACCEPT)
target     prot opt source               destination

- echo 'del 7' > /proc/rtpengine/control   (making sure it does not exist)

- /usr/bin/rtpengine --table=7 --interface=internal/x.x.x.x --interface=external/x.x.x.x\!y.y.y.y --listen-ng=x.x.x.x:2000 -m 20000 -M 35000 -L 6 --log-facility=local5 --delete-delay=0

 

I made a few calls. Calls work and in the logs I see statements like "kernelizing media stream" but notthing in /proc/rtpengine/7/list

# cat /proc/rtpengine/7/list
# cat /proc/rtpengine/7/status
Refcount:    1
Control PID: 5982
Targets:     0

what have I missed? Another piece of info - I am doing all of the above as root.

Thanks,

Anshuman

[Richard Fuchs]

On 13/10/2023 03.06, [EXT] Anshuman Rawat wrote:
> - echo 'del 7' > /proc/rtpengine/control   (making sure it does not exist)
> - /usr/bin/rtpengine --table=7 --interface=internal/x.x.x.x
> --interface=external/x.x.x.x\!y.y.y.y --listen-ng=x.x.x.x:2000 -m
> 20000 -M 35000 -L 6 --log-facility=local5 --delete-delay=0
> I made a few calls. Calls work and in the logs I see statements like
> "kernelizing media stream" but notthing in /proc/rtpengine/7/list
>
> # cat /proc/rtpengine/7/list
> # cat /proc/rtpengine/7/status
> Refcount:    1
> Control PID: 5982
> Targets:     0
>
> what have I missed?

Honestly no idea. The entry should show up in the `list` file
immediately after the `kernelizing` log message (assuming there's
nothing else afterwards, such as the call being deleted or an error
message). I don't have any direct experience with "cloud" kernel
installations, but at least I haven't heard of any special requirements
they have (other than making sure that the installed kernel headers
match the running kernel).

Cheers

[Anshuman Rawat]

Little more info on this, I ran watch -n 0.5 iptables -L INPUT -nvx command & see packet count & bytes increasing.

Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
    pkts      bytes target     prot opt in     out     source               destination
    4909   981465 RTPENGINE  17   --  *      *       0.0.0.0/0            0.0.0.0/0            RTPENGINE id:7

Does that mean kernel forwarding is working?

`cat /proc/rtpengine/7/list` still returns blank.

Thanks.

[Richard Fuchs]

On 18/10/2023 06.23, [EXT] Anshuman Rawat wrote:

Little more info on this, I ran watch -n 0.5 iptables -L INPUT -nvx command & see packet count & bytes increasing.

Chain INPUT (policy ACCEPT 0 packets, 0 bytes)
    pkts      bytes target     prot opt in     out     source               destination
    4909   981465 RTPENGINE  17   --  *      *       0.0.0.0/0            0.0.0.0/0            RTPENGINE id:7

Does that mean kernel forwarding is working?

No, it just means that packets are being passed to the kernel module. It doesn't say anything about whether they're being handled by the kernel module or not. You'd have to inspect the packet counters in the /list file in order to see whether it's actually working, but alas...

Cheers

[Anshuman Rawat]

So I turned on some debugging logs in the kernel module (in the source & recompiled) and tried again.

I can see a bunch of kernel module logs in `dmesg` but still nothing in /proc/rtpengine/7/list. I am not sure what it means. I forgot to mention 1 detail - I am trying this on AWS ec2, so it has a pvt IP with an attached elastic IP. I start using cmd -

/usr/bin/rtpengine --table=7 --interface=internal/20.1.14.3 --interface=external/20.1.14.3\!<elastic-IP> --listen-ng=20.1.14.3:22000 -m 20000 -M 35000 -L 6 --log-facility=local5 --delete-delay=0

dmesg logs - 

[23137.557138] [PID 0 line 801] ref_get(000000008a427158) - refcnt is 1
[23137.557144] [PID 0 line 5330] udp payload = 172
[23137.557146] [PID 0 line 5349] target found, local 2:14010e03000000000000000000000000:22240
[23137.557149] [PID 0 line 5350] target decrypt RTP hmac and cipher are NULL and NULL
[23137.557150] [PID 0 line 4222] rtp header parsed, payload length is 160
[23137.557152] [PID 0 line 5442] packet payload decrypted as 756ef9f4656cfafe7cede7dff875eff46a6f767e...
[23137.557155] [PID 0 line 5494] output src 2:14010e03000000000000000000000000:20248 -> dst 2:86ee1213000000000000000000000000:21275
[23137.557159] [PID 0 line 3986] datalen=172 network_header=0000000023af9ae6 transport_header=00000000984b28e9
[23137.566266] [PID 0 line 801] ref_get(000000008a427158) - refcnt is 1
[23137.566271] [PID 0 line 5330] udp payload = 52
[23137.566273] [PID 0 line 5349] target found, local 2:14010e03000000000000000000000000:20249
[23137.566276] [PID 0 line 5350] target decrypt RTP hmac and cipher are NULL and NULL
[23137.566278] [PID 0 line 5494] output src 2:14010e03000000000000000000000000:22241 -> dst 2:36504eac000000000000000000000000:19333
[23137.566283] [PID 0 line 3986] datalen=52 network_header=0000000065836251 transport_header=0000000063e4773a
[23137.577143] [PID 0 line 801] ref_get(000000008a427158) - refcnt is 1
[23137.577148] [PID 0 line 5330] udp payload = 172
[23137.577150] [PID 0 line 5349] target found, local 2:14010e03000000000000000000000000:22240
[23137.577153] [PID 0 line 5350] target decrypt RTP hmac and cipher are NULL and NULL
[23137.577155] [PID 0 line 4222] rtp header parsed, payload length is 160
[23137.577157] [PID 0 line 5442] packet payload decrypted as 7c7e7b7c7e7ffe7d7bfefe7a7dfbfb7e7779fefe...
[23137.577160] [PID 0 line 5494] output src 2:14010e03000000000000000000000000:20248 -> dst 2:86ee1213000000000000000000000000:21275
[23137.577165] [PID 0 line 3986] datalen=172 network_header=00000000b8f85d95 transport_header=00000000f8cf6e4a
[23137.597183] [PID 0 line 801] ref_get(000000008a427158) - refcnt is 1
[23137.597199] [PID 0 line 5330] udp payload = 172
[23137.597204] [PID 0 line 5349] target found, local 2:14010e03000000000000000000000000:22240
[23137.597210] [PID 0 line 5350] target decrypt RTP hmac and cipher are NULL and NULL
[23137.597214] [PID 0 line 4222] rtp header parsed, payload length is 160
[23137.597218] [PID 0 line 5442] packet payload decrypted as ffffffffffffffffff7f7fff7f7fff7f7f7fffff...
[23137.597223] [PID 0 line 5494] output src 2:14010e03000000000000000000000000:20248 -> dst 2:86ee1213000000000000000000000000:21275
[23137.597231] [PID 0 line 3986] datalen=172 network_header=00000000cec98c85 transport_header=00000000d1993135
[23137.600117] [PID 0 line 801] ref_get(000000008a427158) - refcnt is 1
[23137.600122] [PID 0 line 5330] udp payload = 123
[23137.600374] [PID 7089 line 801] ref_get(000000008a427158) - refcnt is 1
[23137.600378] [PID 7089 line 947] Freeing target
[23137.600389] [PID 7089 line 801] ref_get(000000008a427158) - refcnt is 1
[23137.600392] [PID 7089 line 947] Freeing target
[23137.600400] [PID 7089 line 801] ref_get(000000008a427158) - refcnt is 1
[23137.600402] [PID 7089 line 947] Freeing target
[23137.600414] [PID 7089 line 801] ref_get(000000008a427158) - refcnt is 1
[23137.600416] [PID 7089 line 947] Freeing target
[23137.826901] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23137.826916] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23137.826924] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23138.827029] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23138.827045] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23138.827052] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23139.827199] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23139.827217] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23139.827225] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23140.827384] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23140.827402] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23140.827410] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23141.827572] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23141.827589] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23141.827597] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23142.827758] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23142.827776] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23142.827784] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23143.827867] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23143.827878] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1
[23143.827884] [PID 7082 line 801] ref_get(000000008a427158) - refcnt is 1

On Wednesday, October 18, 2023 at 5:42:52 PM UTC+5:30 Richard Fuchs wrote:

[Richard Fuchs]

On 20/10/2023 08.57, [EXT] Anshuman Rawat wrote:
> So I turned on some debugging logs in the kernel module (in the source
> & recompiled) and tried again.
> I can see a bunch of kernel module logs in `dmesg` but still nothing
> in /proc/rtpengine/7/list. I am not sure what it means. I forgot to
> mention 1 detail - I am trying this on AWS ec2, so it has a pvt IP
> with an attached elastic IP. I start using cmd -
>
> /usr/bin/rtpengine --table=7 --interface=internal/20.1.14.3
> --interface=external/20.1.14.3\!<elastic-IP>
> --listen-ng=20.1.14.3:22000 -m 20000 -M 35000 -L 6
> --log-facility=local5 --delete-delay=0
>
> dmesg logs -
>
> [23137.557138] [PID 0 line 801] ref_get(000000008a427158) - refcnt is 1
> [23137.557144] [PID 0 line 5330] udp payload = 172
> [23137.557146] [PID 0 line 5349] target found, local
> 2:14010e03000000000000000000000000:22240
> [23137.557149] [PID 0 line 5350] target decrypt RTP hmac and cipher
> are NULL and NULL
> [23137.557150] [PID 0 line 4222] rtp header parsed, payload length is 160

...

All that sure looks like kernel forwarding is working just fine. Still
no idea why /list wouldn't return anything though. Having a private IP
address certainly wouldn't make a difference. I can only speculate that
perhaps the cloud environment and the non standard kernel image have
something to do with it.

You can ask rtpengine itself what it thinks about kernel forwarding via
`rtpengine-ctl list totals` - inspect the session counters near the top,
as well as the running packet counters just below.

One concern with /list not returning anything is /blist possibly also
not returning anything. /blist is required for accurate statistics. You
can verify it by identifying the thread dedicated to /blist via `ps
-ecL` - look for a thread labelled "kernel stats", note its thread ID
(not the process ID), and then use `strace -p` to attach to that thread
ID. With a call being handled in kernel mode, you should see it
periodically opening the /blist file and then reading one or more stats
entries before closing the file again:

> openat(AT_FDCWD, "/proc/rtpengine/7/blist", O_RDONLY) = 15
> read(15,
> "\2\0\0\0\177\0\0\1\0\0\0\0\0\0\0\0\0\0\0\0\2\257\0\0\2\0\0\0\177\0\0\1"...,
> 43560) = 43560
> read(15,
> "\2\0\0\0\300\250\1\247\0\0\0\0\0\0\0\0\0\0\0\0\226\246\0\0\2\0\0\0\300\250\1B"...,
> 43560) = 43560
> read(15, "", 43560)                     = 0
> close(15)                               = 0

Cheers

[Anshuman Rawat]

Thank you for that information. I will try & get back.

On Friday, October 20, 2023 at 9:21:25 PM UTC+5:30 Richard Fuchs wrote:

[Anshuman Rawat]

Ok. It seems I had an understanding gap.

I, accidentally, did a cat on /proc/rtpengine/7/list while the call was in progress & i can see a bunch of counters. So i guess that more or less confirms that kernel module is in use. The counters disappear once the call ends.

Running strace on the 'kernel stats' thread I can see the blist file being read -

gettimeofday({tv_sec=1698158329, tv_usec=999012}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7faab57a2f40) = 0
gettimeofday({tv_sec=1698158330, tv_usec=999187}, NULL) = 0
openat(AT_FDCWD, "/proc/rtpengine/7/blist", O_RDONLY) = 13
read(13, "\2\0\0\0\24\1\16\3\0\0\0\0\0\0\0\0\0\0\0\0\240m\0\0\0\0\0\0\0\0\0\0"..., 43560) = 43560
read(13, "\2\0\0\0\24\1\16\3\0\0\0\0\0\0\0\0\0\0\0\0\241m\0\0\0\0\0\0\0\0\0\0"..., 43560) = 43560
read(13, "\2\0\0\0\24\1\16\3\0\0\0\0\0\0\0\0\0\0\0\0Bx\0\0\0\0\0\0\0\0\0\0"..., 43560) = 43560
read(13, "\2\0\0\0\24\1\16\3\0\0\0\0\0\0\0\0\0\0\0\0Cx\0\0\0\0\0\0\0\0\0\0"..., 43560) = 43560
read(13, "", 43560)                     = 0
close(13)                               = 0
madvise(0x7faaa0030000, 45056, MADV_DONTNEED) = 0
madvise(0x7faaa0026000, 40960, MADV_DONTNEED) = 0
gettimeofday({tv_sec=1698158330, tv_usec=999632}, NULL) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7faab57a2f40) = 0
gettimeofday({tv_sec=1698158332, tv_usec=227}, NULL) = 0
openat(AT_FDCWD, "/proc/rtpengine/7/blist", O_RDONLY) = 9
read(9, "", 43560)                      = 0
close(9)

The above is from before & after the call was ended.

However, running rtpengine-ctl -ip 127.0.0.1:22000  list totals returns nothing. I enabled tcp port for the localhost while for outside world it is on private & public IP on udp (if that makes a difference). The cmd was run before, during & after the (phone) call with no output.

I am assuming this is not normal, so what could I be missing?

PS: this is being built on Debian 11 6.1.55 on AWS.

 

[Richard Fuchs]

On 24/10/2023 11.30, [EXT] Anshuman Rawat wrote:

However, running rtpengine-ctl -ip 127.0.0.1:22000  list totals returns nothing. I enabled tcp port for the localhost while for outside world it is on private & public IP on udp (if that makes a difference). The cmd was run before, during & after the (phone) call with no output.

Make sure you're not confusing the TCP control port (listen-tcp=...) with the CLI port (also TCP, but listen-cli=...). For rtpengine-ctl you want to use the CLI port. The TCP control port is only useful if backwards compatibility with legacy protocols are needed.

Cheers

[Anshuman Rawat]

That was it. Everything works now. Thanks for all the help and guiding me through it.