[asterisk-dev] Diagnosing signaling problems

[Pavel Troller]

Hi!
  I've been working on some signaling-related problems (missing or extra
answer signal etc.) and I must admit that I still don't understand  some
details of Asterisk signaling. 
  For example, I don't understand the following part of log, created by
simultaneously enabling IAX2 debug on a peer and the FRAME_TRACE()
function blacklisted to view the control frames only:


Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 013 Type: CONTROL Subclass: PROCDNG
   Timestamp: 03921ms  SCall: 00838  DCall: 11410 [194.213.62.218:4569]
Tx-Frame Retry[-01] -- OSeqno: 013 ISeqno: 006 Type: IAX     Subclass: ACK
   Timestamp: 03921ms  SCall: 11410  DCall: 00838 [194.213.62.218:4569]
--> Write on Channel SCCP/2112-000000c8
FrameType: CONTROL
SubClass: PROCEEDING
Bytes: 0
Src: NOT PRESENT

Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 013 Type: CONTROL Subclass: ANSWER
   Timestamp: 04459ms  SCall: 00838  DCall: 11410 [194.213.62.218:4569]
Tx-Frame Retry[-01] -- OSeqno: 013 ISeqno: 007 Type: IAX     Subclass: ACK
   Timestamp: 04459ms  SCall: 11410  DCall: 00838 [194.213.62.218:4569]
--> Write on Channel SCCP/2112-000000c8
FrameType: CONTROL
SubClass: -1
Bytes: 0
Src: NOT PRESENT

--> Write on Channel SCCP/2112-000000c8
FrameType: CONTROL
SubClass: SRCUPDATE
Bytes: 0
Src: NOT PRESENT

Rx-Frame Retry[ No] -- OSeqno: 007 ISeqno: 013 Type: CONTROL Subclass: (255?)
   Timestamp: 04462ms  SCall: 00838  DCall: 11410 [194.213.62.218:4569]
Tx-Frame Retry[-01] -- OSeqno: 013 ISeqno: 008 Type: IAX     Subclass: ACK
   Timestamp: 04462ms  SCall: 11410  DCall: 00838 [194.213.62.218:4569]
--> Write on Channel SCCP/2112-000000c8
FrameType: CONTROL
SubClass: SRCUPDATE
Bytes: 0
Src: NOT PRESENT

--> Write on Channel SCCP/2112-000000c8
FrameType: CONTROL
SubClass: -1
Bytes: 0
Src: NOT PRESENT

--> Write on Channel SCCP/2112-000000c8
FrameType: CONTROL
SubClass: SRCUPDATE
Bytes: 0
Src: NOT PRESENT


  The points I don't understand are:
  1) What happend to the ANSWER frame coming from IAX2 ? Why I can't see it
in the trace and I can see a "mystical" subclass -1 message instead ? 
Is it a bug of FRAME_TRACE() ? The calling device indicated Answer condition
properly.

  2) Why there is another "subclass -1" message sent a few milliseconds later
from the peer, which is also forwarded as a local control frame ?

  3) What do these "subclass -1" messages mean ? I've been looking to the
sources, the value "-1" is regularly checked on many places, so it seems to
be a regular control frame - so why the negative number ? Why it doesn't have
a symbolic name ?

  4) Why so many SRCUPDATE control frames is being generated, when it's
a single peer-2-peer call (BTW, it's a call to the remote MilliWatt()
service).

  I tried to learn from the network resouces, but I didn't find anything
related to my question closely enough. I will be very thankful for a short
explanation.

  With regards,
  Pavel Troller