IAX: "Raw hangup" messages

Hi all,

I’m running Asterisk 1.2.18, and when I connect a IAXCLIENT-based softphone to it, my log gets flooded with the following message:

chan_iax2.c: Raw Hangup 10.0.100.22:4569, src=4, dst=29566

The phone connects, and I am able to make calls with it, but it tends to ruin my logs… Here is a debug dump:

==================

Aug 1 14:08:59 VERBOSE[2881] logger.c: Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: REGREQ
Aug 1 14:08:59 VERBOSE[2881] logger.c: Timestamp: 00003ms SCall: 29565 DCall: 00000 [10.0.100.22:4569]
Aug 1 14:08:59 VERBOSE[2881] logger.c: USERNAME : 501
Aug 1 14:08:59 VERBOSE[2881] logger.c: REFRESH : 300
Aug 1 14:08:59 VERBOSE[2881] logger.c:
Aug 1 14:08:59 VERBOSE[2881] logger.c: Tx-Frame Retry[000] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: REGAUTH
Aug 1 14:08:59 VERBOSE[2881] logger.c: Timestamp: 00013ms SCall: 00001 DCall: 29565 [10.0.100.22:4569]
Aug 1 14:08:59 VERBOSE[2881] logger.c: AUTHMETHODS : 3
Aug 1 14:08:59 VERBOSE[2881] logger.c: CHALLENGE : 784818859
Aug 1 14:08:59 VERBOSE[2881] logger.c: USERNAME : 501
Aug 1 14:08:59 VERBOSE[2881] logger.c:
Aug 1 14:08:59 VERBOSE[2881] logger.c: Rx-Frame Retry[Yes] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: REGREQ
Aug 1 14:08:59 VERBOSE[2881] logger.c: Timestamp: 00003ms SCall: 29565 DCall: 00000 [10.0.100.22:4569]
Aug 1 14:08:59 VERBOSE[2881] logger.c: USERNAME : 501
Aug 1 14:08:59 VERBOSE[2881] logger.c: REFRESH : 300
Aug 1 14:08:59 VERBOSE[2881] logger.c:
Aug 1 14:08:59 VERBOSE[2881] logger.c: Tx-Frame Retry[-01] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK
Aug 1 14:08:59 VERBOSE[2881] logger.c: Timestamp: 00003ms SCall: 00001 DCall: 29565 [10.0.100.22:4569]
Aug 1 14:08:59 VERBOSE[2881] logger.c: Rx-Frame Retry[ No] – OSeqno: 001 ISeqno: 001 Type: IAX Subclass: REGREQ
Aug 1 14:08:59 VERBOSE[2881] logger.c: Timestamp: 00063ms SCall: 29565 DCall: 00001 [10.0.100.22:4569]
Aug 1 14:08:59 VERBOSE[2881] logger.c: USERNAME : 501
Aug 1 14:08:59 VERBOSE[2881] logger.c: REFRESH : 300
Aug 1 14:08:59 VERBOSE[2881] logger.c: MD5 RESULT : 06df7f5296ee4a4f5e1593014b492421
Aug 1 14:08:59 VERBOSE[2881] logger.c:
Aug 1 14:08:59 NOTICE[2881] chan_iax2.c: Restricting registration for peer ‘501’ to 60 seconds (requested 300)
Aug 1 14:08:59 VERBOSE[2881] logger.c: Tx-Frame Retry[000] – OSeqno: 001 ISeqno: 002 Type: IAX Subclass: REGACK
Aug 1 14:08:59 VERBOSE[2881] logger.c: Timestamp: 00063ms SCall: 00001 DCall: 29565 [10.0.100.22:4569]
Aug 1 14:08:59 VERBOSE[2881] logger.c: USERNAME : 501
Aug 1 14:08:59 VERBOSE[2881] logger.c: DATE TIME : 2007-08-01 14:08:58
Aug 1 14:08:59 VERBOSE[2881] logger.c: REFRESH : 60
Aug 1 14:08:59 VERBOSE[2881] logger.c: APPARENT ADDRES : IPV4 10.0.100.22:4569
Aug 1 14:08:59 VERBOSE[2881] logger.c: MESSAGE COUNT : 0
Aug 1 14:08:59 VERBOSE[2881] logger.c: CALLING NUMBER : 501
Aug 1 14:08:59 VERBOSE[2881] logger.c: CALLING NAME : device
Aug 1 14:08:59 VERBOSE[2881] logger.c:
Aug 1 14:08:59 VERBOSE[2881] logger.c: Rx-Frame Retry[ No] – OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK
Aug 1 14:08:59 VERBOSE[2881] logger.c: Timestamp: 00063ms SCall: 29565 DCall: 00001 [10.0.100.22:4569]
Aug 1 14:09:07 VERBOSE[2881] logger.c: Tx-Frame Retry[000] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE
Aug 1 14:09:07 VERBOSE[2881] logger.c: Timestamp: 00019ms SCall: 00004 DCall: 00000 [10.0.100.22:4569]
Aug 1 14:09:07 VERBOSE[2881] logger.c: Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK
Aug 1 14:09:07 VERBOSE[2881] logger.c: Timestamp: 00019ms SCall: 29566 DCall: 00004 [10.0.100.22:4569]
Aug 1 14:09:07 VERBOSE[2881] logger.c: Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG
Aug 1 14:09:07 VERBOSE[2881] logger.c: Timestamp: 00019ms SCall: 29566 DCall: 00004 [10.0.100.22:4569]
Aug 1 14:09:07 VERBOSE[2881] logger.c: RR_JITTER : 0
Aug 1 14:09:07 VERBOSE[2881] logger.c: RR_LOSS : 0
Aug 1 14:09:07 VERBOSE[2881] logger.c: RR_PKTS : 1
Aug 1 14:09:07 VERBOSE[2881] logger.c: RR_DELAY : 40
Aug 1 14:09:07 VERBOSE[2881] logger.c: RR_DROPPED : 0
Aug 1 14:09:07 VERBOSE[2881] logger.c: RR_OUTOFORDER : 0
Aug 1 14:09:07 VERBOSE[2881] logger.c:
Aug 1 14:09:07 VERBOSE[2881] logger.c: Tx-Frame Retry[-01] – OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK
Aug 1 14:09:07 VERBOSE[2881] logger.c: Timestamp: 00019ms SCall: 00004 DCall: 29566 [10.0.100.22:4569]
Aug 1 14:09:07 DEBUG[2881] chan_iax2.c: Peer lastms 7, historicms 7, maxms 2000
Aug 1 14:09:08 DEBUG[2882] chan_sip.c: Stopping retransmission on ‘6678fbf766155efc157cac7c600e9b0c@10.0.100.115’ of Request 102: Match Found
Aug 1 14:09:09 VERBOSE[2881] logger.c: Rx-Frame Retry[ No] – OSeqno: 001 ISeqno: 001 Type: IAX Subclass: PING
Aug 1 14:09:09 VERBOSE[2881] logger.c: Timestamp: 02000ms SCall: 29566 DCall: 00004 [10.0.100.22:4569]
Aug 1 14:09:09 VERBOSE[2881] logger.c: Tx-Frame Retry[ No] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: INVAL
Aug 1 14:09:09 VERBOSE[2881] logger.c: Timestamp: 00000ms SCall: 00004 DCall: 29566 [10.0.100.22:4569]
Aug 1 14:09:09 DEBUG[2881] chan_iax2.c: Raw Hangup 10.0.100.22:4569, src=4, dst=29566
Aug 1 14:09:09 VERBOSE[2881] logger.c: Rx-Frame Retry[Yes] – OSeqno: 001 ISeqno: 001 Type: IAX Subclass: PING
Aug 1 14:09:09 VERBOSE[2881] logger.c: Timestamp: 02000ms SCall: 29566 DCall: 00004 [10.0.100.22:4569]
Aug 1 14:09:09 VERBOSE[2881] logger.c: Tx-Frame Retry[ No] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: INVAL
Aug 1 14:09:09 VERBOSE[2881] logger.c: Timestamp: 00000ms SCall: 00004 DCall: 29566 [10.0.100.22:4569]
Aug 1 14:09:09 DEBUG[2881] chan_iax2.c: Raw Hangup 10.0.100.22:4569, src=4, dst=29566
Aug 1 14:09:10 VERBOSE[2881] logger.c: Rx-Frame Retry[Yes] – OSeqno: 001 ISeqno: 001 Type: IAX Subclass: PING
Aug 1 14:09:10 VERBOSE[2881] logger.c: Timestamp: 02000ms SCall: 29566 DCall: 00004 [10.0.100.22:4569]
Aug 1 14:09:10 VERBOSE[2881] logger.c: Tx-Frame Retry[ No] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: INVAL
Aug 1 14:09:10 VERBOSE[2881] logger.c: Timestamp: 00000ms SCall: 00004 DCall: 29566 [10.0.100.22:4569]
Aug 1 14:09:10 DEBUG[2881] chan_iax2.c: Raw Hangup 10.0.100.22:4569, src=4, dst=29566

The combination of PING and INVAL keeps repeating after this: I suspect this is causing the problem, but I don’t understand what is going wrong (and more importantly, how I can stop this from happening)

TIA!

Harry

Anybody got an idea ?