[Home]

Summary:ASTERISK-02478: Ye old: 'Asked to transmit frame type 64, while native formats is 8 (read/write = 8/8)'
Reporter:ajlow (ajlow)Labels:
Date Opened:2004-09-27 10:11:15Date Closed:2005-04-21 21:38:04
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/Interoperability
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) bug_2519_patch_bkw0318_output.txt
( 1) channel.c.diff.txt
( 2) h323.txt
( 3) SLIN01
Description:I am currently suffering the exact same bug as described in BUG ID 0001959, in summary, receiving a 'Asked to transmit frame type 64, while native formats is 8 (read/write = 8/8)' when call connects then hangs up. It appears to be caused by the playtones_generator routine in indications.c trying to produce a ring signal on the channel.

The reason I am hitting this problem seems to be that the SIP UA I am using is sending a 183 Session Progress prior to a 180 Alerting. It appears to me that Asterisk is treating the 183 similar to a Q.931 Call Proceeding with in-band info and opening the channel between the endpoints but then gets confused when it receives a 180 Alerting after it.

I cannot see anything in the RFC's that would suggest this sequence (183 then 180) would be invalid.

****** ADDITIONAL INFORMATION ******

Downgrading to minor pending reporter contact.
Comments:By: ajlow (ajlow) 2004-09-27 10:13:07

The SIP UA is an InAlp SN2300 which is converting and ISDN30 interface to SIP/RTP. We have many installed but we only get the problem with some PBX's because they send Call Proceeding before Alerting and the UA is translating this to a SIP 183 followed by 180.
By: ajlow (ajlow) 2004-09-27 10:15:17

SLIN01 is a Ethereal packet dump ...
By: Mark Spencer (markster) 2004-09-27 11:41:22

Can you find me on IRC so I can look at this?  Thanks.
By: ajlow (ajlow) 2004-09-27 12:15:06

Can do, its been a few years since I ran IRC though, which net and whats your nickname?
By: Brian West (bkw918) 2004-09-27 12:16:55

kram is his nick! :P
By: ajlow (ajlow) 2004-09-27 12:37:13

Ok Im on irc.freenode.net but cant get in #asterisk, invite only?
By: ajlow (ajlow) 2004-09-27 15:24:14

spent a good few hours in #asterisk but unable to track you down, since Im on GMT will try another time, otherwise please mail me for info.
By: Mark Spencer (markster) 2004-09-29 10:22:00

Need to try to find a time to meet up again, so I can try to duplicate this problem.  Just to be clear you are trying 1.0 or latest CVS right?
By: ajlow (ajlow) 2004-09-29 15:41:33

Running CVS of 27/09/2004, havent tried 1.0, trying to ping you now on IRC without success )c:
By: Mark Spencer (markster) 2004-09-29 16:28:15

I'm in and out all day.  You'll have to try harder :)
By: twisted (twisted) 2004-10-17 01:18:19

*POKE*  What's going on here.. this is tagged as major, yet the last update is 9/29.  We're going to need an update to keep this alive.
By: Brian West (bkw918) 2004-10-17 01:51:03

Do try latest CVS and do update us.  Otherwise we have to leave bug laying around.  If you want us to look at it you MUST reply in a timely manner.
By: ajlow (ajlow) 2004-10-17 06:19:48

Guys I spent almost a week to forefill Mark's request to find him on IRC to discuss the bug in more detail without any success. I feel the discription and attached packet debug would be sufficient to replicate the bug but if this is not the case please request what you need and I will provide it.

Otherwise if Mark has a more reliable means that I can reach him by to discuss this ie a telephone number then I would be happy to follow that route.

In the meantime I have commented out the code that checks for SLIN running on my G711 alaw channels which gets things working for now ...
By: Brian West (bkw918) 2004-10-17 11:40:34

You still failed to answer my question.  Did you try latest CVS and did it fix it?  If not you can find twisted, me (bkw_) or kram on irc.  #asterisk on irc.freenode.net

You must not have tried very hard at all.

bkw
By: ajlow (ajlow) 2004-10-17 15:04:52

No I have not tried the latest CVS as this is a production system and I am not in a position to set something up in the lab until tomorrow hence why I did not answer yet.

