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

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

 



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



[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