provided by Star2Billing S.L.

I installed 1.5.1 on a piaf fresh install

install went thru ok

i did steps to edit extension_custom and extension_a2billing files along with etc/a2billing.conf

I create an account in a2billing and place it in the freepbx extension account code
sip trunking working
and outbound pointing to A2B/1 and in a2billing trunk points back to freepbx sip trunks

below is the log from dialing a number from extension pointed to A2B/1




[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [12127773456@from-internal:1] Macro("SIP/1-c00153e0", "user-callerid|SKIPTTL|") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-user-callerid:1] Set("SIP/1-c00153e0", "AMPUSER=1") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/1-c00153e0", "0?report") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: GotoIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/1-c00153e0", "1|Set|REALCALLERIDNUM=1") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: ExecIf
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Last app: Set|REALCALLERIDNUM=1
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-user-callerid:4] Set("SIP/1-c00153e0", "AMPUSER=1") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-user-callerid:5] Set("SIP/1-c00153e0", "AMPUSERCIDNAME=1") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/1-c00153e0", "1?report") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Goto (macro-user-callerid,s,10)
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: GotoIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-user-callerid:10] GotoIf("SIP/1-c00153e0", "1?continue") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Goto (macro-user-callerid,s,19)
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: GotoIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-user-callerid:19] NoOp("SIP/1-c00153e0", "Using CallerID "device" <1>") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Noop
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [12127773456@from-internal:2] Set("SIP/1-c00153e0", "_NODEST=") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [12127773456@from-internal:3] Macro("SIP/1-c00153e0", "record-enable|1|OUT|") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/1-c00153e0", "1?check") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Goto (macro-record-enable,s,4)
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: GotoIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-record-enable:4] AGI("SIP/1-c00153e0", "recordingcheck|20100204-183336|1265322816.21") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: recordingcheck|20100204-183336|1265322816.21: Outbound recording not enabled
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- AGI Script recordingcheck completed, returning 0
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: AGI
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-record-enable:5] MacroExit("SIP/1-c00153e0", "") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [12127773456@from-internal:4] Macro("SIP/1-c00153e0", "dialout-trunk|5|12127773456||") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/1-c00153e0", "DIAL_TRUNK=5") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] DEBUG[4786] func_db.c: DB: AMPUSER/1/pinless not found in database.
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/1-c00153e0", "0?sub-pincheck|s|1") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: GosubIf
[2010-02-04 18:33:36] DEBUG[4786] func_db.c: DB: AMPUSER/1/pinless not found in database.
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/1-c00153e0", "0?disabletrunk|1") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: GotoIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:4] Set("SIP/1-c00153e0", "DIAL_NUMBER=12127773456") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:5] Set("SIP/1-c00153e0", "DIAL_TRUNK_OPTIONS=tr") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:6] Set("SIP/1-c00153e0", "OUTBOUND_GROUP=OUT_5") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/1-c00153e0", "1?nomax") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Goto (macro-dialout-trunk,s,9)
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: GotoIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/1-c00153e0", "0?skipoutcid") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: GotoIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:10] Set("SIP/1-c00153e0", "DIAL_TRUNK_OPTIONS=") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:11] Macro("SIP/1-c00153e0", "outbound-callerid|5") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/1-c00153e0", "0|SetCallerPres|") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: ExecIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/1-c00153e0", "1|Set|REALCALLERIDNUM=1") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: ExecIf
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Last app: Set|REALCALLERIDNUM=1
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/1-c00153e0", "1?normcid") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Goto (macro-outbound-callerid,s,6)
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: GotoIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-outbound-callerid:6] Set("SIP/1-c00153e0", "USEROUTCID=") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] DEBUG[4786] func_db.c: DB: DEVICE/1/emergency_cid not found in database.
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-outbound-callerid:7] Set("SIP/1-c00153e0", "EMERGENCYCID=") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-outbound-callerid:8] Set("SIP/1-c00153e0", "TRUNKOUTCID=") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/1-c00153e0", "1?trunkcid") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Goto (macro-outbound-callerid,s,12)
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: GotoIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-outbound-callerid:12] ExecIf("SIP/1-c00153e0", "0|Set|CALLERID(all)=") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: ExecIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-outbound-callerid:13] ExecIf("SIP/1-c00153e0", "0|Set|CALLERID(all)=") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: ExecIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/1-c00153e0", "0|SetCallerPres|prohib_passed_screen") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: ExecIf
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Macro
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:12] ExecIf("SIP/1-c00153e0", "0|AGI|fixlocalprefix") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: ExecIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:13] Set("SIP/1-c00153e0", "OUTNUM=12127773456") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:14] Set("SIP/1-c00153e0", "custom=AMP") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Set
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/1-c00153e0", "0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)") in new stack
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: ExecIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk:16] Macro("SIP/1-c00153e0", "dialout-trunk-predial-hook|") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] GotoIf("SIP/1-c00153e0", "1?custom-freepbx-a2billing|12127773456|1:2") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Goto (custom-freepbx-a2billing,12127773456,1)
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: GotoIf
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: == Channel 'SIP/1-c00153e0' jumping out of macro 'dialout-trunk-predial-hook'
[2010-02-04 18:33:36] DEBUG[4786] app_macro.c: Executed application: Macro
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: == Channel 'SIP/1-c00153e0' jumping out of macro 'dialout-trunk'
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [12127773456@custom-freepbx-a2billing:1] DeadAGI("SIP/1-c00153e0", "a2billing.php|1") in new stack
[2010-02-04 18:33:36] WARNING[4786] res_agi.c: Running DeadAGI on a live channel will cause problems, please use AGI
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/a2billing.php
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- AGI Script a2billing.php completed, returning 0
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: -- Executing [12127773456@custom-freepbx-a2billing:2] Hangup("SIP/1-c00153e0", "") in new stack
[2010-02-04 18:33:36] VERBOSE[4786] logger.c: == Spawn extension (custom-freepbx-a2billing, 12127773456, 2) exited non-zero on 'SIP/1-c00153e0'
[2010-02-04 18:34:23] VERBOSE[4791] logger.c: == Parsing '/etc/asterisk/manager.conf': [2010-02-04 18:34:23] VERBOSE[4791] logger.c: Found
[2010-02-04 18:34:23] VERBOSE[4791] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': [2010-02-04 18:34:23] VERBOSE[4791] logger.c: Found
[2010-02-04 18:34:23] VERBOSE[4791] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': [2010-02-04 18:34:23] VERBOSE[4791] logger.c: Found
[2010-02-04 18:34:23] VERBOSE[4791] logger.c: == Manager 'admin' logged on from 127.0.0.1

