O. Hartmann
2019-Nov-16 08:03 UTC
[asterisk-users] Asterisk 16.6.1: PJSIP: delayed action of core since update to 16.6.1
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
Hello,
we're running a small Asterisk appliance on a PCengine APU2C4. Base
operating system is
FreeBSD 12-STABLE, most recent incarnation as of today.
Since update of port net/asterisk16 to the latest bug fix revision 16.6.1, we
face a severe
"slowdown" of everything that the Asterisk core performs, i.e.
outgoing calls are delayed ~ 20
seconds and I guess incoming calls suffer the same until they gett patched
through to an
endpoint/telephone. We also register a higher load on idle asterisk process
since the last
update.
Here is an example when calling two attached physical phones directly, which
performed prior
to 16.6.1 almost immediately and now takes up to 30 seconds to make the called
ednpoint ring.
The calling phone/endpoint sinals by callsound that it is calling, and the sound
changes then
(some kind of different octave/tune, don't know) when the asterisk core
reports
[Nov 15 13:21:24] == Using SIP RTP Audio TOS bits 184
(see below). It is here approx 10 seconds, but there are situations were it
might more (as
observed). the host has no further load so far!
Incoming testcalls we made from wireless/mobile show the same. It seems,
asterisk is acting as
a black hole delaying device for approx 10 seconds until it decides to pass the
call through
to an endpoint and then it takes another 10 seconds until the endpoint starts
ringing (it is
in fact a group of phones ringing alltogether).
I can not see anything unusual with the underlying OS or some critical debug
messages from
asterisk itself.
Any ideas?
Kind regards,
O. Hartmann
[...]
==>> START [Nov 15 13:21:06] == Setting global variable
'SIPDOMAIN' to '192.168.2.1'
[Nov 15 13:21:15] == Using SIP RTP Audio TOS bits 184
[Nov 15 13:21:15] -- Executing [511 at internalsip_o2:1]
NoOp("PJSIP/501-00000008", "") in
new stack
[Nov 15 13:21:15] -- Executing [511 at internalsip_o2:2]
Progress("PJSIP/501-00000008", "")
in new stack
[Nov 15 13:21:15] -- Executing [511 at internalsip_o2:3]
Gosub("PJSIP/501-00000008",
"subSetChannelLocale,start,1(abschnitt211,de,de_DE)") in new stack
[Nov 15 13:21:15] -- Executing [start at subSetChannelLocale:1]
Verbose("PJSIP/501-00000008",
"2, subSetChannelLocale: ARG1: musicclass=abschnitt211, ARG2: tonezone=de,
ARG3:
language=de_DE") in new stack [Nov 15 13:21:15] > 0x807c82000 --
Strict RTP learning
after remote address set to: 192.168.2.50:17702
[Nov 15 13:21:15] == subSetChannelLocale: ARG1: musicclass=abschnitt211,
ARG2: tonezone=de,
ARG3: language=de_DE
[Nov 15 13:21:15] -- Executing [start at subSetChannelLocale:2]
Progress("PJSIP/501-00000008", "") in new stack
[Nov 15 13:21:15] -- Executing [start at subSetChannelLocale:3]
Set("PJSIP/501-00000008",
"CHANNEL(musicclass)=abschnitt211") in new stack
[Nov 15 13:21:15] -- Executing [start at subSetChannelLocale:4]
Set("PJSIP/501-00000008",
"CHANNEL(tonezone)=de") in new stack
[Nov 15 13:21:15] -- Executing [start at subSetChannelLocale:5]
Set("PJSIP/501-00000008",
"CHANNEL(language)=de_DE") in new stack
[Nov 15 13:21:15] -- Executing [start at subSetChannelLocale:6]
Return("PJSIP/501-00000008",
"") in new stack
[Nov 15 13:21:15] -- Executing [511 at internalsip_o2:4]
Dial("PJSIP/501-00000008",
"PJSIP/511,45,Ttr") in new stack
[Nov 15 13:21:15] -- Called PJSIP/511
[Nov 15 13:21:15] > 0x807c82000 -- Strict RTP switching to RTP target
address
192.168.2.50:17702 as source
[Nov 15 13:21:20] > 0x807c82000 -- Strict RTP learning complete
- - - Locking on source address 192.168.2.50:17702
===>> CHANGE OF RINGING/CONNECTING [Nov 15 13:21:24] == Using SIP RTP
Audio TOS bits 184
[Nov 15 13:21:25] -- PJSIP/511-00000009 is ringing
[Nov 15 13:21:25] -- PJSIP/511-00000009 is ringing
[Nov 15 13:21:32] -- PJSIP/511-00000009 answered PJSIP/501-00000008
[Nov 15 13:21:32] > 0x807c85000 -- Strict RTP learning after remote
address set to:
192.168.2.51:24094
[Nov 15 13:21:32] -- Channel PJSIP/511-00000009 joined
'simple_bridge' basic-bridge
<ba7ffb28-a952-407a-8552-c027f1794ea1>
[Nov 15 13:21:32] -- Channel PJSIP/501-00000008 joined
'simple_bridge' basic-bridge
<ba7ffb28-a952-407a-8552-c027f1794ea1>
[Nov 15 13:21:32] > 0x807c85000 -- Strict RTP switching to RTP target
address
192.168.2.51:24094 as source
[Nov 15 13:21:37] -- Channel PJSIP/511-00000009 left 'simple_bridge'
basic-bridge
<ba7ffb28-a952-407a-8552-c027f1794ea1>
[Nov 15 13:21:37] -- Channel PJSIP/501-00000008 left 'simple_bridge'
basic-bridge
<ba7ffb28-a952-407a-8552-c027f1794ea1>
[Nov 15 13:21:37] == Spawn extension (internalsip_o2, 511, 4) exited non-zero
on
'PJSIP/501-00000008'
[...]
-----BEGIN PGP SIGNATURE-----
iHUEARYIAB0WIQSy8IBxAPDkqVBaTJ44N1ZZPba5RwUCXc+tWQAKCRA4N1ZZPba5
R4nQAQD56LR+gi78iUVjvolqX05wVB87SsHmHphayX4ST20hkwD9FMMgb6/QLW/S
qPnh7b3VB5qanVQFW7XFcrL4e0lXsAQ=VCPx
-----END PGP SIGNATURE-----
Joshua C. Colp
2019-Nov-16 11:39 UTC
[asterisk-users] Asterisk 16.6.1: PJSIP: delayed action of core since update to 16.6.1
On Sat, Nov 16, 2019 at 4:07 AM O. Hartmann <ohartmann at walstatt.org> wrote:> -----BEGIN PGP SIGNED MESSAGE----- > Hash: SHA256 > > > Hello, > > we're running a small Asterisk appliance on a PCengine APU2C4. Base > operating system is > FreeBSD 12-STABLE, most recent incarnation as of today. > > Since update of port net/asterisk16 to the latest bug fix revision 16.6.1, > we face a severe > "slowdown" of everything that the Asterisk core performs, i.e. outgoing > calls are delayed ~ 20 > seconds and I guess incoming calls suffer the same until they gett patched > through to an > endpoint/telephone. We also register a higher load on idle asterisk > process since the last > update. > > Here is an example when calling two attached physical phones directly, > which performed prior > to 16.6.1 almost immediately and now takes up to 30 seconds to make the > called ednpoint ring. > > The calling phone/endpoint sinals by callsound that it is calling, and the > sound changes then > (some kind of different octave/tune, don't know) when the asterisk core > reports > > [Nov 15 13:21:24] == Using SIP RTP Audio TOS bits 184 > > (see below). It is here approx 10 seconds, but there are situations were > it might more (as > observed). the host has no further load so far! > > Incoming testcalls we made from wireless/mobile show the same. It seems, > asterisk is acting as > a black hole delaying device for approx 10 seconds until it decides to > pass the call through > to an endpoint and then it takes another 10 seconds until the endpoint > starts ringing (it is > in fact a group of phones ringing alltogether). > > I can not see anything unusual with the underlying OS or some critical > debug messages from > asterisk itself. > > Any ideas? >Do you have a STUN server configured in rtp.conf? If you do, is it reachable, does the problem go away if you remove it? -- Joshua C. Colp Digium - A Sangoma Company | Senior Software Developer 445 Jan Davis Drive NW - Huntsville, AL 35806 - US Check us out at: www.sangoma.com & www.asterisk.org -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.digium.com/pipermail/asterisk-users/attachments/20191116/5cee3ce4/attachment.html>
Joshua C. Colp
2019-Nov-20 11:06 UTC
[asterisk-users] Asterisk 16.6.1: PJSIP: delayed action of core since update to 16.6.1
On Wed, Nov 20, 2019 at 5:40 AM O. Hartmann <o.hartmann at walstatt.org> wrote:> -----BEGIN PGP SIGNED MESSAGE----- > Hash: SHA256 > > Am Sat, 16 Nov 2019 07:39:08 -0400 > "Joshua C. Colp" <jcolp at sangoma.com> schrieb: > > > On Sat, Nov 16, 2019 at 4:07 AM O. Hartmann <ohartmann at walstatt.org> > wrote: > > > > > -----BEGIN PGP SIGNED MESSAGE----- > > > Hash: SHA256 > > > > > > > > > Hello, > > > > > > we're running a small Asterisk appliance on a PCengine APU2C4. Base > > > operating system is > > > FreeBSD 12-STABLE, most recent incarnation as of today. > > > > > > Since update of port net/asterisk16 to the latest bug fix revision > 16.6.1, > > > we face a severe > > > "slowdown" of everything that the Asterisk core performs, i.e. outgoing > > > calls are delayed ~ 20 > > > seconds and I guess incoming calls suffer the same until they gett > patched > > > through to an > > > endpoint/telephone. We also register a higher load on idle asterisk > > > process since the last > > > update. > > > > > > Here is an example when calling two attached physical phones directly, > > > which performed prior > > > to 16.6.1 almost immediately and now takes up to 30 seconds to make the > > > called ednpoint ring. > > > > > > The calling phone/endpoint sinals by callsound that it is calling, and > the > > > sound changes then > > > (some kind of different octave/tune, don't know) when the asterisk core > > > reports > > > > > > [Nov 15 13:21:24] == Using SIP RTP Audio TOS bits 184 > > > > > > (see below). It is here approx 10 seconds, but there are situations > were > > > it might more (as > > > observed). the host has no further load so far! > > > > > > Incoming testcalls we made from wireless/mobile show the same. It > seems, > > > asterisk is acting as > > > a black hole delaying device for approx 10 seconds until it decides to > > > pass the call through > > > to an endpoint and then it takes another 10 seconds until the endpoint > > > starts ringing (it is > > > in fact a group of phones ringing alltogether). > > > > > > I can not see anything unusual with the underlying OS or some critical > > > debug messages from > > > asterisk itself. > > > > > > Any ideas? > > > > > > > Do you have a STUN server configured in rtp.conf? If you do, is it > > reachable, does the problem go away if you remove it? > > > > Is there anything wrong/buggy with the implementation of the STUN service > in 16.6.1? >In that specific version? No. That code itself hasn't been touched in years, so the problem applies to every version. Using the defined STUN server to get a server reflexive ICE candidate is a blocking process. If the server isn't reachable or is extremely slow then it has to wait until a timeout occurs, causing a delay. -- Joshua C. Colp Digium - A Sangoma Company | Senior Software Developer 445 Jan Davis Drive NW - Huntsville, AL 35806 - US Check us out at: www.sangoma.com & www.asterisk.org -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.digium.com/pipermail/asterisk-users/attachments/20191120/5322d159/attachment.html>