MOS 4.5 and no loss despite simulated outages

[drbw]

I'm currently deploying the sniffer as a Docker container in order to monitor calls being made by sipp. For this, I'm using service:sipp networking mode and sniffing outgoing traffic from the sipp container. This works well for recording jitter and delay which appear to reflect conditions well.

The calls are ca. 2min in length and go to echo or to me for testing. It's just one at a time for now - I may sniff our production calls later. The codec is G711a and I'm just playing back the well-known wurlitzer sample in a loop.

However, no matter what I do, my MOS is at a stable 4.5. I've tried introducing massive packet loss (10%) with emnet and iptables on the Docker host, reordering packets a lot and introducing large amounts of jitter. In order to make sure it wasn't a local effect, I also limited the bandwidth to 1 kbit/s on the firewall (we have a cloud PBX). All of these produce clearly audible distortions, delays, reordering, stuttering etc. so the actual MOS was very low.

However, with -v 999 sniffer still reports:

elastic-helper0-voipmonitor | -call dump 0x5eb8000---------------------------------
elastic-helper0-voipmonitor | callid:1-6@172.27.0.3
elastic-helper0-voipmonitor | last packet time:1570637444
elastic-helper0-voipmonitor | last SIP response [200] [200 OK]
elastic-helper0-voipmonitor | ipport_n:2
elastic-helper0-voipmonitor | addr: 172.27.0.3, port: 6000
elastic-helper0-voipmonitor | addr: <snip>, port: 15004
elastic-helper0-voipmonitor | From:99977
elastic-helper0-voipmonitor | To:40
elastic-helper0-voipmonitor | First packet: 1570637343, Last packet: 1570637444
elastic-helper0-voipmonitor | ssrc_n:1
elastic-helper0-voipmonitor | Call statistics:
elastic-helper0-voipmonitor | SSRC:ca110000 3390111744 ssrc_index[0]
elastic-helper0-voipmonitor | codec:8
elastic-helper0-voipmonitor | src ip:172.27.0.3
elastic-helper0-voipmonitor | dst ip:<snip>
elastic-helper0-voipmonitor | dst port:15004
elastic-helper0-voipmonitor | Packetization:20
elastic-helper0-voipmonitor | s->received: 3438
elastic-helper0-voipmonitor | total loss:0
elastic-helper0-voipmonitor | loss ratio:0.000000
elastic-helper0-voipmonitor | serial loss: 1:0 2:0 3:0 4:0 5:0 6:0 7:0 8:0 9:0 10:0
elastic-helper0-voipmonitor | d50: 0, d70: 0, d90: 0, d120: 0, d150: 0, d200: 0, d300: 0
elastic-helper0-voipmonitor | jitter stats:
elastic-helper0-voipmonitor | fix(50/50)    loss rate:  0.000000
elastic-helper0-voipmonitor | fix(50/50)    burst rate: 0.000000
elastic-helper0-voipmonitor | fix(200/200)  loss rate:  0.000000
elastic-helper0-voipmonitor | fix(200/200)  burst rate: 0.000000
elastic-helper0-voipmonitor | adapt(500/500)    loss rate:  0.000000
elastic-helper0-voipmonitor | adapt(500/500)    burst rate: 0.000000
elastic-helper0-voipmonitor | ---
elastic-helper0-voipmonitor | -end call dump  0x5eb8000----------------------------

voipmonitor.conf:

[general]
timezone = /usr/share/zoneinfo/Europe/Berlin
id_sensor = 1

sqldriver = mysql
mysqlhost = elastic-helper0-mysql
mysqlport = 3306
mysqlusername = root
mysqlpassword = my-secret-pw
mysqldb = voipmonitor
cdr_partition = yes
mysqlcompress = yes
mysqlloadconfig = no
sqlcallend = yes

cleandatabase = 7

interface = eth0
promisc = yes
#filter = udp or (vlan and udp)

managerport = 5029
sipport = 5060
cdr_sipport = yes
cdr_rtpport = yes
cdr_rtpsrcport = yes

absolute_timeout = 120
destroy_call_at_bye = 120
onewaytimeout = 120
sipwithoutrtptimeout = 120
rtptimeout = 120

ringbuffer = 50
packetbuffer_enable             = yes
packetbuffer_compress           = no
max_buffer_mem          = 1000

jitterbuffer_f1 = yes
jitterbuffer_f2 = yes
jitterbuffer_adapt = yes
plcdisable = no
callslimit = 5

cdrproxy = yes
cdr_ua_enable = yes

