[Asterisk-Dev] "Unexpected control subclass '-1'"

[Andrew Kohlsmith]

I'm using a callfile with the extensions.conf that comes with asterisk (CVS 
HEAD as of today) with an extra extension hanging off the very end (in the 
default context, where my zap channels end up in):

exten => 101,1,Dial(Zap/1)

Basically it's there so I can ring my phone.  FXO loopstart signalling is 
being used.  The callfile is simple:

Channel: Local/101 at default
MaxRetries: 10
RetryTime: 300
WaitTime: 45

Context: demo
Extension: 600
Priority: 1

Basically it'll dial extension 101 and connect to extension 600 in the demo 
(the echo test).  I cp /tmp/callfile /var/spool/asterisk/outgoing and the 
phone rings just fine.  When I pick up though, I see this in the Asterisk 
CLI:

Jan  8 23:46:02 WARNING[27007]: file.c:975 ast_waitstream: Unexpected control 
subclass '-1'

Turning on debugging didn't reveal anything exciting:

Jan  8 23:43:07 DEBUG[26957]: Exception on 20, channel 1
Jan  8 23:43:07 DEBUG[26957]: Got event Ringer Off(11) on channel 1 (index 0)
Jan  8 23:43:10 DEBUG[26957]: Exception on 20, channel 1
Jan  8 23:43:10 DEBUG[26957]: Got event Ring/Answered(2) on channel 1 (index 
0)
Jan  8 23:43:10 DEBUG[26957]: Enabled echo cancellation on channel 1
Jan  8 23:43:10 DEBUG[26957]: No echo training requested
Jan  8 23:43:10 DEBUG[26957]: channel 1 answered
Jan  8 23:43:10 DEBUG[26957]: Dropping duplicate answer!
Jan  8 23:43:10 DEBUG[26957]: Planning to masquerade Zap/1-1 into the 
structure of Local/101 at default-4115,1
Jan  8 23:43:10 DEBUG[26957]: Done planning to masquerade 
Local/101 at default-4115,1 into the structure of Zap/1-1
Jan  8 23:43:10 DEBUG[26955]: Actually Masquerading Zap/1-1(6) into the 
structure of Local/101 at default-4115,1(0)
Jan  8 23:43:10 DEBUG[26955]: Got clone lock on 'Zap/1-1' at 0x8179484
Jan  8 23:43:10 DEBUG[26957]: Didn't get a frame from channel: 
Local/101 at default-4115,2
Jan  8 23:43:10 DEBUG[26957]: Bridge stops bridging channels 
Local/101 at default-4115,2 and Zap/1-1<MASQ>
Jan  8 23:43:10 DEBUG[26955]: Putting channel Zap/1-1 in 64/64 formats
Jan  8 23:43:10 DEBUG[26955]: New owner for channel 1 is Zap/1-1
Jan  8 23:43:10 DEBUG[26955]: Updated conferencing on 1, with 0 conference 
users
Jan  8 23:43:10 DEBUG[26955]: Updated conferencing on 1, with 0 conference 
users
Jan  8 23:43:10 DEBUG[26955]: Released clone lock on 
'Local/101 at default-4115,1<ZOMBIE>'
Jan  8 23:43:10 DEBUG[26955]: Done Masquerading Zap/1-1 (6)
Jan  8 23:43:10 DEBUG[26955]: Scheduling timer at 160 sample intervals
Jan  8 23:43:10 DEBUG[26955]: Dropping duplicate answer!
Jan  8 23:43:10 DEBUG[26957]: Exiting with DIALSTATUS=ANSWER.

*** somewhere around here is where the message comes up in the CLI ***

Jan  8 23:43:14 DEBUG[26955]: Exception on 20, channel 1
Jan  8 23:43:14 DEBUG[26955]: Got event On hook(1) on channel 1 (index 0)
Jan  8 23:43:14 DEBUG[26955]: disabled echo cancellation on channel 1
Jan  8 23:43:14 DEBUG[26955]: Scheduling timer at 0 sample intervals
Jan  8 23:43:14 DEBUG[26955]: Hangup: channel: 1 index = 0, normal = 20, 
callwait = -1, thirdcall = -1
Jan  8 23:43:14 DEBUG[26955]: disabled echo cancellation on channel 1
Jan  8 23:43:14 DEBUG[26955]: Set option TDD MODE, value: OFF(0) on Zap/1-1
Jan  8 23:43:14 DEBUG[26955]: Updated conferencing on 1, with 0 conference 
users

The call sounds fine and works as expected, but I'm just wondering what's 
causing that error.  I'm looking at file.c and it looks like I'm getting a 
control frame but the subclass is uninitialized (or rather it's initialized 
to -1 and never filled in).

Can anyone assist in debugging this?  I'm guessing it's just the way the 
callfile is dropping out.  Adding a priority 2 Hangup() doesn't help (and 
indeed Dial() wouldn't have finished yet).

-A.