Hi

turn up the logging in the agi-conf so you can see what is going on.

Joe

agi = /var/log/a2billing_agi.log

it was agi = /tmp/a2billing_agi.log


but i notice its still not logging


what i'm doing wrong here
tried user asterisk and root at 644

agi-conf verbose=4

[2010-02-05 09:36:51] VERBOSE[7299] logger.c: == Parsing '/etc/asterisk/manager.conf': [2010-02-05 09:36:51] VERBOSE[7299] logger.c: Found
[2010-02-05 09:36:51] VERBOSE[7299] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': [2010-02-05 09:36:51] VERBOSE[7299] logger.c: Found
[2010-02-05 09:36:51] VERBOSE[7299] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': [2010-02-05 09:36:51] VERBOSE[7299] logger.c: Found
[2010-02-05 09:36:51] VERBOSE[7299] logger.c: == Manager 'admin' logged on from 127.0.0.1
[2010-02-05 09:36:51] VERBOSE[7299] logger.c: == Manager 'admin' logged off from 127.0.0.1
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [12127773456@from-internal:1] Macro("SIP/2-c0015730", "user-callerid|SKIPTTL|") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-user-callerid:1] Set("SIP/2-c0015730", "AMPUSER=2") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/2-c0015730", "0?report") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: GotoIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/2-c0015730", "1|Set|REALCALLERIDNUM=2") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: ExecIf
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Last app: Set|REALCALLERIDNUM=2
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-user-callerid:4] Set("SIP/2-c0015730", "AMPUSER=2") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-user-callerid:5] Set("SIP/2-c0015730", "AMPUSERCIDNAME=2") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/2-c0015730", "1?report") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Goto (macro-user-callerid,s,10)
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: GotoIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-user-callerid:10] GotoIf("SIP/2-c0015730", "1?continue") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Goto (macro-user-callerid,s,19)
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: GotoIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-user-callerid:19] NoOp("SIP/2-c0015730", "Using CallerID "device" <2>") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Noop
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [12127773456@from-internal:2] Set("SIP/2-c0015730", "_NODEST=") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [12127773456@from-internal:3] Macro("SIP/2-c0015730", "record-enable|2|OUT|") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/2-c0015730", "1?check") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Goto (macro-record-enable,s,4)
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: GotoIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-record-enable:4] AGI("SIP/2-c0015730", "recordingcheck|20100205-093651|1265377011.31") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_request: recordingcheck
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_channel: SIP/2-c0015730
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_language: en
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_type: SIP
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_uniqueid: 1265377011.31
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_callerid: 2
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_calleridname: device
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_callingpres: 0
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_callingani2: 0
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_callington: 0
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_callingtns: 0
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_dnid: 12127773456
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_rdnis: unknown
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_context: macro-record-enable
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_extension: s
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_priority: 4
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_enhanced: 0.0
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_accountcode: 6244775448
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >>
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Rx << GET VARIABLE ARG2
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> 200 result=1 (OUT)
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Rx << GET VARIABLE ARG1
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> 200 result=1 (2)
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Rx << DATABASE GET "AMPUSER" "2/recording"
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> 200 result=1 (out=Adhoc|in=Adhoc)
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Rx << VERBOSE "Outbound recording not enabled" 1
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: recordingcheck|20100205-093651|1265377011.31: Outbound recording not enabled
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> 200 result=1
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- AGI Script recordingcheck completed, returning 0
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: AGI
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-record-enable:5] MacroExit("SIP/2-c0015730", "") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [12127773456@from-internal:4] Macro("SIP/2-c0015730", "dialout-trunk|5|12127773456||") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/2-c0015730", "DIAL_TRUNK=5") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] DEBUG[7301] func_db.c: DB: AMPUSER/2/pinless not found in database.
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/2-c0015730", "0?sub-pincheck|s|1") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: GosubIf
[2010-02-05 09:36:51] DEBUG[7301] func_db.c: DB: AMPUSER/2/pinless not found in database.
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/2-c0015730", "0?disabletrunk|1") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: GotoIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:4] Set("SIP/2-c0015730", "DIAL_NUMBER=12127773456") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:5] Set("SIP/2-c0015730", "DIAL_TRUNK_OPTIONS=tr") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:6] Set("SIP/2-c0015730", "OUTBOUND_GROUP=OUT_5") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/2-c0015730", "1?nomax") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Goto (macro-dialout-trunk,s,9)
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: GotoIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/2-c0015730", "0?skipoutcid") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: GotoIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:10] Set("SIP/2-c0015730", "DIAL_TRUNK_OPTIONS=") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:11] Macro("SIP/2-c0015730", "outbound-callerid|5") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/2-c0015730", "0|SetCallerPres|") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: ExecIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/2-c0015730", "1|Set|REALCALLERIDNUM=2") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: ExecIf
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Last app: Set|REALCALLERIDNUM=2
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/2-c0015730", "1?normcid") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Goto (macro-outbound-callerid,s,6)
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: GotoIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-outbound-callerid:6] Set("SIP/2-c0015730", "USEROUTCID=") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] DEBUG[7301] func_db.c: DB: DEVICE/2/emergency_cid not found in database.
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-outbound-callerid:7] Set("SIP/2-c0015730", "EMERGENCYCID=") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-outbound-callerid:8] Set("SIP/2-c0015730", "TRUNKOUTCID=") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/2-c0015730", "1?trunkcid") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Goto (macro-outbound-callerid,s,12)
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: GotoIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-outbound-callerid:12] ExecIf("SIP/2-c0015730", "0|Set|CALLERID(all)=") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: ExecIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-outbound-callerid:13] ExecIf("SIP/2-c0015730", "0|Set|CALLERID(all)=") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: ExecIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/2-c0015730", "0|SetCallerPres|prohib_passed_screen") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: ExecIf
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Macro
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:12] ExecIf("SIP/2-c0015730", "0|AGI|fixlocalprefix") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: ExecIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:13] Set("SIP/2-c0015730", "OUTNUM=12127773456") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:14] Set("SIP/2-c0015730", "custom=AMP") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Set
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/2-c0015730", "0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)") in new stack
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: ExecIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk:16] Macro("SIP/2-c0015730", "dialout-trunk-predial-hook|") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] GotoIf("SIP/2-c0015730", "1?custom-freepbx-a2billing|12127773456|1:2") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Goto (custom-freepbx-a2billing,12127773456,1)
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: GotoIf
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: == Channel 'SIP/2-c0015730' jumping out of macro 'dialout-trunk-predial-hook'
[2010-02-05 09:36:51] DEBUG[7301] app_macro.c: Executed application: Macro
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: == Channel 'SIP/2-c0015730' jumping out of macro 'dialout-trunk'
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [12127773456@custom-freepbx-a2billing:1] DeadAGI("SIP/2-c0015730", "a2billing.php|1") in new stack
[2010-02-05 09:36:51] WARNING[7301] res_agi.c: Running DeadAGI on a live channel will cause problems, please use AGI
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/a2billing.php
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_request: a2billing.php
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_channel: SIP/2-c0015730
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_language: en
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_type: SIP
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_uniqueid: 1265377011.31
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_callerid: 2
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_calleridname: device
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_callingpres: 0
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_callingani2: 0
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_callington: 0
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_callingtns: 0
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_dnid: 12127773456
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_rdnis: unknown
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_context: custom-freepbx-a2billing
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_extension: 12127773456
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_priority: 1
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_enhanced: 0.0
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >> agi_accountcode: 6244775448
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: AGI Tx >>
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- AGI Script a2billing.php completed, returning 0
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: -- Executing [12127773456@custom-freepbx-a2billing:2] Hangup("SIP/2-c0015730", "") in new stack
[2010-02-05 09:36:51] VERBOSE[7301] logger.c: == Spawn extension (custom-freepbx-a2billing, 12127773456, 2) exited non-zero on 'SIP/2-c0015730'
[2010-02-05 09:36:54] VERBOSE[7304] logger.c: == Parsing '/etc/asterisk/manager.conf': [2010-02-05 09:36:54] VERBOSE[7304] logger.c: Found
[2010-02-05 09:36:54] VERBOSE[7304] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': [2010-02-05 09:36:54] VERBOSE[7304] logger.c: Found
[2010-02-05 09:36:54] VERBOSE[7304] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': [2010-02-05 09:36:54] VERBOSE[7304] logger.c: Found
[2010-02-05 09:36:54] VERBOSE[7304] logger.c: == Manager 'admin' logged on from 127.0.0.1
[2010-02-05 09:36:54] VERBOSE[7304] logger.c: == Manager 'admin' logged off from 127.0.0.1
[2010-02-05 09:37:23] VERBOSE[7309] logger.c: == Parsing '/etc/asterisk/manager.conf': [2010-02-05 09:37:23] VERBOSE[7309] logger.c: Found
[2010-02-05 09:37:23] VERBOSE[7309] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': [2010-02-05 09:37:23] VERBOSE[7309] logger.c: Found
[2010-02-05 09:37:23] VERBOSE[7309] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': [2010-02-05 09:37:23] VERBOSE[7309] logger.c: Found
[2010-02-05 09:37:23] VERBOSE[7309] logger.c: == Manager 'admin' logged on from 127.0.0.1

