Cannot hear any system or user recordings over phone

Problem: I cannot hear any system recordings (voicemail, starting call waiting, etc) or recordings I make on *77 and attempt to playback on *99.

I’ve setup two phones and can make calls between them without problems; I can even make calls to extensions on our other asterisk server using IAX2 but I cannot seem to hear any recordings.

I do however hear a small click on the line when I would expect recordings to play.

Any help or at least pointing me in the right direction would be much appretiated. I setup and still have running an old Asterisk@Home setup but even the problems I had on that never included not being able to hear the system recordings.

Software
TrixBox 2.2.1 (vanilla)

Hardware
TDM410
GXP2000

LogFile:

Jun 15 15:47:27 DEBUG[6241] chan_sip.c: Setting NAT on RTP to 524288
Jun 15 15:47:27 DEBUG[6241] chan_sip.c: Checking SIP call limits for device 4000
Jun 15 15:47:27 DEBUG[6241] chan_sip.c: build_route: Contact hop:
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is 'device’
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is '4000’
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Noop
Jun 15 15:47:27 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:27 DEBUG[2908] pbx.c: Not taking any branch
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:27 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:27 DEBUG[2908] pbx.c: Not taking any branch
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is '4000’
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: NoOp
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is '4000’
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is 'Test Extension 1’
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:27 DEBUG[2908] pbx.c: Not taking any branch
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is '4000’
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Noop
Jun 15 15:47:27 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:27 DEBUG[2908] pbx.c: Not taking any branch
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:27 DEBUG[2908] pbx.c: Expression result is '1’
Jun 15 15:47:27 DEBUG[2908] pbx.c: Expression result is '-1’
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is '64’
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] pbx.c: Expression result is '1’
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is '“Test Extension 1” <4000>'
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: NoOp
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Macro
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] db.c: Unable to find key ‘4001’ in family 'CFU’
Jun 15 15:47:27 DEBUG[2908] func_db.c: DB: CFU/4001 not found in database.
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is ''
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] db.c: Unable to find key ‘4001’ in family 'CFB’
Jun 15 15:47:27 DEBUG[2908] func_db.c: DB: CFB/4001 not found in database.
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is ''
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] pbx.c: Expression result is '1’
Jun 15 15:47:27 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:27 DEBUG[2908] pbx.c: Expression result is '1’
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is '15’
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:27 DEBUG[2908] pbx.c: Function result is '0’
Jun 15 15:47:27 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:27 VERBOSE[2908] logger.c: recordingcheck|20070615-154727|1181936847.31: Inbound recording not enabled
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: DeadAGI
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Noop
Jun 15 15:47:27 DEBUG[2908] app_macro.c: Executed application: Macro
Jun 15 15:47:27 VERBOSE[2908] logger.c: dialparties.agi: Starting New Dialparties.agi
Jun 15 15:47:27 VERBOSE[2908] logger.c: dialparties.agi: priority is 1
Jun 15 15:47:27 VERBOSE[2908] logger.c: dialparties.agi: Caller ID name is ‘Test Extension 1’ number is '4000’
Jun 15 15:47:27 VERBOSE[2908] logger.c: dialparties.agi: Methodology of ring is 'none’
Jun 15 15:47:27 DEBUG[2908] db.c: Unable to find key ‘4001’ in family 'CF’
Jun 15 15:47:27 DEBUG[2908] db.c: Unable to find key ‘4001’ in family 'DND’
Jun 15 15:47:27 DEBUG[2908] db.c: Unable to find key ‘4001’ in family 'CFB’
Jun 15 15:47:27 DEBUG[2908] db.c: Unable to find key ‘4001’ in family 'CFU’
Jun 15 15:47:28 DEBUG[2908] app_macro.c: Executed application: DeadAGI
Jun 15 15:47:28 DEBUG[2908] chan_sip.c: Setting NAT on RTP to 524288
Jun 15 15:47:28 DEBUG[2908] chan_sip.c: Outgoing Call for 4001
Jun 15 15:47:28 DEBUG[6241] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 102: Found
Jun 15 15:47:28 DEBUG[6241] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 102: Found
Jun 15 15:47:43 DEBUG[2908] chan_sip.c: update_call_counter(4001) - decrement call limit counter
Jun 15 15:47:43 DEBUG[2908] chan_sip.c: Acked pending invite 102
Jun 15 15:47:43 DEBUG[2908] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Jun 15 15:47:43 DEBUG[2908] app_dial.c: Exiting with DIALSTATUS=NOANSWER.
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Dial
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Macro
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '1’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: GosubIf
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '1’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: GosubIf
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: NoOp
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Not taking any branch
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: NoOp
Jun 15 15:47:43 DEBUG[2908] pbx.c: Function result is 'Test Extension 1’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Function result is '4000’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Noop
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Not taking any branch
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '1’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: NoOp
Jun 15 15:47:43 DEBUG[2908] pbx.c: Function result is '4000’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:43 DEBUG[2908] pbx.c: Function result is 'Test Extension 1’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Not taking any branch
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:43 DEBUG[2908] pbx.c: Function result is '4000’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Noop
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '1’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:43 DEBUG[2908] pbx.c: Function result is '“Test Extension 1” <4000>'
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: NoOp
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Macro
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '0’
Jun 15 15:47:43 DEBUG[2908] pbx.c: Function result is ''
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:43 WARNING[2908] func_db.c: DB requires an argument, DB(/)
Jun 15 15:47:43 DEBUG[2908] pbx.c: Function result is ''
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is '1’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:43 DEBUG[2908] pbx.c: Function result is 'default’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Set
Jun 15 15:47:43 DEBUG[2908] pbx.c: Expression result is ‘0’
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: GotoIf
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: NoOp
Jun 15 15:47:43 DEBUG[2908] app_macro.c: Executed application: Macro
Jun 15 15:47:43 DEBUG[2908] app_voicemail.c: /var/spool/asterisk/voicemail/default/4001/unavail doesn’t exist, doing what we can
Jun 15 15:47:43 DEBUG[2908] channel.c: Scheduling timer at 160 sample intervals
Jun 15 15:47:43 DEBUG[6241] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Jun 15 15:47:43 DEBUG[6241] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Not Found
Jun 15 15:47:43 DEBUG[6241] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Response 2027: Match Found
Jun 15 15:47:49 DEBUG[6240] chan_iax2.c: Peer lastms 3, historicms 3, maxms 2000
Jun 15 15:47:49 DEBUG[6241] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Jun 15 15:47:56 DEBUG[2878] manager.c: Manager received command ‘Command’
Jun 15 15:47:56 DEBUG[2878] manager.c: Manager received command ‘Command’
Jun 15 15:47:56 DEBUG[2878] manager.c: Manager received command ‘Command’
Jun 15 15:48:03 DEBUG[2908] app_voicemail.c: Hang up during prefile playback
Jun 15 15:48:03 DEBUG[2908] channel.c: Scheduling timer at 0 sample intervals
Jun 15 15:48:03 ERROR[2908] cdr_addon_mysql.c: cdr_mysql: cannot connect to database server localhost. CDR will not be spooled.
Jun 15 15:48:03 DEBUG[2908] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Jun 15 15:48:03 DEBUG[2908] 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-06-15 15:47:27’,’“Test Extension 1” <4000>’,‘4000’,‘4001’,‘from-internal’, ‘SIP/4000-09c42ed0’,‘SIP/4001-09c4fae0’,‘VoiceMail’,‘4001@default|u’,36,20,‘ANSWERED’,3,’’,‘1181936847.31’)

bump

Any help is appretiated

try posting the CLI first, the log can be very cryptic and misses a lot of information that is in the CLI trace (it’s usually only needed in conjunction with the cli trace to track harder problems).