[Iaxclient-devel] Issues with libiax/iaxclient under Windows 32

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 422-6466

Iaxclient-dev members, please pardon the recap.  Everybody please pardon
the cross-post.  I just wanted as many knowledgeable eyes on this as I
could get.

For the past several months I have been working with the iaxclient
library in an attempt to make a powerful, multi-function IAX/IAX2 client
that works on the Windows platform.  The one major stumbling block that
I run into is this: the client seems to stop responding to inbound call
requests (i.e. it don't ring when it should ring) after some period of
time or event.

After tracking the issue as best I can (I am no c-language genius and
have little experience with gcc/gdb) I have found out where the error is
occurring.  It seems that the sequence tracker in the
iax_header_to_event function in the iax.c file of libiax2 is somehow
getting messages out-of-sequence.  Below is a make-shift trace that
shows a registration sequence and several calls that are handled by the
client.  The trace logs both sent and received command messages.

I don't understand the messaging sequence enough to figure out why this
is occurring.  Steve Underwood apparently fixed this issue (or the issue
was never as bad) when running under Linux.  It appears to be specific
to the IAX2 protocol (IAX1 does not seem to loose messages) running on
Win32.  Oddly, it seems to be much more prevalent with connections from
my local Asterisk server than from IAXtel (which I have used for
testing).

Below is the trace with all of the commands sent/received.  Attached is
the version of the iax.c file that I hacked.  Please forgive my ugly C
coding.  It was a quick/dirty operation.  I would greatly appreciate any
insight as to how the messaging sequence works, and what could be
causing it to get out of wack.  Additional info can be had from the
iaxclient-dev list archive (previous posts on this topic).

Please feel free to contact me directly.  My phone number is [IAXTel]
1-700-613-9004, [PSTN} 1-826-822-1807.

Thanks!

Steve

[Client Starts And Registers]
12:13:10 (59914093) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:13:10 (59914109) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 0, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_REGAUTH
12:13:10 (59914109) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:13:10 (59914125) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_REGACK
12:13:10 (59914125) LOG_MESSAGE-> COMMAND SENT: Sequence: 2, Type: 6,
Subclass: IAX_COMMAND_ACK

[Successful Inbound Call (SIP UA to IAX Client)]
12:13:18 (59922625) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 0, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_NEW
12:13:18 (59922640) LOG_MESSAGE-> COMMAND SENT: Sequence: 0, Type: 6,
Subclass: IAX_COMMAND_ACK
12:13:18 (59922656) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_ACCEPT
12:13:18 (59922656) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 4,
Subclass: IAX_COMMAND_PONG
12:13:18 (59922671) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_ACK
12:13:18 (59922671) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_ACK
12:13:20 (59924453) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 4,
Subclass: IAX_COMMAND_ACK
12:13:20 (59924500) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_ACK
12:13:20 (59924578) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 2, O.
Sequence: 2, Type: 6, Subclass: IAX_COMMAND_ACK
12:13:24 (59928062) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 2, O.
Sequence: 2, Type: 6, Subclass: IAX_COMMAND_HANGUP
12:13:24 (59928078) LOG_MESSAGE-> COMMAND SENT: Sequence: 4, Type: 6,
Subclass: IAX_COMMAND_ACK

[Successful Inbound Call (SIP UA to IAX Client)]
12:13:55 (59959437) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 0, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_NEW
12:13:55 (59959437) LOG_MESSAGE-> COMMAND SENT: Sequence: 0, Type: 6,
Subclass: IAX_COMMAND_ACK
12:13:55 (59959453) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_ACCEPT
12:13:55 (59959453) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 4,
Subclass: IAX_COMMAND_PONG
12:13:55 (59959468) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_ACK
12:13:55 (59959468) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_ACK
12:13:57 (59961578) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 4,
Subclass: IAX_COMMAND_ACK
12:13:57 (59961625) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_ACK
12:13:57 (59961625) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 2, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_ACK
12:13:57 (59961640) LOG_MESSAGE-> COMMAND SENT: Sequence: 4, Type: 6,
Subclass: IAX_COMMAND_ACK
12:14:00 (59964109) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_HANGUP
12:14:00 (59964343) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 2, O.
Sequence: 2, Type: 6, Subclass: IAX_COMMAND_ACK
12:14:00 (59964343) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 2, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_INVAL

[Successful Outbound Call (IAX Client to SIP UA)]
12:14:26 (59990750) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_NEW
12:14:26 (59990796) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 0, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_AUTHREQ
12:14:26 (59990812) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_AUTHREP
12:14:26 (59990812) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_ACK
12:14:27 (59990828) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_ACCEPT
12:14:27 (59990843) LOG_MESSAGE-> COMMAND SENT: Sequence: 3, Type: 6,
Subclass: IAX_COMMAND_ACK
12:14:27 (59990843) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 2, O.
Sequence: 2, Type: 4, Subclass: IAX_COMMAND_ACK
12:14:29 (59992828) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 2, Type: 4, Subclass: IAX_COMMAND_ACK
12:14:29 (59992843) LOG_MESSAGE-> Packet arrived out of order (expecting
4, got 2) (frametype = 4, subclass = 4)
12:14:29 (59992843) LOG_MESSAGE-> Sending Ack Anyway!
12:14:29 (59992859) LOG_MESSAGE-> COMMAND SENT: Sequence: 3, Type: 6,
Subclass: IAX_COMMAND_ACK
12:14:29 (59992875) LOG_MESSAGE-> Returning Null! Exiting In ReSend
Section!
12:14:35 (59999265) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 4, Type: 6, Subclass: IAX_COMMAND_HANGUP
12:14:35 (59999281) LOG_MESSAGE-> COMMAND SENT: Sequence: 3, Type: 6,
Subclass: IAX_COMMAND_ACK

[Re-Registration]
12:17:10 (60154156) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:17:10 (60154171) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 0, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_REGAUTH
12:17:10 (60154187) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:17:10 (60154203) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_REGACK
12:17:10 (60154218) LOG_MESSAGE-> COMMAND SENT: Sequence: 2, Type: 6,
Subclass: IAX_COMMAND_ACK

[FAILED CALL! Inbound Call (SIP UA to IAX Client)]
12:18:07 (60211578) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 2, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_NEW
12:18:07 (60211593) LOG_MESSAGE-> Packet arrived out of order (expecting
2, got 0) (frametype = 6, subclass = 1)
12:18:07 (60211609) LOG_MESSAGE-> Sending Ack Anyway!
12:18:07 (60211625) LOG_MESSAGE-> COMMAND SENT: Sequence: 0, Type: 6,
Subclass: IAX_COMMAND_ACK
12:18:07 (60211640) LOG_MESSAGE-> Returning Null! Exiting In ReSend
Section!
12:18:09 (60213593) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 2, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_NEW
12:18:09 (60213609) LOG_MESSAGE-> Packet arrived out of order (expecting
2, got 0) (frametype = 6, subclass = 1)
12:18:09 (60213625) LOG_MESSAGE-> Sending Ack Anyway!
12:18:09 (60213625) LOG_MESSAGE-> COMMAND SENT: Sequence: 0, Type: 6,
Subclass: IAX_COMMAND_ACK
12:18:09 (60213640) LOG_MESSAGE-> Returning Null! Exiting In ReSend
Section!
12:18:10 (60214171) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:18:10 (60214187) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 0, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_REGAUTH
12:18:10 (60214203) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:18:10 (60214218) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_REGACK
12:18:10 (60214218) LOG_MESSAGE-> COMMAND SENT: Sequence: 2, Type: 6,
Subclass: IAX_COMMAND_ACK
12:18:17 (60221593) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 2, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_LAGRQ
12:18:17 (60221609) LOG_MESSAGE-> Packet arrived out of order (expecting
2, got 1) (frametype = 6, subclass = 11)
12:18:17 (60221609) LOG_MESSAGE-> Sending Ack Anyway!
12:18:17 (60221625) LOG_MESSAGE-> COMMAND SENT: Sequence: 0, Type: 6,
Subclass: IAX_COMMAND_ACK
12:18:17 (60221640) LOG_MESSAGE-> Returning Null! Exiting In ReSend
Section!
12:18:27 (60231593) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 2, O.
Sequence: 2, Type: 6, Subclass: IAX_COMMAND_PING
12:18:27 (60231609) LOG_MESSAGE-> COMMAND SENT: Sequence: 0, Type: 6,
Subclass: IAX_COMMAND_ACK
12:18:27 (60231625) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_PONG
12:18:27 (60231625) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 3, O.
Sequence: 3, Type: 6, Subclass: IAX_COMMAND_LAGRQ
12:18:27 (60231640) LOG_MESSAGE-> COMMAND SENT: Sequence: 0, Type: 6,
Subclass: IAX_COMMAND_ACK
12:18:27 (60231656) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_LAGRP
12:18:27 (60231671) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_VNAK
12:18:27 (60231671) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_VNAK
12:18:27 (60231703) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_VNAK
12:18:27 (60231734) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_VNAK
12:18:28 (60231937) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_VNAK
12:18:28 (60231984) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_VNAK
12:18:29 (60232906) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_VNAK
12:18:29 (60232953) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_VNAK
12:18:32 (60236750) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_VNAK
12:18:32 (60236796) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_VNAK
12:18:37 (60241578) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 4, O.
Sequence: 4, Type: 6, Subclass: IAX_COMMAND_HANGUP
12:18:37 (60241593) LOG_MESSAGE-> COMMAND SENT: Sequence: 0, Type: 6,
Subclass: IAX_COMMAND_ACK

[Re-Registration]
12:19:10 (60274187) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:19:10 (60274203) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 0, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_REGAUTH
12:19:10 (60274218) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:19:10 (60274234) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_REGACK
12:19:10 (60274234) LOG_MESSAGE-> COMMAND SENT: Sequence: 2, Type: 6,
Subclass: IAX_COMMAND_ACK

[Re-Registration]
12:20:10 (60334203) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:20:10 (60334218) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 0, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_REGAUTH
12:20:10 (60334218) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:20:10 (60334250) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_REGACK
12:20:10 (60334250) LOG_MESSAGE-> COMMAND SENT: Sequence: 2, Type: 6,
Subclass: IAX_COMMAND_ACK

[Re-Registration]
12:21:10 (60394218) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:21:10 (60394234) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 0, O.
Sequence: 0, Type: 6, Subclass: IAX_COMMAND_REGAUTH
12:21:10 (60394234) LOG_MESSAGE-> COMMAND SENT: Sequence: -1, Type: 6,
Subclass: IAX_COMMAND_REGREQ
12:21:10 (60394265) LOG_MESSAGE-> COMMAND RECEIVED: I. Sequence: 1, O.
Sequence: 1, Type: 6, Subclass: IAX_COMMAND_REGACK
12:21:10 (60394265) LOG_MESSAGE-> COMMAND SENT: Sequence: 2, Type: 6,
Subclass: IAX_COMMAND_ACK

[END OF SESSION - CLIENT CLOSED]