In my opinion I tried hard but I guess that could always be open to others opinion. I am on IRC now (which I do not use for any other purpose) ...
By: Danny Froberg (dfroberg) 2004-10-17 15:35:49

I have a vauge memory of solving this by rearranging the sip.conf to;

disallow=all   <-- this is key I believe
;allow=all     <--
allow=ulaw                    
;allow=ilbc             ; The rest is just the order of preference      
allow=gsm
:allow=adpcm
;allow=speex

Hope this helps someone.
By: ajlow (ajlow) 2004-10-17 16:00:51

Chatted briefly with Mark on IRC, he requested access to a box that could replicate the bug. Unfortunately this box is in production and so I need to setup a new test box with ISDN->SIP gateway and an ISDN device that will answer calls.

This will take a day or two but I will update these bugnotes appropriately and once again try and reach mark via IRC.
By: ajlow (ajlow) 2004-10-17 16:08:11

dfroberg, thanks for the input.

Unfortunately I dont think this is going to work for me, my sip.conf is thus already:

disallow=all
allow=alaw
allow=ulaw
allow=g729
By: Brian West (bkw918) 2004-10-25 20:49:53

Something that might clue you in on where to look..

exten => 999,1,Answer
exten => 999,2,MusicOnHold(default)

then do a show channel XXXXX (what ever the channel is)

The first question to me is WHY does it show that the Write format is 64 when in fact its not.  Maybe I missing something.  Same thing applys when using meetme.

bkw
By: ajlow (ajlow) 2004-10-26 02:04:13

bkw,

Im not sure if you loaded the SLIN01 into your Ethereal but the SIP UA we are using that triggers this problem is an ISDN to SIP translator. We have 4/5 of these boxes working fine and it was only when we found a PBX that sends an ISDN Call Progress and an Alerting which resulted in the 180 & 183 conbination being sent to Asterisk from the SIP side of the ISDN translator.

The reason why its taking me so long as that I am waiting for a new delivery of these units as well as trying to build something that can emulate the Call Progress/Alerting situation on the ISDN side and answer the call.

There is another option which would be much easier for me in order to provide you guys with an enviroment to see for youself. That is that I arrange a maintenance window with the customer one evening (GMT) and then if I can get some commitment from you guys to be available we can test to our hearts content. Do you think this is viable ?
By: Russell Bryant (russell) 2004-11-07 19:47:34.000-0600

any updates here?

-- Housekeeping
By: Mark Spencer (markster) 2004-11-07 20:57:33.000-0600

If you find me on IRC  I can login and look at the issue.
By: Russell Bryant (russell) 2004-11-14 22:14:49.000-0600

Have you made an effort to contact Mark on IRC so he can address this issue?

If there aren't any updates, this bug will have to be closed due to lack of interest.

Thanks!
By: ajlow (ajlow) 2004-11-15 17:19:07.000-0600

I did contact Mark who requested an enviroment where he could witness the problem and make code changes. Unfortunately I couldnt arrange that for our production systems. Trying to replicate the setup with the ISDN-SIPUA conversion and a device on the ISDN side that would answer was not possible due to lack of hardware.

I have also not had a chance to test with the new software, again production enviroment changes ): I'm in the process of gathering the equipment for a replica setup but it will take time.

Understanding the need to keep things tidy I will accept closure for time being.

BTW: My quick hack (removing the format check) is functioning well...
By: Russell Bryant (russell) 2004-11-21 01:00:42.000-0600

There is no need to close it if it is still an issue.  I just posted that because I wanted to verify that this was still actively being worked on.

Thanks for the help to provide an environment for testing!
By: Brian West (bkw918) 2004-12-01 14:39:03.000-0600

How much do you guys wanna bet this might be related:
http://bugs.digium.com/bug_view_page.php?bug_id=0002966
By: ajlow (ajlow) 2004-12-02 02:06:57.000-0600

bkw, I don't have that wide an understanding of the coding as you but if your indicating the same codec selection is used to generate ringback then I think we're on to a winner.

Im not using app_record though just to be clear, its a straight call but the 183 in my opinion is key here.
By: Brian West (bkw918) 2004-12-02 07:48:52.000-0600

