Decipher Log File

In the log entry below, extension 2025 can call ext 2001 but 2001 fails when calling 2025. If anyone can take a look and point me in the right direction, I would appreciate it.

Feb 9 08:45:25 DEBUG[2994] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Feb 9 08:45:40 DEBUG[2994] chan_sip.c: Auto destroying call 'YTU5NTRkNGRhODc3N2YyYTgzZmM3ZDUyOGY3YzYxMjQ.'
Feb 9 08:45:40 DEBUG[2994] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Feb 9 08:45:40 NOTICE[2994] chan_sip.c: Peer ‘2001’ is now REACHABLE! (9ms / 2000ms)
Feb 9 08:45:53 DEBUG[3371] manager.c: Manager received command 'Command’
Feb 9 08:45:53 DEBUG[3371] manager.c: Manager received command 'Command’
Feb 9 08:45:53 DEBUG[3371] manager.c: Manager received command 'Command’
Feb 9 08:45:55 DEBUG[2994] chan_sip.c: Auto destroying call 'YzZlMzllNGNjYTQwOGEyMWM1OTkyMTkzMjY3YzBjZmM.'
Feb 9 08:46:25 DEBUG[2994] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Feb 9 08:46:40 DEBUG[2994] chan_sip.c: Stopping retransmission on ‘04b785f421c5f9f2784c04d104eb031[email protected]’ of Request 102: Match Found
Feb 9 08:46:40 DEBUG[2994] chan_sip.c: Setting NAT on RTP to 524288
Feb 9 08:46:40 DEBUG[2994] chan_sip.c: Stopping retransmission on ‘NGM4ODQ5NjY4ZDVhZTMxZTkwNzM5NWRiZTM1NmI0NzY.’ of Response 1: Match Found
Feb 9 08:46:40 DEBUG[2994] chan_sip.c: Setting NAT on RTP to 524288
Feb 9 08:46:40 DEBUG[2994] chan_sip.c: Checking SIP call limits for device 2025
Feb 9 08:46:40 DEBUG[2994] chan_sip.c: build_route: Contact hop: sip:[email protected]:58494
Feb 9 08:46:40 DEBUG[3425] pbx.c: Function result is 'device’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Function result is '2025’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Expression result is '0’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Not taking any branch
Feb 9 08:46:40 DEBUG[3425] pbx.c: Expression result is '0’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Not taking any branch
Feb 9 08:46:40 DEBUG[3425] pbx.c: Function result is '2025’
Feb 9 08:46:40 DEBUG[3425] db.c: Unable to find key ‘2025/user’ in family 'DEVICE’
Feb 9 08:46:40 DEBUG[3425] func_db.c: DB: DEVICE/2025/user not found in database.
Feb 9 08:46:40 DEBUG[3425] pbx.c: Function result is ''
Feb 9 08:46:40 DEBUG[3425] db.c: Unable to find key ‘/cidname’ in family 'AMPUSER’
Feb 9 08:46:40 DEBUG[3425] func_db.c: DB: AMPUSER//cidname not found in database.
Feb 9 08:46:40 DEBUG[3425] pbx.c: Function result is ''
Feb 9 08:46:40 DEBUG[3425] pbx.c: Expression result is '1’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Expression result is '0’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Not taking any branch
Feb 9 08:46:40 DEBUG[3425] pbx.c: Expression result is '1’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Expression result is '-1’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Function result is '64’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Expression result is '1’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Function result is '“device” <2025>'
Feb 9 08:46:40 DEBUG[3425] db.c: Unable to find key ‘2001’ in family 'CFU’
Feb 9 08:46:40 DEBUG[3425] func_db.c: DB: CFU/2001 not found in database.
Feb 9 08:46:40 DEBUG[3425] pbx.c: Function result is ''
Feb 9 08:46:40 DEBUG[3425] pbx.c: Expression result is '0’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Expression result is '0’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Expression result is '0’
Feb 9 08:46:40 DEBUG[3425] pbx.c: Function result is ''
Feb 9 08:46:40 DEBUG[3425] pbx.c: Function result is '0’
Feb 9 08:46:41 VERBOSE[3425] logger.c: recordingcheck|20070209-084640|1171028800.0: Inbound recording not enabled
Feb 9 08:46:41 VERBOSE[3425] logger.c: dialparties.agi: Starting New Dialparties.agi
Feb 9 08:46:41 VERBOSE[3425] logger.c: dialparties.agi: priority is 1
Feb 9 08:46:41 VERBOSE[3425] logger.c: dialparties.agi: Caller ID name is ‘device’ number is '2025’
Feb 9 08:46:41 VERBOSE[3425] logger.c: dialparties.agi: Methodology of ring is 'none’
Feb 9 08:46:41 DEBUG[3425] db.c: Unable to find key ‘2001’ in family 'CF’
Feb 9 08:46:41 DEBUG[3425] db.c: Unable to find key ‘2001’ in family 'DND’
Feb 9 08:46:41 DEBUG[3425] db.c: Unable to find key ‘2001’ in family ‘CFB’
Feb 9 08:46:41 DEBUG[3425] db.c: Unable to find key ‘2001’ in family ‘CFU’
Feb 9 08:46:41 DEBUG[3425] chan_sip.c: Setting NAT on RTP to 524288
Feb 9 08:46:41 DEBUG[3425] chan_sip.c: Outgoing Call for 2001
Feb 9 08:46:41 DEBUG[2994] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on ‘[email protected]’ Request 102: Found
Feb 9 08:46:42 DEBUG[3425] chan_sip.c: update_call_counter(2001) - decrement call limit counter
Feb 9 08:46:42 DEBUG[3425] chan_sip.c: Acked pending invite 102
Feb 9 08:46:42 DEBUG[3425] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Feb 9 08:46:42 DEBUG[3425] app_dial.c: Exiting with DIALSTATUS=CANCEL.
Feb 9 08:46:42 DEBUG[2994] chan_sip.c: Stopping retransmission on ‘NGM4ODQ5NjY4ZDVhZTMxZTkwNzM5NWRiZTM1NmI0NzY.’ of Response 2: Match Found
Feb 9 08:46:42 DEBUG[3425] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Feb 9 08:46:42 DEBUG[3425] 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-02-09 08:46:40’,’“device” <2025>’,‘2025’,‘2001’,‘from-internal’, ‘SIP/2025-09eac780’,‘SIP/2001-09edc688’,‘ResetCDR’,‘w’,2,0,‘NO ANSWER’,3,‘1000063’,‘1171028800.0’)
Feb 9 08:46:42 DEBUG[2994] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
Feb 9 08:46:42 DEBUG[2994] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Not Found
Feb 9 08:46:42 NOTICE[3425] cdr.c: CDR on channel ‘SIP/2025-09eac780’ not posted
Feb 9 08:46:42 NOTICE[3425] cdr.c: CDR on channel ‘SIP/2025-09eac780’ lacks end
Feb 9 08:46:42 DEBUG[3425] pbx.c: Expression result is '1’
Feb 9 08:46:42 DEBUG[3425] pbx.c: Expression result is '1’
Feb 9 08:46:42 DEBUG[3425] chan_sip.c: update_call_counter(2025) - decrement call limit counter
Feb 9 08:46:59 DEBUG[2994] chan_sip.c: Setting NAT on RTP to 524288
Feb 9 08:46:59 DEBUG[2994] chan_sip.c: Stopping retransmission on ‘MzEzNWNkNTY4ZDlhYTkxZWFhZjBmNDQ5YjcwNTBmMTc.’ of Response 1: Match Found
Feb 9 08:46:59 DEBUG[2994] chan_sip.c: Setting NAT on RTP to 524288
Feb 9 08:46:59 DEBUG[2994] chan_sip.c: Checking SIP call limits for device 2001
Feb 9 08:46:59 DEBUG[2994] chan_sip.c: build_route: Contact hop: sip:[email protected]:58014
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is 'device’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '2001’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Not taking any branch
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Not taking any branch
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '2001’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '2001’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is 'Cherisse Soft’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Not taking any branch
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '2001’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Not taking any branch
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '1’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '-1’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '64’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '1’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '“Cherisse Soft” <2001>'
Feb 9 08:46:59 DEBUG[3432] db.c: Unable to find key ‘2025’ in family 'CFU’
Feb 9 08:46:59 DEBUG[3432] func_db.c: DB: CFU/2025 not found in database.
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is ''
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '1’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '1’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '15’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '0’
Feb 9 08:46:59 DEBUG[3432] db.c: Unable to find key ‘2025/recording’ in family 'AMPUSER’
Feb 9 08:46:59 VERBOSE[3432] logger.c: recordingcheck|20070209-084659|1171028819.2: No AMPUSER db entry for 2025. Not recording
Feb 9 08:46:59 VERBOSE[3432] logger.c: dialparties.agi: Starting New Dialparties.agi
Feb 9 08:46:59 VERBOSE[3432] logger.c: dialparties.agi: priority is 1
Feb 9 08:46:59 VERBOSE[3432] logger.c: dialparties.agi: Caller ID name is ‘Cherisse Soft’ number is '2001’
Feb 9 08:46:59 VERBOSE[3432] logger.c: dialparties.agi: Methodology of ring is 'none’
Feb 9 08:46:59 DEBUG[3432] db.c: Unable to find key ‘2025’ in family 'CF’
Feb 9 08:46:59 DEBUG[3432] db.c: Unable to find key ‘2025’ in family 'DND’
Feb 9 08:46:59 DEBUG[3432] db.c: Unable to find key ‘2025’ in family 'CW’
Feb 9 08:46:59 DEBUG[3432] db.c: Unable to find key ‘2025’ in family 'CFB’
Feb 9 08:46:59 DEBUG[3432] db.c: Unable to find key ‘2025’ in family 'CFU’
Feb 9 08:46:59 DEBUG[3436] manager.c: Manager received command 'login’
Feb 9 08:46:59 DEBUG[3436] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Feb 9 08:46:59 DEBUG[3436] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Feb 9 08:46:59 DEBUG[3436] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Feb 9 08:46:59 DEBUG[3436] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Feb 9 08:46:59 DEBUG[3436] manager.c: Manager received command 'ExtensionState’
Feb 9 08:46:59 DEBUG[3436] manager.c: Manager received command 'Logoff’
Feb 9 08:46:59 VERBOSE[3432] logger.c: dialparties.agi: Extension 2025 has ExtensionState: 0
Feb 9 08:46:59 DEBUG[3432] db.c: Unable to find key ‘2025/device’ in family 'AMPUSER’
Feb 9 08:46:59 DEBUG[3432] db.c: Unable to find key ‘/dial’ in family 'DEVICE’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Not taking any branch
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is 'Cherisse Soft’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '2001’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Not taking any branch
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '1’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '2001’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is 'Cherisse Soft’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Not taking any branch
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '2001’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '1’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is '“Cherisse Soft” <2001>'
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is '0’
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is ''
Feb 9 08:46:59 WARNING[3432] func_db.c: DB requires an argument, DB(/)
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is ''
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is ‘1’
Feb 9 08:46:59 DEBUG[3432] db.c: Unable to find key ‘2025/voicemail’ in family ‘AMPUSER’
Feb 9 08:46:59 DEBUG[3432] func_db.c: DB: AMPUSER/2025/voicemail not found in database.
Feb 9 08:46:59 DEBUG[3432] pbx.c: Function result is ‘‘
Feb 9 08:46:59 DEBUG[3432] pbx.c: Expression result is ‘1’
Feb 9 08:46:59 WARNING[3432] app_voicemail.c: No entry in voicemail config file for ‘2025’
Feb 9 08:47:00 DEBUG[3432] channel.c: Scheduling timer at 160 sample intervals
Feb 9 08:47:00 DEBUG[2994] chan_sip.c: Stopping retransmission on ‘MzEzNWNkNTY4ZDlhYTkxZWFhZjBmNDQ5YjcwNTBmMTc.’ of Response 2: Match Found
Feb 9 08:47:00 DEBUG[3432] channel.c: Scheduling timer at 0 sample intervals
Feb 9 08:47:00 DEBUG[3432] channel.c: Scheduling timer at 0 sample intervals
Feb 9 08:47:00 DEBUG[3432] channel.c: Scheduling timer at 160 sample intervals
Feb 9 08:47:01 DEBUG[3432] channel.c: Scheduling timer at 0 sample intervals
Feb 9 08:47:01 DEBUG[3432] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Feb 9 08:47:01 DEBUG[3432] 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-02-09 08:46:59’,’“Cherisse Soft” <2001>’,‘2001’,‘2025’,‘from-internal’, ‘SIP/2001-09eac780’,’’,‘Playback’,‘im-sorry&an-error-has-occured’,2,2,‘ANSWERED’,3,’’,‘1171028819.2’)
Feb 9 08:47:01 DEBUG[3432] chan_sip.c: update_call_counter(2001) - decrement call limit counter
Feb 9 08:47:14 DEBUG[2994] chan_sip.c: Auto destroying call ‘[email protected]