[Home]

Summary:ASTERISK-08051: After a while of operation, IAX becomes behaving incorrectly, no audio or 1-way, and no-answer
Reporter:Anton Vazir (vazir)Labels:
Date Opened:2006-11-02 09:53:03.000-0600Date Closed:2007-03-05 14:37:59.000-0600
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) iax2-ethereal-dump.tgz
( 1) iaxsilentbug.txt
Description:SUBJ. Some amount of calls must pass the box to make IAX behave so. For me setup a box on a transit Asterisk that happen after several hours of normal operation. Tim Panton <tim@mexuar.com> have looked at the ethereal capture of the flow and the following has been found:

----------FROM TIM ---

IAX2 calls go silent in 1.4

1.4 seems to send invalid miniframe packets:

Here's an ethereal trace:

 1   0.000000 192.168.8.38 -> 212.44.92.99 IAX2 IAX, source call# 84, timestamp 16ms NEW
 2   0.000313 212.44.92.99 -> 192.168.8.38 IAX2 IAX, source call# 2, timestamp 3ms AUTHREQ
 3   0.000719 192.168.8.38 -> 212.44.92.99 IAX2 IAX, source call# 84, timestamp 19ms AUTHREP
 4   0.003076 212.44.92.99 -> 192.168.8.38 IAX2 IAX, source call# 2, timestamp 6ms ACCEPT
 5   0.003631 192.168.8.38 -> 212.44.92.99 IAX2 IAX, source call# 84, timestamp 6ms ACK
 6   0.003671 212.44.92.99 -> 192.168.8.38 IAX2 Control, source call# 2, timestamp 9ms ANSWER
 7   0.003954 192.168.8.38 -> 212.44.92.99 IAX2 IAX, source call# 84, timestamp 9ms ACK
 8   0.018850 192.168.8.38 -> 212.44.92.99 IAX2 Voice, source call# 84, timestamp 40ms, Raw mu-law data (G.711)
 9   0.018979 212.44.92.99 -> 192.168.8.38 IAX2 IAX, source call# 2, timestamp 40ms ACK
10   0.038825 192.168.8.38 -> 212.44.92.99 IAX2 Mini packet, source call# 84, timestamp 60ms, Raw mu-law data (G.711)

(more mini packets from 192.168.8.38 -> 212.44.92.99)

59   1.006042 212.44.92.99 -> 192.168.8.38 IAX2 Voice, source call# 2, timestamp 1020ms, Raw mu-law data (G.711)
60   1.006638 192.168.8.38 -> 212.44.92.99 IAX2 IAX, source call# 84, timestamp 1020ms ACK
61   1.018886 192.168.8.38 -> 212.44.92.99 IAX2 Mini packet, source call# 84, timestamp 1040ms, Raw mu-law data (G.711)

We then get the garbled frame:

62   1.037614 212.44.92.99 -> 192.168.8.38 IAX2

0000  00 0e a6 96 22 bb 00 14 85 c7 1e 45 08 00 45 00   ...."......E..E.
0010  00 c8 4e b9 00 00 40 11 32 0e d4 2c 5c 63 c0 a8   ..N...@.2..,\c..
0020  08 26 11 d9 11 d9 00 b4 fa 23 00 00 01 00 00 00   .&.......#......
0030  00 00 00 02 00 a0 78 78 78 79 79 79 79 79 79 78   ......xxxyyyyyyx
0040  79 79 78 79 79 79 7a 7a 7b 7b 7b 7b 7b 7c 7d 7e   yyxyyyzz{{{{{|}~
0050  7e 7d 7d 7e ff ff ff 7e 7e 7e ff ff ff ff ff ff   ~}}~...~~~......
0060  ff fe fe ff fe fe fe fd fd fd fe fe fe ff ff ff   ................
0070  7d 7e 7e 7e 7e 7e 7d 7d 7d 7c 7c 7c 7b 7b 7b 7c   }~~~~~}}}|||{{{|
0080  7b 7b 7d 7d 7d 7d 7e ff ff ff fe fe fe fc fd fd   {{}}}}~.........
0090  fd fd fd fc fd fd fe fe fe fd fd fe ff ff fe fe   ................
00a0  fe fe fd fd fd fe fe fe ff ff ff 7d 7e 7e 7d 7e   ...........}~~}~
00b0  7e 7d 7d 7d 7d 7c 7c 7c 7d 7c 7c 7b 7c 7c 7d 7d   ~}}}}|||}||{||}}
00c0  7d 7e 7e 7e 7d 7d 7e ff ff ff fe fe fe ff ff fe   }~~~}}~.........
00d0  7e 7e ff 7d 7d 7e                                 ~~.}}~


It looks like a meta (trunk) frame, but it doesn't have Meta Command or
Cmd data set to valid values. The length is plausible for a Meta frame carrying a single (G.711) packet.
Comments:By: Anton Vazir (vazir) 2006-11-02 10:06:06.000-0600

