Re: pjsua -- non-interactive mode for quality monitoring?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Franz, I spotted yet another difference in our logs: yours includes this very cool line:

common.c Nagios output: connect time: 14.184s total time: 18.257s setup time: 4.073s jitter avg: 0.285 msecs rtt avg: 16.518 msec loss: 0.0% codec: PCMA @8kHz

This is exactly what I would need - on my build it is missing. I also grepped the entire sources looking for the phrase "Nagios output", but found no match. Is this something you have added yourself?

cheers,
Mateusz




On 06/02/2020 23:22, Mateusz Viste wrote:
Hi,

The 'silence' I send is being actually sent over RTP (ie. it truly is a stream, I can see it in Wireshark), but just to be sure I added "--auto-loop" to my pjsua command-line - so now my call echoes back whatever the remote end says. And again - I can see in Wireshark that it works, pjsua receives a stream, and sends it back with a slight delay.

But still -- the RTT stats shows 0.

I compared your console output with mine (thanks for sharing it!). I see that in your case, there are two RX/TX dumps, and the first one displays a RTT with a 0.000 value - just like mine. The big difference being that you have a second RX/TX stats dump that follows the first one, and this second dump does have a non-zero RTT. Myself, I have only one dumpe (presumably because I am processing a single connection, while you perform some kind of conferencing, I think). Would you mind telling what is the difference between the two calls you have?

Mateusz