but it could be a similar issue. somewhere else in the code. ;)
By: cmaj (cmaj) 2004-12-06 11:50:53.000-0600

Although this bug has similar symptoms to ASTERISK-2932966, I'm not sure it's the same cause.  I could fix the problem with IAX2 via a patch that corrects the setup of the initial read/write formats, whereas for SIP they appear to be already selected properly.

edited on: 12-16-04 22:30
By: Olle Johansson (oej) 2004-12-12 04:07:00.000-0600

Any updates? Did the change of codec selection in sip.conf (as bkw918 pointed out) change the situation?
By: twisted (twisted) 2004-12-28 10:40:24.000-0600

Please provide an answer the update request, or we will have to assume that this issue has been resovled.

Thanks,
Housekeeping
By: Serge Vecher (serge-v) 2004-12-28 14:54:10.000-0600

I strongly suspect that the behaviour I observe is related to this bug, hence I will report it here. Although error message is different, I believe this may help further diagnosis of the bug. Functionality is not affected, however console is quickly overfilled with annoying warning messages. Here is my setup:

1. Asterisk: CVS-Head of 12-27-04
2. Phones: CISCO 79X0G/SIP 7.3 firmware.
3. sip.conf: disallow=all; allow=ulaw, allow=gsm
4. Wilcard T100P, 8 channels of E&M Wink.

How to reproduce problem:
1. Set Call Forwarding on one Cisco phone to another.
2. Call the phone with Call Forwarding through T100P
3. Observe the following until the call is picked up.
   -- Starting simple switch on 'Zap/1-1'
   -- Executing Goto("Zap/1-1", "incoming|s|10") in new stack
   -- Goto (incoming,s,10)
   -- Executing Goto("Zap/1-1", "0|2") in new stack
   -- Goto (incoming,0,2)
   -- Executing Goto("Zap/1-1", "o|1") in new stack
   -- Goto (incoming,o,1)
   -- Executing Macro("Zap/1-1", "stdexten|100|SIP/100") in new stack
   -- Executing Dial("Zap/1-1", "SIP/100|20") in new stack
   -- Called 100
   -- Got SIP response 302 "Moved Temporarily" back from 192.168.1.100
   -- Now forwarding Zap/1-1 to 'Local/105@ldaccess' (thanks to SIP/100-76c3)
   -- Executing Macro("Local/105@ldaccess-625f,2", "stdexten|105|SIP/105") in new stack
   -- Executing Dial("Local/105@ldaccess-625f,2", "SIP/105|20") in new stack
   -- Called 105
Dec 28 15:02:57 NOTICE[7223]: channel.c:1323 ast_read: Dropping incompatible voice frame on Local/105@ldaccess-625f,2 of format ulaw since our native format has changed to slin
Dec 28 15:02:57 NOTICE[7223]: channel.c:1323 ast_read: Dropping incompatible voice frame on Local/105@ldaccess-625f,2 of format ulaw since our native format has changed to slin

  Hope this helps in identifying the problem.

Thanks,

Serge
By: Mark Spencer (markster) 2005-01-06 21:22:51.000-0600

Please try latest CVS and let me know.
By: Serge Vecher (serge-v) 2005-01-07 09:04:31.000-0600

Will try this evening as behaviour is observed on the production. Will report back asap.

Serge
By: Serge Vecher (serge-v) 2005-01-07 19:42:16.000-0600