BTW, it exists also in 46821, issue were found AFTER latest patch, which was fixing IAX and which is exists in 46821, just 46663 were patched by a single patch, so did not contain a latest revision NO.
By: Jason Parker (jparker) 2006-12-22 10:10:11.000-0600

The output from iax debug would be very useful here.  There are some things we log internally, that external sniffers won't see.
By: Phoebe Anderson (phoebe) 2006-12-24 13:20:45.000-0600

I have observed this as an issue in 1.2.x as well.

Call is placed like this: SIP-Asterisk1-IAX2-Asterisk2-SIP.

IAX configured with jitterbuffer=no and trunk=no on both Asterisk boxes.

Transcoding on both ends. ie: G711-Asterisk1-Speex-Asterisk2-G711. (this is reproducable with other codecs as well)

The call proceeds normally until excessive network jitter occurs, then the following happens:

1) No audio on either end, but the channel stays up.

2) The asterisk process on Asterisk2 consumes exactly 50% of CPU per affected thread (according to top). This happens regardless of the CPU used.  I have observed this from a PIII-450 all the way up to the latest P4's.  Sometimes watching top, you can see it almost happening, the thread apporoaches 50% hits 50%, goes up to around 52% and then goes back down to more reasonable levels.

3) New calls placed to Asterisk3 will not go through

4) The condition sometimes repairs itself within a few seconds.  If not, then it may take a restart to get Asterisk3 to resume taking calls. During this time, there is no loss of connectivity, or even packet loss between the two boxes.

5) IAX2 Debug reports NOTHING when this happens.  

6) Commands like "iax2 trunk debug" return "IAX2 Trunk Debug Requested" and then no additional response until the box returns to normal.

I can reporoduce this with a jittery connection by calling a conference bridge on Asterisk2, putting it on hold and calling it again.  I hear hold music as expected, but within a few minutes the condition is observed.
By: Dmytro Mishchenko (arkadia) 2006-12-25 03:00:32.000-0600

This issue should be verified with revision after 48564. It may be gone.
By: Phoebe Anderson (phoebe) 2006-12-26 09:36:55.000-0600

Thanks Arkadia,

Using the latest 1.4.0 release, 6 Hours of testing couldn't reproduce the issue, so it looks like issue 8604 fixed in 48564 did indeed fix the problem.  

Will the fix be backported to 1.2.x?
By: Dmytro Mishchenko (arkadia) 2006-12-26 10:38:31.000-0600

Revision 48564 doesn't require back porting to 1.2 course its a fix for multithreading IAX channel which was added in v 1.4.
By: Phoebe Anderson (phoebe) 2006-12-26 11:17:06.000-0600

So the issue will remain in 1.2?
By: Joshua C. Colp (jcolp) 2007-01-25 13:46:22.000-0600

If this issue is still happening can you try the following: 1.2 as of revision 52264, 1.4 as of revision 52265, or trunk as of revision 52266? Based on the analysis there this may have caused the issue described. Note that we are having SVN issues at the moment so you may not get the latest revision, to that extent I'll be waiting awhile on this bug so don't rush too much.
By: Serge Vecher (serge-v) 2007-01-31 13:03:05.000-0600

since you weren't monitoring the issue, you may have missed file's last note. A fix in a related bug ASTERISK-8310 may help this.
By: Joshua C. Colp (jcolp) 2007-02-08 20:10:03.000-0600

Is anybody still having this happen?
By: Anton Vazir (vazir) 2007-02-08 21:49:40.000-0600

Not sure though, after upgrading * on the office PBX one of my links became one-way-audio until I've restarted * on the PSTN-GW - I use

1.4 SVN on PBX
1.4.0 on the transit
1.2.14 PSTN E1 GW
But can't say that it's this or it is not that issue.


By: pj (pj) 2007-02-11 04:04:22.000-0600

As workaround issues with one-way audio on jittery iax:
I disabled jitterbuffer on 'central' asterisk, seems, that this helps.
setup with issues:
phone(sip)-ast-branchA(jb)===IAX===(jb)central-asterisk(jb)====IAX===(jb)asterisk-branchB-phone(sip)
after workaround:
phone(sip)-ast-branchA(jb)===IAX===(jb-disable)central-asterisk(jb-disable)====IAX===(jb)asterisk-branchB-phone(sip)
related to "0008325"
seems, that asterisk have problems, when forced iax jitterbuffers are in tandem.


By: Joshua C. Colp (jcolp) 2007-02-15 19:54:44.000-0600

Well we know the issue is/was with the jitterbuffer, it's just there have been changes done that solve the issue where it was happening where I had access... so I wanted to see if it was still around for others.
By: Joshua C. Colp (jcolp) 2007-03-05 14:37:56.000-0600

It has been quite some time now with no new reports of badness after the last IAX2 changes so I'm closing this out as fixed. If this is not the case please reopen. Thanks!