On 06/02/2020 21:42, Skale Franz wrote:
Hi,
i use version 2.9 only with the patch i commited (FFMPEG) as well as one from Andreas. My check_call_loop connects a wav file (with text2speech) to the conference bridge and it will start to play when CONFIRM (200) has been sent. So, my wav file is 14s long. RTT is 20ms via SIP->GSM->SIP.
So basically, the client is also a server when using pjsua callbacks.
For the mainloop i use the superb EV Library (http://software.schmorp.de/pkg/EV.html).
pjsua uses and endless for loop, so the program won't be closed.
My guess is, that when you send silence, there are only protocol level packets but no stream, therefore the stats show "0".

My 14s call loop output: (keep in mind, that it calls a number which will be rerouted to SIP using another subscriber and calls back the app. So i have call 0 TX and call1 RX):
Here one call (obfuscated IP addresses and contacts etc)

21:00:01.421           pjsua_core.c !.pjsua version 2.9 for Linux-4.19.91/x86_64/glibc-2.28 initialized
21:00:01.422             init_app.c  WAV player conf port id: 1
21:00:01.422             init_app.c  Setting clock rate to wav file properties: 22050 Hz 21:00:01.422             init_app.c  Conference port info: Port #01[22KHz/20ms/1] 21:00:01.422             init_app.c  Wav properties: Sample rate: 22KHz Bits per sample: 16 Channel count: 1 File length: 624546 bytes
21:00:01.422             init_app.c  Estimated play duration: 14 seconds
21:00:01.422             init_app.c  Enabling NULL audio
21:00:01.426               module.c  ....INVITE: From: xxxxxxxxxxxx
21:00:01.426            callbacks.c  .......Call 0 state changed to CALLING
21:00:01.426                   ev.c  Initialize read event watcher
21:00:01.426                   ev.c  Start I/O event watcher
21:00:01.426                   ev.c  Init timeout event watcher
21:00:01.426                   ev.c  Init write event watcher
21:00:01.426                   ev.c  Start timeout event watcher
21:00:01.426                   ev.c  Start write event watcher
21:00:01.426                   ev.c  Start main event loop
21:00:01.436               module.c !.......INVITE: From: xxxxxxxxxxxxxx
21:00:01.436               module.c !.......INVITE: From: 0720258001
21:00:01.439            pjsua_acc.c ....sip:xxxxxxxxxxx@xxxxxxxxxxxxxxxx: registration success, status=200 (OK), will re-register in 600 seconds 21:00:05.200            callbacks.c  ..Incoming call successfully verified 21:00:05.200            callbacks.c  ..Incoming call from <sip:xxxxxxxxxxxx@xxxxxxxxxxxxxxxxxxx> 21:00:05.200            callbacks.c  ..Call-ID: 1 Call-ID-string: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxx Active: 1 21:00:05.200            callbacks.c  ..Local contact: <sip:xxxxxxxxx@xxxxxxxxxxxxxxx:5060;ob> 21:00:05.200            callbacks.c  ..Remote contact: <sip:xxxxxxxxxxxxxx@xxxxxxxxxxxxxxx>
21:00:05.200            callbacks.c  .......Media stream created: 1 0
21:00:05.201            callbacks.c  .....Call media active: 1 Slot: 2
21:00:05.201            callbacks.c  .........Call 1 state changed to CONNECTING 21:00:05.223            callbacks.c  ...Successfully connected wav conf port: 1 to conf slot: 2
21:00:05.223            callbacks.c  ...Call 1 state changed to CONFIRMED
21:00:05.292            callbacks.c  .....Call 0 state changed to EARLY
21:00:05.496            callbacks.c  .....Call 0 state changed to CONNECTING
21:00:05.496            callbacks.c  .......Media stream created: 0 0
21:00:05.497            callbacks.c  .....Call media active: 0 Slot: 3
21:00:05.497            callbacks.c  .....Call 0 state changed to CONFIRMED 21:00:19.648            callbacks.c  .....Call 1 is DISCONNECTED [reason=200 (Normal call clearing)] 21:00:19.648            callbacks.c  .....Call 1 disconnected, dumping media stats..
21:00:19.648               common.c  .....
[DISCONNCTD] t: <sip:xxxxxxxxxxxxxxx@xxxxxxxxxx>;tag=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
     Call time: 00h:00m:14s, 1st res in 1 ms, conn in 24ms
     #0 audio PCMA @8kHz, sendrecv, peer=xxx.xxx.xxx.xxx:37724
        SRTP status: Not active Crypto-suite:
        RX pt=8, last update:00h:00m:00.226s ago
           total 717pkt 114.7KB (143.4KB +IP hdr) @avg=63.5Kbps/79.4Kbps
           pkt loss=1 (0.1%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
                 (msec)    min     avg     max     last    dev
           loss period:  20.000  20.000  20.000  20.000   0.000
           jitter     :   0.000   0.011   0.125   0.000   0.035
        TX pt=8, ptime=20, last update:never
           total 714pkt 114.2KB (142.8KB +IP hdr) @avg=63.2Kbps/79.0Kbps
           pkt loss=0 (0.0%), dup=0 (0.0%), reorder=0 (0.0%)
                 (msec)    min     avg     max     last    dev
           loss period:   0.000   0.000   0.000   0.000   0.000
           jitter     :   0.000   0.000   0.000   0.000   0.000
        RTT msec      :   0.000   0.000   0.000   0.000   0.000
21:00:19.681            callbacks.c  .....Call 0 is DISCONNECTED [reason=200 (Normal call clearing)] 21:00:19.681            callbacks.c  .....Call 0 disconnected, dumping media stats..
21:00:19.681               common.c  .....
   [DISCONNCTD] t: sip:xxxxxxxxxxxxxxxxxx@xxxxxxxxxxxxxx;tag=xxxxxxxxxxxxxxxxxxxxxxxxxxx
     Call time: 00h:00m:14s, 1st res in 3868 ms, conn in 4073ms
     #0 audio PCMA @8kHz, sendrecv, peer=xxxxxxxxxxxxx:37764
        SRTP status: Not active Crypto-suite:
        RX pt=8, last update:00h:00m:03.418s ago
           total 707pkt 113.1KB (141.4KB +IP hdr) @avg=63.7Kbps/79.7Kbps
           pkt loss=0 (0.0%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
                 (msec)    min     avg     max     last    dev
           loss period:   0.000   0.000   0.000   0.000   0.000
           jitter     :   0.000   0.285   0.500   0.375   0.124
        TX pt=8, ptime=20, last update:00h:00m:05.044s ago
           total 33pkt 5.2KB (6.6KB +IP hdr) @avg=2.9Kbps/3.7Kbps
           pkt loss=0 (0.0%), dup=0 (0.0%), reorder=0 (0.0%)
                 (msec)    min     avg     max     last    dev
           loss period:   0.000   0.000   0.000   0.000   0.000
           jitter     :   0.000   0.000   0.000   0.000   0.000
        RTT msec      :  12.802  16.518  20.233  12.802   3.715
21:00:20.428                   ev.c !LOG DUMP DONE
21:00:20.428               common.c  Connect duration (msec): 14184 Total durarion (msec): 18257 Setup time (seconds): 4.073 21:00:20.428               common.c  Nagios output: connect time: 14.184s total time: 18.257s setup time: 4.073s jitter avg: 0.285 msecs rtt avg: 16.518 msec loss: 0.0% codec: PCMA @8kHz
21:00:20.428               common.c  warning: 15 Critical: 20
21:00:20.428               common.c  Call Loop finished:: Success [status=0]
21:00:20.428                   ev.c  Stopping outstanding event loops
21:00:20.428               common.c  Releasing memory pool
21:00:20.428               common.c  Destroy pjsua
21:00:20.442            pjsua_acc.c .....xxxxxxxxxxx@xxxxxxxxxxxxxxxxx: unregistration success


Best regards
Franz
________________________________________
Von: pjsip <pjsip-bounces@xxxxxxxxxxxxxxx> im Auftrag von Mateusz Viste <mateusz@xxxxxxxx>
Gesendet: Donnerstag, 06. Februar 2020 21:21
An: pjsip@xxxxxxxxxxxxxxx
Betreff: Re: pjsua -- non-interactive mode for quality monitoring?

Hello Franz,

On 06/02/2020 17:54, Skale Franz wrote:
I really do think you didn't make a call at all.
You didn't attach a wav file nor did you supply a tone generation at the commandline.

I definitely did a call, but you are correct to assume the worst :)

I even did a tcpdump capture, and using wireshark I see RTP traffic
going both ways. Even more - wireshark is able to show me the waveform
of the voice communication and play it out right from the pcap (how cool
is that?!).

Apparently pjsua does not need a tone instruction nor it require any
kind of sound sample - with the command line I used, it simply
"generates" silence and sends it as a G.711 stream.

If you look at the TX/RX stats I posted in my initial message, you will
see that it says "RX = total 336 pkts, TX = total 460 pkts".

But why it is unable to compute the RTT is a mystery to me. The PBX
server is 45ms away from me, so I'd expect this to show up in the stats...

Anyway, my three initial questions still hold :)

1. Is there a "proper" way to fetch call stats from pjsua? (other than
savagely grepping, seding and cutting its console output)

2. How should I instruct pjsua to quit when the call is over? Currently
I run it through the Linux "timeout" command so it gets killed after a
few seconds, but that's a really dirty way of doing business.

3. What may be the reason pjsua outputs "0.000" in its RTT stats output?

The stats are for media quality, but will show 0 when no RDP session was established !

Do you confirm that you do get some meaningful "RTT msec" values in
pjsua's output? Do you use vanilla pjsua code, as found in pjsip 2.9?

best,
Mateusz




________________________________________
Von: pjsip <pjsip-bounces@xxxxxxxxxxxxxxx> im Auftrag von Mateusz Viste <mateusz@xxxxxxxx>
Gesendet: Donnerstag, 06. Februar 2020 16:49
An: pjsip@xxxxxxxxxxxxxxx
Betreff:  pjsua -- non-interactive mode for quality monitoring?

Hello list,

I am fiddling with the pjsua tool from pjsip 2.9, because I'd like to
use it to monitor the quality of my VoIP provider at home. I am able to
run a call all right, but pjsua does not exit once the call is
terminated - I have to press 'q' to quit the interactive shell.

Is there any trick I could use so pjsua performs the call, and exit once
the call ends? This is the command line I use now:

./pjsua-armv7l-unknown-linux-gnueabihf
--id='sip:mylogin@xxxxxxxxxxxxxxx' --realm='*' --username='mylogin'
--password='xxxxxx' --disable-stun --no-tcp --null-audio --no-vad
--max-calls=1 --duration=10 'sip:123@xxxxxxxxxxxxxxx' --no-color

Additionally, I'd need to get some stats from it. Currently I am
grepping the logs that pjsua outputs, to extract some data from this:

    RX pt=0, last update:00h:00m:03.841s ago
       total 336pkt 53.7KB (67.2KB +IP hdr) @avg=46.7Kbps/58.4Kbps
       pkt loss=0 (0.0%), discrd=0 (0.0%), dup=0 (0.0%), reord=0 (0.0%)
             (msec)    min     avg     max     last    dev
       loss period:   0.000   0.000   0.000   0.000   0.000
       jitter     :   0.000   0.119   0.750   0.125   0.151
    TX pt=0, ptime=20, last update:never
       total 460pkt 73.6KB (92.0KB +IP hdr) @avg=64.0Kbps/80.0Kbps
       pkt loss=0 (0.0%), dup=0 (0.0%), reorder=0 (0.0%)
             (msec)    min     avg     max     last    dev
       loss period:   0.000   0.000   0.000   0.000   0.000
       jitter     :   0.000   0.000   0.000   0.000   0.000
    RTT msec      :   0.000   0.000   0.000   0.000   0.000

...but maybe there is some easier way? I noticed that 'RTT msec' always
shows 0.000, which is kind of strange. Any idea?

best,
Mateusz

_______________________________________________
Visit our blog: http://blog.pjsip.org

pjsip mailing list
pjsip@xxxxxxxxxxxxxxx
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org

_______________________________________________
Visit our blog: http://blog.pjsip.org

pjsip mailing list
pjsip@xxxxxxxxxxxxxxx
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org


_______________________________________________
Visit our blog: http://blog.pjsip.org

pjsip mailing list
pjsip@xxxxxxxxxxxxxxx
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org

_______________________________________________
Visit our blog: http://blog.pjsip.org

pjsip mailing list
pjsip@xxxxxxxxxxxxxxx
http://lists.pjsip.org/mailman/listinfo/pjsip_lists.pjsip.org




[Index of Archives]     [Asterisk Users]     [Asterisk App Development]     [Linux ARM Kernel]     [Linux ARM]     [Linux Omap]     [Fedora ARM]     [IETF Annouce]     [Security]     [Bugtraq]     [Linux]     [Linux OMAP]     [Linux MIPS]     [Linux API]
  Powered by Linux