Just clean-updated to the latest CVS version. The phantom still seems to be there :(. This only happens when a call arrives on a ZapChannel, and then is Forwarded from one SIP extension to another and is in "ringing state". When the call is answered and then transferred to another SIP extension, no notices appear while the second extension rings.

Here is the transcript when notice appears:

Connected to Asterisk CVS-HEAD-01/07/05-20:09:46 currently running on asterisk02
(pid = 17010)
NIX connection>
Verbosity is at least 7
   -- Starting simple switch on 'Zap/2-1'
   -- Local/2000@ldaccess-3d81,1 answered Zap/2-1
   -- Playing 'kb-custom/ivr-greet-part1' (language 'en')
Jan  7 20:19:28 NOTICE[17010]: channel.c:1352 ast_read: Dropping incompatible voice frame on Local/2000@ldaccess-3d81,2 of format gsm since our native format has changed to slin
Jan  7 20:19:29 NOTICE[17010]: channel.c:1352 ast_read: Dropping incompatible voice frame on Local/2000@ldaccess-3d81,2 of format gsm since our native format has changed to slin
Jan  7 20:19:30 NOTICE[17010]: channel.c:1352 ast_read: Dropping incompatible voice frame on Local/2000@ldaccess-3d81,2 of format gsm since our native format has changed to slin
 == Spawn extension (macro-stdexten, s, 1) exited non-zero on 'Local/2000@ldacc
ess-3d81,2<ZOMBIE>' in macro 'stdexten'

Serge
By: Serge Vecher (serge-v) 2005-01-21 17:39:57.000-0600

Updated the system to CVS-01/21/05 tonight. Still seeing the problem:

Serge

   -- Starting simple switch on 'Zap/1-1'
   -- Executing SetGlobalVar("Zap/1-1", "OPERATOR=SIP/100") in new stack
   -- Setting global variable 'OPERATOR' to 'SIP/100'
   -- Executing Goto("Zap/1-1", "incoming|0|2") in new stack
   -- Goto (incoming,0,2)
   -- Executing Macro("Zap/1-1", "stdexten|100|SIP/100") in new stack
   -- Executing Dial("Zap/1-1", "SIP/100|20") in new stack
   -- Called 100
   -- Got SIP response 302 "Moved Temporarily" back from 192.168.1.100
   -- Now forwarding Zap/1-1 to 'Local/105@ldaccess' (thanks to SIP/100-0209)
   -- Executing Macro("Local/105@ldaccess-3fef,2", "stdexten|105|SIP/105") in new stack
   -- Executing Dial("Local/105@ldaccess-3fef,2", "SIP/105|20") in new stack
   -- Called 105
Jan 21 18:25:28 NOTICE[11452]: channel.c:1352 ast_read: Dropping incompatible voice frame on Local/105@ldaccess-3fef,2 of format gsm since our native format has changed to slin
Jan 21 18:25:28 NOTICE[11452]: channel.c:1352 ast_read: Dropping incompatible voice frame on Local/105@ldaccess-3fef,2 of format gsm since our native format has changed to slin
By: Mark Spencer (markster) 2005-02-08 01:55:28.000-0600

Does this only occur when using local channel?
By: Serge Vecher (serge-v) 2005-02-08 10:06:59.000-0600

Mark: yes, only when using the local channel. Additionally, it only happens on zap->local->sip or sip->local->zap scenario. sip->local->sip is fine.

Serge
By: Serge Vecher (serge-v) 2005-02-14 17:30:57.000-0600

Do you want me to run some specific debug tests? The system is in production, but I could do some work afterhours.
By: halightw (halightw) 2005-02-15 10:00:04.000-0600

I am having the same problem with a new install, Grandstream ATA-486 and Sipura SPA cause the exact same issue while the free X-Lite softphone has no problem. I can hear audio but not transmit.
This error message is repeated....
Feb 15 05:44:54 WARNING[7403]: chan_sip.c:1829 sip_write: Asked to transmit frame type 64, while native formats is 4 (read/write = 4/4)

I was running 1.0.3 upgraded to 1.0.5 today with no effect.
By: nick (nick) 2005-03-09 21:25:03.000-0600

Is this still a problem with CVS HEAD?

NB
By: Serge Vecher (serge-v) 2005-03-09 21:31:16.000-0600

Nick, the problem is still there. Running CVS-Head 03/08/2005.

Serge
By: ajlow (ajlow) 2005-03-10 06:46:45.000-0600

Ok original poster back, sorry for the long absence but this was due to me changing browser (and losing login credentials) and not having any means to get my password recovered for the site, anyone fancy developing this ? :)

I will test again using my originals params with latest CVS.
By: Michael Jerris (mikej) 2005-03-17 21:32:48.000-0600

Update on this?
By: Brian West (bkw918) 2005-03-17 21:35:35.000-0600

Ok Here we go.

Try this patch.. keep an eye on all the times the read/write formats are changed.

/b
By: srathje (srathje) 2005-03-18 15:48:01.000-0600