# ????
# this is important option if voipmonitor is sniffing on SIP proxy and see both RTP leg of CALL.
# in that case use this option. It will analyze RTP only for the first LEG and not each 4 RTP
# streams which will confuse voipmonitor. Drawback of this switch is that voipmonitor will analyze
# SDP only for SIP packets which have the same IP and port of the first INVITE source IP
# and port. It means it will not work in case where phone sends INVITE from a.b.c.d:1024 and
# SIP proxy replies to a.b.c.d:5060. If you have better idea how to solve this problem better
# please contact support@voipmonitor.org
rtp-firstleg = no

deduplicate = no

sipoverlap = yes
sip-register = yes
sip-register-timeout = 5
sip-register-active-nologbin = yes
nocdr = no
cdronlyanswered = no
cdronlyrtp = no

skinny = no

maxpcapsize = 50
spooldir = /var/spool/voipmonitor
pcap_dump_bufflength = 8184
pcap_dump_zip = yes
pcap_dump_zip_rtp = lzo
pcap_dump_ziplevel_rtp = 1
pcap_dump_writethreads = 1
pcap_dump_writethreads_max = 32
pcap_dump_asyncwrite = yes

cachedir = /dev/shm/voipmonitor
savesip = yes
savertp = header
pcapsplit = yes
savertcp = yes
saveaudio_stereo = yes
silencedetect = yes
silencethreshold = 512
clippingdetect = yes
savegraph = yes

maxpoolsize     = 501200
maxpooldays     = 7
autocleanspool = yes
autocleanspoolminpercent = 1
autocleanmingb = 5
mos_g729 = yes

mos_lqo = yes
mos_lqo_bin = pesq
mos_lqo_ref = /usr/local/share/voipmonitor/audio/mos_lqe_original.wav
mos_lqo_ref16 = /usr/local/share/voipmonitor/audio/mos_lqe_original_16khz.wav

dscp = yes

Is this a bug or am I not getting something?

[voipmonitor]

Hi, share the pcap please

[drbw]

Attached is a pcap from a call to Echo, with 5 kbps bandwidth, 100ms +- 100ms delay, 10% loss, 25% reordering. Wireshark can't open it, by the way - is it some proprietary format? Otherwise I'd have looked at it myself.

Screenshot of ping statistics to the PBX is attached as well (avg / minmax as shadow) - it's clearly visible that the restrictions are working. I had the jitter running over night and re-introduced the loss and bandwidth restriction when the line gets torn.

rtp_2019-10-10-07-44.tar.gz

[voipmonitor]

I need pcap which I can open in the wireshark - run the tcpdump during your test and send the raw pcap

[drbw]

rtp.pcap.gz

Hi, RTP pcap is attached. For a single call for the first time, the f1_min MOS actually dropped to 3.7 now and adapt_min to 4.0, by the way. (Rest still 4.5.) However, listening to the echoed stream, you can hear the single packets trickling in from the PBX - that's more like 1.0 MOS... but at least it means the relevant code is executed. It still looks like it's mostly using the values you initialize the variables with, though.

Also, for the linked pcap, voipmonitor still writes a loss of 0 to the DB and logs "total loss: 0" to console. At the same time, I'm seeing messages like this:

voipmonitor | bc loss[5]: 7 bc loss[117]: 1
voipmonitor | bc loss[7]: 3 bc loss[110]: 1
voipmonitor | bc loss[15]: 2    bc loss[18]: 1  bc loss[127]: 1

The console output is a bit hard to interpret, though, to be honest...

[voipmonitor]

I'm checking the pcap and there is no packet loss at all (I'm checking stream coming from 172.31.0.2)

[drbw]

That's the stream from sipp whose network stack voipmonitor is sitting on, it's always going to look good. If I could give you the full traffic, it would be clearer and you could listen to it in Wireshark, but unfortunately that would reveal sensitive information.

However, the issue seems to be resolved. I dropped such large amounts of packets because I wasn't seeing stats in the beginning due to configuration errors and just kept them like that. It seems the quality was just too bad for your model. I tried with less aggressive limits and (1% packet loss and 2% reordering) and b_mos_f1_min instantly crashes to 1.0 and more or less stays there.

Weirdly, the adapt value floats between 3.5-4.5 and f2 is still sitting at 4.5, though, and 0 loss is written to the DB. However, I think the problem may be more in my simple approach to testing - I'll ask our network guys to produce some more realistic issues on the line instead of on the Docker host.

Thanks for responding so quickly! Hope this thread will help people looking for ways to test your sniffer.