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

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

 



Hi Mateusz,
as i stated in my last post, i programmed a call check plugin which:
1.) Calls a number which terminates on a beronet SIP Gateway (GSM -> SIP).
2.) The beronet SIP account is registered to the C5 so when a call reached the SIP Gateway, it routes the call to the internal C5  SIP account.
The program verifies the calling contact and then connects the WAV file to the conference bridge.
So i have one outgoing and one incoming call which terminates in my program, running in a different event loop.
I favour EV as eventloop interface though.
This is a special plugin for SIP providers !
When you sent nothing, there will be no jitter. Try to attach a wav file to the conference bridge and check the stats.
There's a bug when enabling the extended stats which has not been addressed by any of the core developers so far.
Perhaps, the stats my be wrong with regards to only calling a party but not reveicing a call on the same loop.
I will, later this year, publish the program on github.

Best regards
Franz


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

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

_______________________________________________
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