I did a fresh install and got the same problem, let me detailed what i did

Load piaf 1.4 x64

update-scripts / fixes

update freepbx 2.6

update php 5.2.10

install a2billing using instruction from
viewtopic.php?f=21&t=5010


added entry for
extension_custom
manger_custom
extension_a2billing
custom destinations

in freepbx added trunk and it work to make a freepbx call
in a2billing added rate cards and trunk

and still getting the above errors

can anyone say what i am doing wrong?

i am seeing something like No provider found, checking channel drivers for SIP
wonder if that is the problem, i have tested the trunk in freepbx and it work, and a2billing its pointed correctly trunk name matching



anyone got any ideas?





[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: Setting NAT on RTP to On
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: Allocating new SIP dialog for [email protected] - INVITE (With RTP)
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: Setting NAT on RTP to On
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: = Found Their Call ID: [email protected] Their Tag 4d0cf28a7b36aafo1 Our tag: as00d763c0
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: Stopping retransmission on '[email protected]' of Response 101: Match Found
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: = Found Their Call ID: [email protected] Their Tag 4d0cf28a7b36aafo1 Our tag: as00d763c0
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: Setting NAT on RTP to On
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: T38 state changed to 0 on channel <none>
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: We're settling with these formats: 0x1 (g723)
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: Checking SIP call limits for device 1697848084
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: Updating call counter for incoming call
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: *** Our native formats are 0x1 (g723)
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: *** Joint capabilities are 0x1 (g723)
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: *** Our capabilities are 0x5 (g723|ulaw)
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x1 (g723)
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: This channel will not be able to handle video.
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: build_route: Contact hop: <sip:[email protected]:5060>
[2010-02-08 13:39:51] DEBUG[3257] chan_sip.c: SIP/1697848084-14b70b30: New call is still down.... Trying...
[2010-02-08 13:39:51] DEBUG[3257] devicestate.c: Notification of state change to be queued on device/channel SIP/1697848084-14b70b30
[2010-02-08 13:39:51] DEBUG[3257] devicestate.c: Notification of state change to be queued on device/channel SIP/1697848084
[2010-02-08 13:39:51] DEBUG[3255] devicestate.c: No provider found, checking channel drivers for SIP - 1697848084-14b70b30
[2010-02-08 13:39:51] DEBUG[3255] chan_sip.c: Checking device state for peer 1697848084-14b70b30
[2010-02-08 13:39:51] DEBUG[3255] devicestate.c: Changing state for SIP/1697848084-14b70b30 - state 4 (Invalid)
[2010-02-08 13:39:51] DEBUG[3255] devicestate.c: No provider found, checking channel drivers for SIP - 1697848084
[2010-02-08 13:39:51] DEBUG[3255] chan_sip.c: Checking device state for peer 1697848084
[2010-02-08 13:39:51] DEBUG[3255] devicestate.c: Changing state for SIP/1697848084 - state 1 (Not in use)
[2010-02-08 13:39:51] DEBUG[3277] app_queue.c: Device 'SIP/1697848084-14b70b30' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[2010-02-08 13:39:51] DEBUG[3277] app_queue.c: Device 'SIP/1697848084' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2010-02-08 13:39:51] DEBUG[16300] pbx.c: Launching 'Answer'
[2010-02-08 13:39:51] VERBOSE[16300] logger.c: -- Executing [12127773456@a2billing:1] Answer("SIP/1697848084-14b70b30", "") in new stack
[2010-02-08 13:39:51] DEBUG[16300] devicestate.c: Notification of state change to be queued on device/channel SIP/1697848084-14b70b30
[2010-02-08 13:39:51] DEBUG[3255] devicestate.c: No provider found, checking channel drivers for SIP - 1697848084-14b70b30
[2010-02-08 13:39:51] DEBUG[3255] chan_sip.c: Checking device state for peer 1697848084-14b70b30
[2010-02-08 13:39:51] DEBUG[3255] devicestate.c: Changing state for SIP/1697848084-14b70b30 - state 4 (Invalid)
[2010-02-08 13:39:51] DEBUG[3277] app_queue.c: Device 'SIP/1697848084-14b70b30' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[2010-02-08 13:39:51] DEBUG[16300] devicestate.c: Notification of state change to be queued on device/channel SIP/1697848084
[2010-02-08 13:39:51] DEBUG[3255] devicestate.c: No provider found, checking channel drivers for SIP - 1697848084
[2010-02-08 13:39:51] DEBUG[3255] chan_sip.c: Checking device state for peer 1697848084
[2010-02-08 13:39:51] DEBUG[3255] devicestate.c: Changing state for SIP/1697848084 - state 1 (Not in use)
[2010-02-08 13:39:51] DEBUG[3277] app_queue.c: Device 'SIP/1697848084' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2010-02-08 13:39:51] DEBUG[16300] chan_sip.c: SIP answering channel: SIP/1697848084-14b70b30
[2010-02-08 13:39:51] DEBUG[16300] chan_sip.c: Setting framing from config on incoming call
[2010-02-08 13:39:51] DEBUG[16300] chan_sip.c: ** Our capability: 0x1 (g723) Video flag: True
[2010-02-08 13:39:51] DEBUG[16300] chan_sip.c: ** Our prefcodec: 0x0 (nothing)
[2010-02-08 13:39:51] DEBUG[16300] chan_sip.c: -- Done with adding codecs to SDP
[2010-02-08 13:39:51] DEBUG[16300] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=22)
[2010-02-08 13:39:51] DEBUG[16300] chan_sip.c: Done building SDP. Settling with this capability: 0x1 (g723)
[2010-02-08 13:39:51] DEBUG[16300] pbx.c: Launching 'Wait'
[2010-02-08 13:39:51] VERBOSE[16300] logger.c: -- Executing [12127773456@a2billing:2] Wait("SIP/1697848084-14b70b30", "1") in new stack
[2010-02-08 13:39:52] DEBUG[3257] chan_sip.c: = Found Their Call ID: [email protected] Their Tag 4d0cf28a7b36aafo1 Our tag: as78960aa2
[2010-02-08 13:39:52] DEBUG[3257] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[2010-02-08 13:39:52] DEBUG[3257] chan_sip.c: Stopping retransmission on '[email protected]' of Response 102: Match Found
[2010-02-08 13:39:52] DEBUG[16300] rtp.c: - RTP 2833 Event: 0000000b (len = 4)
[2010-02-08 13:39:52] DEBUG[16300] rtp.c: Sending dtmf: 35 (#), at 10.11.12.215
[2010-02-08 13:39:52] DEBUG[16300] rtp.c: - RTP 2833 Event: 0000000b (len = 4)
[2010-02-08 13:39:52] DEBUG[16300] rtp.c: - RTP 2833 Event: 0000000b (len = 4)
[2010-02-08 13:39:52] DEBUG[16300] rtp.c: - RTP 2833 Event: 0000000b (len = 4)
[2010-02-08 13:39:52] DEBUG[16300] rtp.c: - RTP 2833 Event: 0000000b (len = 4)
[2010-02-08 13:39:52] DEBUG[16300] rtp.c: - RTP 2833 Event: 0000000b (len = 4)
[2010-02-08 13:39:52] DEBUG[16300] rtp.c: Sending dtmf: 35 (#), at 10.11.12.215
[2010-02-08 13:39:52] DEBUG[16300] rtp.c: - RTP 2833 Event: 0000000b (len = 4)
[2010-02-08 13:39:52] DEBUG[16300] rtp.c: - RTP 2833 Event: 0000000b (len = 4)
[2010-02-08 13:39:53] DEBUG[16300] pbx.c: Launching 'DeadAGI'
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: -- Executing [12127773456@a2billing:3] DeadAGI("SIP/1697848084-14b70b30", "a2billing.php|1") in new stack
[2010-02-08 13:39:53] WARNING[16300] res_agi.c: Running DeadAGI on a live channel will cause problems, please use AGI
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/a2billing.php
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_request: a2billing.php
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_channel: SIP/1697848084-14b70b30
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_language: en
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_type: SIP
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_uniqueid: 1265650791.42
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_callerid: 1697848084
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_calleridname: unknown
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_callingpres: 0
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_callingani2: 0
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_callington: 0
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_callingtns: 0
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_dnid: 12127773456
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_rdnis: unknown
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_context: a2billing
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_extension: 12127773456
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_priority: 3
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_enhanced: 0.0
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >> agi_accountcode: 1697848084
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: AGI Tx >>
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: -- AGI Script a2billing.php completed, returning 0
[2010-02-08 13:39:53] DEBUG[16300] pbx.c: Launching 'Hangup'
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: -- Executing [12127773456@a2billing:4] Hangup("SIP/1697848084-14b70b30", "") in new stack
[2010-02-08 13:39:53] DEBUG[16300] pbx.c: Spawn extension (a2billing,12127773456,4) exited non-zero on 'SIP/1697848084-14b70b30'
[2010-02-08 13:39:53] VERBOSE[16300] logger.c: == Spawn extension (a2billing, 12127773456, 4) exited non-zero on 'SIP/1697848084-14b70b30'
[2010-02-08 13:39:53] DEBUG[16300] channel.c: Soft-Hanging up channel 'SIP/1697848084-14b70b30'
[2010-02-08 13:39:53] DEBUG[16300] channel.c: Hanging up channel 'SIP/1697848084-14b70b30'
[2010-02-08 13:39:53] DEBUG[16300] chan_sip.c: Hangup call SIP/1697848084-14b70b30, SIP callid [email protected])
[2010-02-08 13:39:53] DEBUG[16300] devicestate.c: Notification of state change to be queued on device/channel SIP/1697848084-14b70b30
[2010-02-08 13:39:53] DEBUG[16300] devicestate.c: Notification of state change to be queued on device/channel SIP/1697848084
[2010-02-08 13:39:53] DEBUG[3255] devicestate.c: No provider found, checking channel drivers for SIP - 1697848084-14b70b30
[2010-02-08 13:39:53] DEBUG[3255] chan_sip.c: Checking device state for peer 1697848084-14b70b30
[2010-02-08 13:39:53] DEBUG[3255] devicestate.c: Changing state for SIP/1697848084-14b70b30 - state 4 (Invalid)
[2010-02-08 13:39:53] DEBUG[3255] devicestate.c: No provider found, checking channel drivers for SIP - 1697848084
[2010-02-08 13:39:53] DEBUG[3255] chan_sip.c: Checking device state for peer 1697848084
[2010-02-08 13:39:53] DEBUG[3255] devicestate.c: Changing state for SIP/1697848084 - state 1 (Not in use)
[2010-02-08 13:39:53] DEBUG[3277] app_queue.c: Device 'SIP/1697848084-14b70b30' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[2010-02-08 13:39:53] DEBUG[3277] app_queue.c: Device 'SIP/1697848084' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[2010-02-08 13:39:53] DEBUG[16300] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
[2010-02-08 13:39:53] DEBUG[16300] 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) VALUES ('2010-02-08 13:39:51','1697848084','1697848084','12127773456','a2billing', 'SIP/1697848084-14b70b30','','Hangup','',2,2,'ANSWERED',2,'1697848084')
[2010-02-08 13:39:53] DEBUG[3257] chan_sip.c: = Found Their Call ID: [email protected] Their Tag 4d0cf28a7b36aafo1 Our tag: as78960aa2
[2010-02-08 13:39:53] DEBUG[3257] chan_sip.c: Stopping retransmission on '[email protected]' of Request 102: Match Found
[2010-02-08 13:39:53] VERBOSE[3257] logger.c: Really destroying SIP dialog '[email protected]' Method: ACK
[2010-02-08 13:40:02] DEBUG[16302] manager.c: Manager received command 'login'
[2010-02-08 13:40:02] VERBOSE[16302] logger.c: == Parsing '/etc/asterisk/manager.conf': [2010-02-08 13:40:02] DEBUG[16302] config.c: Parsing /etc/asterisk/manager.conf
[2010-02-08 13:40:02] VERBOSE[16302] logger.c: Found
[2010-02-08 13:40:02] VERBOSE[16302] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': [2010-02-08 13:40:02] DEBUG[16302] config.c: Parsing /etc/asterisk/manager_additional.conf
[2010-02-08 13:40:02] VERBOSE[16302] logger.c: Found
[2010-02-08 13:40:02] VERBOSE[16302] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': [2010-02-08 13:40:02] DEBUG[16302] config.c: Parsing /etc/asterisk/manager_custom.conf
[2010-02-08 13:40:02] VERBOSE[16302] logger.c: Found
[2010-02-08 13:40:02] DEBUG[16302] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
[2010-02-08 13:40:02] DEBUG[16302] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
[2010-02-08 13:40:02] DEBUG[16302] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
[2010-02-08 13:40:02] DEBUG[16302] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
[2010-02-08 13:40:02] VERBOSE[16302] logger.c: == Manager 'admin' logged on from 127.0.0.1

Hi

Check the symbolic link to lib in /var/lib/asterisk/agi-bin
probably it is broken, correct it to [pathwherelocated]/common/lib

I hope this helps you