Call is not receiving,only hearing busy tone

Hi,
I have configured 2 extensions.4000 and 4001.one extension is configures on softphone and other on a hardphone.When i make a call from any one of the extensions to other i am hearing only a busy tone since i am a newbie i am not able to find a solution for that.
Pls help!!!
Here is the log!
[Mar 28 18:50:52] VERBOSE[3577][C-00000002] netsock2.c: == Using SIP RTP TOS bits 184
[Mar 28 18:50:52] VERBOSE[3577][C-00000002] netsock2.c: == Using SIP RTP CoS mark 5
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [4000@from-internal:1] Macro(“SIP/4001-00000002”, “exten-vm,novm,4000”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:1] Macro(“SIP/4001-00000002”, “user-callerid,”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/4001-00000002”, “AMPUSER=4001”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:2] GotoIf(“SIP/4001-00000002”, “0?report”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:3] ExecIf(“SIP/4001-00000002”, “1?Set(REALCALLERIDNUM=4001)”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:4] Set(“SIP/4001-00000002”, “AMPUSER=4001”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/4001-00000002”, “AMPUSERCIDNAME=Madhav”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/4001-00000002”, “0?report”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/4001-00000002”, “AMPUSERCID=4001”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:8] Set(“SIP/4001-00000002”, “CALLERID(all)=“Madhav” <4001>”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:9] ExecIf(“SIP/4001-00000002”, “0?Set(CHANNEL(language)=)”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:10] GotoIf(“SIP/4001-00000002”, “0?continue”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:11] Set(“SIP/4001-00000002”, “__TTL=64”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:12] GotoIf(“SIP/4001-00000002”, “1?continue”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-user-callerid,s,19)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:19] Set(“SIP/4001-00000002”, “CALLERID(number)=4001”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:20] Set(“SIP/4001-00000002”, “CALLERID(name)=Madhav”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-user-callerid:21] NoOp(“SIP/4001-00000002”, “Using CallerID “Madhav” <4001>”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:2] Set(“SIP/4001-00000002”, “RingGroupMethod=none”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:3] Set(“SIP/4001-00000002”, “VMBOX=novm”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:4] Set(“SIP/4001-00000002”, “__EXTTOCALL=4000”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:5] Set(“SIP/4001-00000002”, “CFUEXT=”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:6] Set(“SIP/4001-00000002”, “CFBEXT=”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:7] Set(“SIP/4001-00000002”, “RT=”"") in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:8] Macro(“SIP/4001-00000002”, “record-enable,4000,IN”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-record-enable:1] GotoIf(“SIP/4001-00000002”, “1?check”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-record-enable,s,4)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-record-enable:4] ExecIf(“SIP/4001-00000002”, “0?MacroExit()”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-record-enable:5] GotoIf(“SIP/4001-00000002”, “0?Group:OUT”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-record-enable,s,15)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-record-enable:15] GotoIf(“SIP/4001-00000002”, “1?IN”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-record-enable,s,20)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-record-enable:20] ExecIf(“SIP/4001-00000002”, “1?MacroExit()”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:9] Macro(“SIP/4001-00000002”, “dial-one,”",tr,4000") in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-dial-one:1] Set(“SIP/4001-00000002”, “DEXTEN=4000”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-dial-one:2] Set(“SIP/4001-00000002”, “DIALSTATUS_CW=”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-dial-one:3] GosubIf(“SIP/4001-00000002”, “0?screen,1”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-dial-one:4] GosubIf(“SIP/4001-00000002”, “0?cf,1”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-dial-one:5] GotoIf(“SIP/4001-00000002”, “0?skip1”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-dial-one:6] Set(“SIP/4001-00000002”, “DEXTEN=”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-dial-one:7] Set(“SIP/4001-00000002”, “DIALSTATUS=BUSY”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-dial-one:8] GotoIf(“SIP/4001-00000002”, “1?nodial”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-dial-one,s,41)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-dial-one:41] ExecIf(“SIP/4001-00000002”, “0?Set(DIALSTATUS=NOANSWER)”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-dial-one:42] NoOp(“SIP/4001-00000002”, “Returned from dial-one with nothing to call and DIALSTATUS: BUSY”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-dial-one:43] MacroExit(“SIP/4001-00000002”, “”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:10] GotoIf(“SIP/4001-00000002”, “0?exit”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:11] Set(“SIP/4001-00000002”, “SV_DIALSTATUS=BUSY”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:12] GosubIf(“SIP/4001-00000002”, “0?docfu,1”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:13] GosubIf(“SIP/4001-00000002”, “0?docfb,1”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:14] Set(“SIP/4001-00000002”, “DIALSTATUS=BUSY”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:15] NoOp(“SIP/4001-00000002”, “Voicemail is ‘novm’”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-exten-vm:16] GotoIf(“SIP/4001-00000002”, “1?s-BUSY,1”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-exten-vm,s-BUSY,1)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s-BUSY@macro-exten-vm:1] NoOp(“SIP/4001-00000002”, “Extension is reporting BUSY and not passing to Voicemail”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s-BUSY@macro-exten-vm:2] GotoIf(“SIP/4001-00000002”, “0?exit,1”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s-BUSY@macro-exten-vm:3] PlayTones(“SIP/4001-00000002”, “busy”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s-BUSY@macro-exten-vm:4] Busy(“SIP/4001-00000002”, “20”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] app_macro.c: == Spawn extension (macro-exten-vm, s-BUSY, 4) exited non-zero on ‘SIP/4001-00000002’ in macro ‘exten-vm’
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: == Spawn extension (from-internal, 4000, 1) exited non-zero on ‘SIP/4001-00000002’
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [h@from-internal:1] Macro(“SIP/4001-00000002”, “hangupcall”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/4001-00000002”, “1?endmixmoncheck”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-hangupcall,s,9)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:9] NoOp(“SIP/4001-00000002”, “End of MIXMON check”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:10] GotoIf(“SIP/4001-00000002”, “1?nomeetmemon”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-hangupcall,s,28)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:28] NoOp(“SIP/4001-00000002”, “End of MEETME check”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:29] GotoIf(“SIP/4001-00000002”, “1?noautomon”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-hangupcall,s,34)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:34] NoOp(“SIP/4001-00000002”, “TOUCH_MONITOR_OUTPUT=”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:35] GotoIf(“SIP/4001-00000002”, “1?noautomon2”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-hangupcall,s,41)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:41] NoOp(“SIP/4001-00000002”, “MONITOR_FILENAME=”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:42] GotoIf(“SIP/4001-00000002”, “1?skiprg”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-hangupcall,s,45)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:45] GotoIf(“SIP/4001-00000002”, “1?skipblkvm”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-hangupcall,s,48)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:48] GotoIf(“SIP/4001-00000002”, “1?theend”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Goto (macro-hangupcall,s,50)
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:50] AGI(“SIP/4001-00000002”, “hangup.agi”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/hangup.agi
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] res_agi.c: – <SIP/4001-00000002>AGI Script hangup.agi completed, returning 0
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: – Executing [s@macro-hangupcall:51] Hangup(“SIP/4001-00000002”, “”) in new stack
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] app_macro.c: == Spawn extension (macro-hangupcall, s, 51) exited non-zero on ‘SIP/4001-00000002’ in macro ‘hangupcall’
[Mar 28 18:50:52] VERBOSE[3846][C-00000002] pbx.c: == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/4001-00000002’

This looks like a trace of a FreePBX dialplan. FreePBX support is provided at freepbx.org/forums/

The test in priority 8 of macro-dial-one appears to have rejected the call. I guess it is testing device state or something similar, as it seems to have given up without actually trying to make the call. You will need to ask the FreePBX people what that test does.