Summary:	ASTERISK-16276: All Calls Originated with .call files using Local Channels are logged with NO ANSWER Disposition.
Reporter:	Jamuel Starkey (jamuel)	Labels:
Date Opened:	2010-06-21 16:07:46	Date Closed:	2010-11-23 10:55:51.000-0600
Priority:	Minor	Regression?	No
Status:	Closed/Complete	Components:	CDR/General
Versions:		Frequency of Occurrence
Related Issues:
Environment:		Attachments:	( 0) 17540-asterisk-full_debug_log.txt
Description:	Using .call files to originate outbound faxing with sendfax app on * 1.6.2.9 with Local Channel results in the A-leg being logged as disposition ANSWERED while the B-leg and the resulting bridged fax call being logged as disposition UNANSWERED even though the call completes normally. ****** ADDITIONAL INFORMATION ****** A-leg is the Fax Recipient (i.e. PSTN/SIP Gateway) destination which enters the dialplan via a Local Channel while B-leg is the SendFax app. Here's a sample .call file: Channel: Local/4159622567@from-internal SetVar: LOCALHEADERINFO=Jamuel P. Starkey SetVar: LOCALSTATIONID=4152000126 SetVar: FAXRECEIVER=4159622567 SetVar: NEWFILENAME=/tmp/faxout/4159622567-4c1d480152e57/outfile.tif SetVar: JOBPATH=/tmp/faxout/4159622567-4c1d480152e57 SetVar: JOB=4159622567-4c1d480152e57 Context: sendfax Extension: s Priority: 1 Callerid: 4152000126 MaxRetries: 3 RetryTime: 300 WaitTime: 60 And here is the sendfax context: [sendfax] exten => s,1,Answer exten => s,1,NoOp(NEWFILENAME: ${NEWFILENAME}) exten => s,n,SendFAX(${NEWFILENAME}) exten => s,n,Set(CDR(userfield)=${FROM_DID}) exten => h,1,DumpChan() exten => h,n,AGI(post_process_fax.php, FAXSTATUS=${FAXSTATUS}, FAXERROR=${FAXERROR}, FAXPAGES=${FAXPAGES}, FAXMODE=${FAXMODE}, JOB=${JOB}, FAXRECEIVER=${FAXRECEIVER}, REMOTESTATIONID=${REMOTESTATIONID}) exten => h,n,Macro(hangupcall,) exten => failed,1,DumpChan() exten => failed,n,AGI(post_process_fax.php, FAXSTATUS=FAILED, FAXPAGES=${FAXPAGES}, FAXMODE=${FAXMODE}, JOB=${JOB}, FAXRECEIVER=${FAXRECEIVER}, REMOTESTATIONID=${REMOTESTATIONID})
Comments:	By: Jamuel Starkey (jamuel) 2010-06-21 16:11:26 Sorry, the Disposition is set to NO ANSWER rather than UNANSWERED. By: Paul Belanger (pabelanger) 2010-06-21 17:01:58 We require a complete debug log to help triage the issue. This document will provide instructions on how to collect debugging logs from an Asterisk machine for the purpose of helping bug marshals troubleshoot an issue: http://svn.digium.com/svn/asterisk/trunk/doc/HOWTO_collect_debug_information.txt By: Jamuel Starkey (jamuel) 2010-06-21 17:44:49 Attaching Verbose=15, Debug=15 logging from a test call. By: Jeff Hoppe (jhoppebugs) 2010-07-30 14:18:11 Could this be related to my issue where ORIGINATE commands via AMI are connecting to the context specified when then call is answered, but the ORIGINATERESPONSE event shows FAILED with NO ANSWER?   Should I create a seperate issue? By: Matthew Nicholson (mnicholson) 2010-07-30 14:28:53 I don't know if the two are related.  Create another issue and indicate in that issue that it may be related to this one. By: Matthew Nicholson (mnicholson) 2010-09-15 18:19:55 This works fine with the latest version of asterisk 1.6.2, please test with the latest version or the 1.6.2 SVN branch and let me know if you are still having problems. By: Jamuel Starkey (jamuel) 2010-09-18 01:20:13 Just checked out latest 1.6.2-SVN and see the same call disposition (UNANSWERED) for a completed call. By: Matthew Nicholson (mnicholson) 2010-09-22 11:34:01 I looked a little deeper into your logs and the problem here is that you are calling ResetCDR(w) in your dialplan which causes a CDR record that would not normally be written to be written (the one with NO ANSWER).  If you check your CDR records, there should be a record with the proper ANSWERED disposition in there as well.  If you remove the call to ResetCDR(w) that NO ANSWER record should go away. By: Matthew Nicholson (mnicholson) 2010-09-28 15:02:23 Have you had a chance to test with the work around I recommended (removing the call to ResetCDR)? By: Jamuel Starkey (jamuel) 2010-09-30 00:50:15 So I've tested with 1.6.2-SVN (287464) with all instances of ResetCDR(w) removed from the entire dialplan and *NO* CDR whatsoever is written out now for the second leg of the call (the Local Channel's call leg CDR is still written while the app SendFax call leg CDR is not written).  Is this expected behavior.  I was originally calling ResetCDR(w) in the 'h' extension after app SendFax completes. So if I then only invoke ResetCDR(w) after app SendFax completes I'm back to two CDR entries: one for the Local channel (which shows disposition ANSWERED) and the other for the subsequent app SendFax leg showing disposition NO ANSWER. Please let me know if I'm doing something stupid/wrong--otherwise I'm unable to confirm your workaround. By: Matthew Nicholson (mnicholson) 2010-09-30 11:35:38 Also try removing the call to NoCDR. By: Matthew Nicholson (mnicholson) 2010-09-30 11:37:06 You should only be seeing a single CDR record for both legs of the call. By: Jamuel Starkey (jamuel) 2010-09-30 12:52:22 I should apologize for not being more clear: in the first test when I removed the ResetCDR(w) I also removed NoCDR. So in first test:  there was neither ResetCDR and nor NoCDR invoked (both were commented out of the dialplan)--resulting in a single CDR for the Local call leg only (the app SendFax leg was not recorded in CDR). In test #2: both ResetCDR and NoCDR were added back to the "h" extension resulting in two CDR records (one for the Local and one for the app SendFax). When you are testing are you testing with app SendFax being invoked? By: Matthew Nicholson (mnicholson) 2010-09-30 12:53:55 Yes, I am testing with the SendFax app being invoked. By: Jamuel Starkey (jamuel) 2010-09-30 13:26:31 Matt: would remote ssh access to this box be of any interest? By: Matthew Nicholson (mnicholson) 2010-09-30 13:31:04 Not at this time.  What are you expecting to see in your CDR file? By: Jamuel Starkey (jamuel) 2010-09-30 13:35:57 I'd expect disposition == 'ANSWERED' and billsec != 0 (billsec roughly the same value as duration) Currently I see disposition == 'NO ANSWER' and billsec == 0 By: Matthew Nicholson (mnicholson) 2010-09-30 13:44:13 And you expect to see two records? By: Jamuel Starkey (jamuel) 2010-09-30 14:28:54 Actually I'd prefer to have only a single record (for the app SendFax leg) but am okay with 2 records if I can have disposition and billsec reflected accurately in each. By: Matthew Nicholson (mnicholson) 2010-09-30 14:35:59 Testing with '/n' on the local channel seems to produce two records with accurate disposition and billsec values. By: Jamuel Starkey (jamuel) 2010-09-30 15:50:46 I was under the impression that using '/n' on local channels along with T.38 (which is what we use with app SendFax) was not supported. Has that been fixed? By: Matthew Nicholson (mnicholson) 2010-09-30 16:00:26 No, I don't think that has been completely fixed yet.  Ok, I'll look into this a little more.  I think I have a better understanding of the issue.  I didn't realize billsec was incorrect when not using /n.  The fix for this may be to use /n, and if so, that T.38 on local channels bug will have to be fixed before this will work properly. By: Matthew Nicholson (mnicholson) 2010-11-12 13:20:53.000-0600 Test this with the latest SVN with local channels and '/n'.  I believe the t.38 on local channels thing is fixed. By: Matthew Nicholson (mnicholson) 2010-11-19 10:03:08.000-0600 Have you had a chance to do any more testing? By: Jamuel Starkey (jamuel) 2010-11-20 22:01:50.000-0600 Will test 1.6.2 SVN tonight (Saturday PST) and report back. By: Jamuel Starkey (jamuel) 2010-11-23 01:41:39.000-0600 Matthew:  I can confirm that outbound faxes running on Asterisk SVN-branch-1.6.2-r295868 with local channels specified with '/n' now complete with both successful T38 transmission and cdr call disposition ANSWERED logged. I am however running into a problem getting app_cdr_mysql.so module to load with 1.6.2 SVN.  So I haven't been able to completely test my existing setup. I'm seeing this error message in asterisk log: [Nov 22 23:04:44] WARNING[4847] loader.c: Module 'cdr_addon_mysql.so' was not compiled with the same compile-time options as this version of Asterisk. [Nov 22 23:04:44] WARNING[4847] loader.c: Module 'cdr_addon_mysql.so' will not be initialized as it may cause instability. [Nov 22 23:04:44] WARNING[4847] loader.c: Module 'cdr_addon_mysql.so' could not be loaded. Both asterisk and asterisk-addons were checked out of SVN and were both compiled with the same configure options. Any ideas? Are there other compile time options I should set?  I ran bootstrap.sh on both builds prior to runing configure && make menuconfig && make all && make install. I can attached config.log from both builds if that would help. Thanks. By: Matthew Nicholson (mnicholson) 2010-11-23 10:55:22.000-0600 Send a message to asterisk-users about that cdr_addon_mysql.so issue, there may be bugs there or there may be something special you have to do when building it.  I am going to close this bug as '/n' should be an acceptable work around.