Just set up TrixBox is working great with one exception. Using LoudHush OSX IAX2 client if I dial another extension and that extension is not online I do not get the voicemail as I would when using a SIP client instead the call is dropped immediately.
Otherwise all is working GREAT!
Oh how I love open source 
Thanks in advance
cli trace, not debug trace, and turn off any iax2 debug when you do it. There’s too much info (and also some lack of info) in the log that makes it difficult to sift through on first pass. Also - what version of asterisk are you running.
Found out a bit more and got the logging data…
If I have followme set up for the extension I am trying to dial I get forwarded as appropriate… however if I just have voicemail setup but no follow me I get the hangup…
Here is the log data…
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is '202’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Noop
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] pbx.c: Not taking any branch
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: GotoIf
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '1’
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '-1’
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is '64’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '1’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: GotoIf
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is '“Bob Jones” <202>'
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: NoOp
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Macro
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] db.c: Unable to find key ‘203’ in family 'CFU’
May 10 13:09:49 DEBUG[29074] func_db.c: DB: CFU/203 not found in database.
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is ''
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '1’
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '1’
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is '15’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is '0’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: GotoIf
May 10 13:09:49 VERBOSE[25782] logger.c: Rx-Frame Retry[ No] – OSeqno: 002 ISeqno: 002 Type: IAX Subclass: ACK
May 10 13:09:49 VERBOSE[25782] logger.c: Timestamp: 00038ms SCall: 04375 DCall: 00003 [192.168.0.238:4569]
May 10 13:09:49 VERBOSE[29074] logger.c: recordingcheck|20070510-130949|1178816988.48: Inbound recording not enabled
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: DeadAGI
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Noop
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Macro
May 10 13:09:49 VERBOSE[25782] logger.c: Rx-Frame Retry[ No] – OSeqno: 002 ISeqno: 002 Type: VOICE Subclass: 138
May 10 13:09:49 VERBOSE[25782] logger.c: Timestamp: 00180ms SCall: 04375 DCall: 00003 [192.168.0.238:4569]
May 10 13:09:49 DEBUG[25782] chan_iax2.c: Ooh, voice format changed to 1024
May 10 13:09:49 VERBOSE[25782] logger.c: Tx-Frame Retry[-01] – OSeqno: 002 ISeqno: 003 Type: IAX Subclass: ACK
May 10 13:09:49 VERBOSE[25782] logger.c: Timestamp: 00180ms SCall: 00003 DCall: 04375 [192.168.0.238:4569]
May 10 13:09:49 VERBOSE[29074] logger.c: dialparties.agi: Starting New Dialparties.agi
May 10 13:09:49 VERBOSE[29074] logger.c: dialparties.agi: priority is 1
May 10 13:09:49 VERBOSE[29074] logger.c: dialparties.agi: Caller ID name is ‘Bob Jones’ number is '202’
May 10 13:09:49 VERBOSE[29074] logger.c: dialparties.agi: Methodology of ring is 'none’
May 10 13:09:49 DEBUG[29074] db.c: Unable to find key ‘203’ in family 'CF’
May 10 13:09:49 DEBUG[29074] db.c: Unable to find key ‘203’ in family 'DND’
May 10 13:09:49 DEBUG[29074] db.c: Unable to find key ‘203’ in family 'CFB’
May 10 13:09:49 DEBUG[29074] db.c: Unable to find key ‘203’ in family 'CFU’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: DeadAGI
May 10 13:09:49 NOTICE[29074] app_dial.c: Unable to create channel of type ‘IAX2’ (cause 3 - No route to destination)
May 10 13:09:49 DEBUG[29074] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Dial
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Macro
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: GosubIf
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: NoOp
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] pbx.c: Not taking any branch
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: GotoIf
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: NoOp
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is 'Bob Jones’
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is '202’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Noop
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] pbx.c: Not taking any branch
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: GotoIf
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '1’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: GotoIf
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: NoOp
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is '202’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is 'Bob Jones’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] pbx.c: Not taking any branch
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: GotoIf
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is '202’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Noop
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '1’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: GotoIf
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is '“Bob Jones” <202>'
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: NoOp
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Macro
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is '0’
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is '‘
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 WARNING[29074] func_db.c: DB requires an argument, DB(/)
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is ‘‘
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is ‘1’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: GotoIf
May 10 13:09:49 DEBUG[29074] pbx.c: Function result is ‘default’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Set
May 10 13:09:49 DEBUG[29074] pbx.c: Expression result is ‘0’
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: GotoIf
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: NoOp
May 10 13:09:49 DEBUG[29074] app_macro.c: Executed application: Macro
May 10 13:09:49 DEBUG[29074] app_voicemail.c: /var/spool/asterisk/voicemail/default/203/unavail doesn’t exist, doing what we can
May 10 13:09:49 DEBUG[29074] channel.c: Scheduling timer at 160 sample intervals
May 10 13:09:49 VERBOSE[25782] logger.c: Tx-Frame Retry[000] – OSeqno: 002 ISeqno: 003 Type: CONTROL Subclass: ANSWER
May 10 13:09:49 VERBOSE[25782] logger.c: Timestamp: 00239ms SCall: 00003 DCall: 04375 [192.168.0.238:4569]
May 10 13:09:49 VERBOSE[25782] logger.c: Rx-Frame Retry[ No] – OSeqno: 003 ISeqno: 003 Type: IAX Subclass: ACK
May 10 13:09:49 VERBOSE[25782] logger.c: Timestamp: 00239ms SCall: 04375 DCall: 00003 [192.168.0.238:4569]
May 10 13:09:49 DEBUG[29074] chan_iax2.c: predicted timestamp skew (260) > max (160), using real ts instead.
May 10 13:09:49 VERBOSE[25782] logger.c: Tx-Frame Retry[000] – OSeqno: 003 ISeqno: 003 Type: VOICE Subclass: 138
May 10 13:09:49 VERBOSE[25782] logger.c: Timestamp: 00270ms SCall: 00003 DCall: 04375 [192.168.0.238:4569]
May 10 13:09:49 VERBOSE[25782] logger.c: Rx-Frame Retry[ No] – OSeqno: 003 ISeqno: 004 Type: IAX Subclass: ACK
May 10 13:09:49 VERBOSE[25782] logger.c: Timestamp: 00270ms SCall: 04375 DCall: 00003 [192.168.0.238:4569]
May 10 13:09:49 NOTICE[29074] chan_iax2.c: I should never be called! Hanging up.
May 10 13:09:49 DEBUG[29074] app_voicemail.c: Hang up during prefile playback
May 10 13:09:49 DEBUG[29074] channel.c: Scheduling timer at 0 sample intervals
May 10 13:09:49 DEBUG[29074] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
May 10 13:09:49 DEBUG[29074] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES (‘2007-05-10 13:09:48’,’“Bob Jones” <202>’,‘202’,‘203’,‘from-internal’, ‘IAX2/202-3’,’’,‘VoiceMail’,‘203@default|u’,1,0,‘ANSWERED’,3,’’,‘1178816988.48’)
May 10 13:09:49 DEBUG[29074] chan_iax2.c: We’re hanging up IAX2/202-3 now…
May 10 13:09:49 VERBOSE[25782] logger.c: Tx-Frame Retry[000] – OSeqno: 004 ISeqno: 003 Type: IAX Subclass: HANGUP
May 10 13:09:49 VERBOSE[25782] logger.c: Timestamp: 00303ms SCall: 00003 DCall: 04375 [192.168.0.238:4569]
May 10 13:09:49 VERBOSE[25782] logger.c: CAUSE CODE : 3
May 10 13:09:49 VERBOSE[25782] logger.c:
May 10 13:09:49 VERBOSE[25782] logger.c: Rx-Frame Retry[ No] – OSeqno: 003 ISeqno: 005 Type: IAX Subclass: ACK
May 10 13:09:49 VERBOSE[25782] logger.c: Timestamp: 00303ms SCall: 04375 DCall: 00003 [192.168.0.238:4569]
May 10 13:09:51 VERBOSE[25782] logger.c: Tx-Frame Retry[000] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00001ms SCall: 00004 DCall: 00000 [192.168.0.238:4569]
May 10 13:09:51 VERBOSE[25782] logger.c: Tx-Frame Retry[000] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00009ms SCall: 00008 DCall: 00000 [192.168.0.249:4569]
May 10 13:09:51 VERBOSE[25782] logger.c: Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00001ms SCall: 04376 DCall: 00004 [192.168.0.238:4569]
May 10 13:09:51 VERBOSE[25782] logger.c: Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00001ms SCall: 04376 DCall: 00004 [192.168.0.238:4569]
May 10 13:09:51 VERBOSE[25782] logger.c: RR_JITTER : 0
May 10 13:09:51 VERBOSE[25782] logger.c: RR_LOSS : 0
May 10 13:09:51 VERBOSE[25782] logger.c: RR_PKTS : 1
May 10 13:09:51 VERBOSE[25782] logger.c: RR_DELAY : 40
May 10 13:09:51 VERBOSE[25782] logger.c: RR_DROPPED : 0
May 10 13:09:51 VERBOSE[25782] logger.c: RR_OUTOFORDER : 0
May 10 13:09:51 VERBOSE[25782] logger.c:
May 10 13:09:51 VERBOSE[25782] logger.c: Tx-Frame Retry[-01] – OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00001ms SCall: 00004 DCall: 04376 [192.168.0.238:4569]
May 10 13:09:51 DEBUG[25782] chan_iax2.c: Peer lastms 9, historicms 9, maxms 2000
May 10 13:09:51 VERBOSE[25782] logger.c: Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00009ms SCall: 16352 DCall: 00008 [192.168.0.249:4569]
May 10 13:09:51 VERBOSE[25782] logger.c: Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00009ms SCall: 16352 DCall: 00008 [192.168.0.249:4569]
May 10 13:09:51 VERBOSE[25782] logger.c: RR_JITTER : 0
May 10 13:09:51 VERBOSE[25782] logger.c: RR_LOSS : 0
May 10 13:09:51 VERBOSE[25782] logger.c: RR_PKTS : 1
May 10 13:09:51 VERBOSE[25782] logger.c: RR_DELAY : 40
May 10 13:09:51 VERBOSE[25782] logger.c: RR_DROPPED : 0
May 10 13:09:51 VERBOSE[25782] logger.c: RR_OUTOFORDER : 0
May 10 13:09:51 VERBOSE[25782] logger.c:
May 10 13:09:51 VERBOSE[25782] logger.c: Tx-Frame Retry[-01] – OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00009ms SCall: 00008 DCall: 16352 [192.168.0.249:4569]
May 10 13:09:51 DEBUG[25782] chan_iax2.c: Peer lastms 4, historicms 4, maxms 2000
May 10 13:09:51 VERBOSE[25782] logger.c: Tx-Frame Retry[000] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: POKE
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00013ms SCall: 00010 DCall: 00000 [68.35.215.126:4569]
May 10 13:09:51 DEBUG[25780] chan_sip.c: Stopping retransmission on ‘321f7de36[email protected]’ of Request 102: Match Found
May 10 13:09:51 VERBOSE[25782] logger.c: Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00013ms SCall: 00863 DCall: 00010 [68.35.215.126:4569]
May 10 13:09:51 VERBOSE[25782] logger.c: Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: PONG
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00013ms SCall: 00863 DCall: 00010 [68.35.215.126:4569]
May 10 13:09:51 VERBOSE[25782] logger.c: RR_JITTER : 0
May 10 13:09:51 VERBOSE[25782] logger.c: RR_LOSS : 0
May 10 13:09:51 VERBOSE[25782] logger.c: RR_PKTS : 1
May 10 13:09:51 VERBOSE[25782] logger.c: RR_DELAY : 40
May 10 13:09:51 VERBOSE[25782] logger.c: RR_DROPPED : 0
May 10 13:09:51 VERBOSE[25782] logger.c: RR_OUTOFORDER : 0
May 10 13:09:51 VERBOSE[25782] logger.c:
May 10 13:09:51 VERBOSE[25782] logger.c: Tx-Frame Retry[-01] – OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK
May 10 13:09:51 VERBOSE[25782] logger.c: Timestamp: 00013ms SCall: 00010 DCall: 00863 [68.35.215.126:4569]
May 10 13:09:51 DEBUG[25782] chan_iax2.c: Peer lastms 178, historicms 178, maxms 2000
you’ll need to post a cli trace to see what is going on - or, got to #freepbx in the irc and find someone who can help - they’s also want a trace pastebin-ed.