Not to spoil your fun, I've got the exact same problem using HEAD(fresh copy), chan_h323 and a Siemens OptiPoint 300A w/ 2.5 H323 firmware (alaw only)

Put the "r" on Dial and it fails.. Plus a couple of other scenarios..

(h323.txt)
By: Serge Vecher (serge-v) 2005-03-18 18:40:54.000-0600

Ok, just updated to CVS Head with bkw's patch applied. Here is the interesting part:

[Mar 18 19:32:22]     -- Called 105
[Mar 18 19:32:22]   == Set channel SIP/105-9090 to read format slin
[Mar 18 19:32:22]   == Set channel Zap/1-1 to write format slin
[Mar 18 19:32:22]   == Set channel SIP/105-9090 to write format gsm
[Mar 18 19:32:22]   == Set channel Zap/1-1 to read format gsm
[Mar 18 19:32:22]     -- Got SIP response 302 "Moved Temporarily" back from 192.168.1.105
[Mar 18 19:32:22]     -- Now forwarding Zap/1-1 to 'Local/108@ldaccess' (thanks to SIP/105-9090)
[Mar 18 19:32:22]     -- Executing Macro("Local/108@ldaccess-408a,2", "stdexten|108|SIP/108") in new stack
[Mar 18 19:32:22]     -- Executing Dial("Local/108@ldaccess-408a,2", "SIP/108|20") in new stack
[Mar 18 19:32:22]     -- Called 108
[Mar 18 19:32:22]   == Set channel SIP/108-a0bb to read format slin
[Mar 18 19:32:22]   == Set channel Local/108@ldaccess-408a,2 to write format slin
[Mar 18 19:32:22]   == Set channel SIP/108-a0bb to write format gsm
[Mar 18 19:32:22]   == Set channel Local/108@ldaccess-408a,2 to read format gsm
[Mar 18 19:32:22] NOTICE[18973]: channel.c:1341 ast_read: Dropping incompatible voice frame on Local/108@ldaccess-408a,2 of format gsm since our native format has changed to slin


Full transcript in bug_2519_patch_bkw0318_output.txt

-s
By: Brian West (bkw918) 2005-03-19 00:29:50.000-0600

w00t that should narrow it down a bit eh?

/b
By: Serge Vecher (serge-v) 2005-03-19 11:09:33.000-0600

Well something is not working properly, as:
1) We == Set channel Local/108@ldaccess-408a,2 to read format _gsm_
2) Then we are dropping a frame of format gsm because something changed format to slin and there was no idication of that.
By: Brian West (bkw918) 2005-03-19 22:44:08.000-0600

Is this only a Local/ issue? or does it happen elsewhere?

/b
By: Serge Vecher (serge-v) 2005-03-21 07:04:38.000-0600

Bkw: yes, only when using the Local/ channel. Additionally, it only happens in zap->local->sip or sip->local->zap scenario and end device is ringing. sip->local->sip is fine. Also, when call is answered - the problem goes away
By: Serge Vecher (serge-v) 2005-04-06 18:58:11

There appear to be some good news: the problem is no longer exhibited in zap->local->sip scenario for 04/04 HEAD.

However, the problem still exists in sip->local->zap scenario.

I've checked the bkbits.net site and the only change between 04/04 and 03/18 (previous HEAD I've tested) for chan_local.c has to do with local_sendhtml function. So, probably, the source is not in that file.

The scenario that got fixed was the important one for me. So, probably, we can close this bug out and hope second scenario gets fixed as biproduct of future work. Thanks
By: Brian West (bkw918) 2005-04-06 21:10:25

3947 could be the cure of this also... I suspect they are somewhat related.

/b
By: Serge Vecher (serge-v) 2005-04-06 22:32:36

Possibly. I've tried anthm's patch from 3947 -> sip->local->zap problem still there :(
By: Serge Vecher (serge-v) 2005-04-21 18:09:53

Ok, I've just checked out fresh Asterisk HEAD and the problem appears to be fixed for both zap->local->sip and sip->local->zap scenarios.

As far as I am concerned, this bug can be closed.

Thanks, -serge
By: Kevin P. Fleming (kpfleming) 2005-04-21 21:37:56

Apparently fixed by duplicate bug.