yaai icon indicating copy to clipboard operation
yaai copied to clipboard

Outbound calls don't display caller ID

Open randomf opened this issue 12 years ago • 17 comments

I have a problem with outbound calls. The caller ID is lost in the process. Please see the log. Any idea what it might cause?

******** Asterisk Logger Starting **************
# Sugar root set to [/var/www/sugar/custom/modules/Asterisk/../../../]
Logging to: 
# Callout prefix is [1]
# Callin prefix is [+420]
asteriskMatchInternal = /^(sip\/[1-9][0-9][0-9]?[0-9]?-|Local)/i
# (Config processed)
Selecting DB Name: sugarcrm6
! Trying SOAP login endpoint=[http://192.168.192.200/sugar/soap.php] user=[admin] password=[35fab3a349bac12d4a018f9dc93d6976]
PHP Warning:  Attempt to modify property of non-object in /var/www/sugar/include/nusoap/nusoap.php on line 6160
PHP Warning:  Attempt to modify property of non-object in /var/www/sugar/include/nusoap/nusoap.php on line 6160
PHP Warning:  Attempt to modify property of non-object in /var/www/sugar/include/nusoap/nusoap.php on line 6160
PHP Warning:  Attempt to modify property of non-object in /var/www/sugar/include/nusoap/nusoap.php on line 6160
! Successful SOAP login id=e1a2cf458a60ca547eca0185da2e67ac user=admin GUID=1
# Successfully opened socket connection to 127.0.0.1:5038
! AMI Login action returned with rc=Asterisk Call Manager/1.1

[2012-10-04 00:26:37]
! --- Event -----------------------------------------------------------
!                Event -->                                                   
! ---------------------------------------------------------------------
[2012-10-04 00:27:37] Timeout or Error
[2012-10-04 00:27:41]
! --- Event -----------------------------------------------------------
!                Event --> NewCallerid                                       
!            Privilege --> call,all                                          
!              Channel --> SIP/300-00000058                                  
!          CallerIDNum --> 300                                               
!         CallerIDName --> Radek Strnad                                      
!             Uniqueid --> 1349303261.88                                     
!      CID-CallingPres --> 0 (Presentation Allowed, Not Screened)            
! ---------------------------------------------------------------------
* CallerID is: 300
* {e['UniqueId']} CallerID  Changed to: 300
[2012-10-04 00:27:41]
! --- Event -----------------------------------------------------------
!                Event --> NewCallerid                                       
!            Privilege --> call,all                                          
!              Channel --> SIP/300-00000058                                  
!          CallerIDNum -->                                                   
!         CallerIDName --> realexpert_m3                                     
!             Uniqueid --> 1349303261.88                                     
!      CID-CallingPres --> 0 (Presentation Allowed, Not Screened)            
! ---------------------------------------------------------------------
* CallerID is: 
* {e['UniqueId']} CallerID  Changed to: 
[2012-10-04 00:27:41]
! --- Event -----------------------------------------------------------
!                Event --> NewCallerid                                       
!            Privilege --> call,all                                          
!              Channel --> SIP/or_m3-00000059                                
!          CallerIDNum --> +420731119303                                     
!         CallerIDName --> CID:                                              
!             Uniqueid --> 1349303261.89                                     
!      CID-CallingPres --> 0 (Presentation Allowed, Not Screened)            
! ---------------------------------------------------------------------
* CallerID is: +420731119303
* {e['UniqueId']} CallerID  Changed to: +420731119303
[2012-10-04 00:27:41]
! --- Event -----------------------------------------------------------
!                Event --> Dial                                              
!            Privilege --> call,all                                          
!             SubEvent --> Begin                                             
!              Channel --> SIP/300-00000058                                  
!          Destination --> SIP/or_m3-00000059                                
!          CallerIDNum --> <unknown>                                         
!         CallerIDName --> realexpert_m3                                     
!     ConnectedLineNum --> +420731119303                                     
!    ConnectedLineName --> CID:                                              
!             UniqueID --> 1349303261.88                                     
!         DestUniqueID --> 1349303261.89                                     
!           Dialstring --> or_m3/9993+420731119303                           
! ---------------------------------------------------------------------
! Dial Event src=SIP/300-00000058 dest=SIP/or_m3-00000059
Array
(
    [id] => 386fce88-cae9-513c-1de4-506cbb69a4fa
    [error] => Array
        (
            [number] => 0
            [name] => No Error
            [description] => No Error
        )

)
! Successfully created CALL record with id=386fce88-cae9-513c-1de4-506cbb69a4fa
* CallerID is: <unknown>
OUTBOUND state detected... /^(sip\/[1-9][0-9][0-9]?[0-9]?-|Local)/i is astMatchInternal eChannel= SIP/300-00000058 eDestination=SIP/or_m3-00000059
[2012-10-04 00:27:44]
! --- Event -----------------------------------------------------------
!                Event --> NewAccountCode                                    
!            Privilege --> call,all                                          
!              Channel --> SIP/or_m3-00000059                                
!             Uniqueid --> 1349303261.89                                     
!          AccountCode -->                                                   
!       OldAccountCode -->                                                   
! ---------------------------------------------------------------------
[2012-10-04 00:27:44]
! --- Event -----------------------------------------------------------
!                Event --> Bridge                                            
!            Privilege --> call,all                                          
!          Bridgestate --> Link                                              
!           Bridgetype --> core                                              
!             Channel1 --> SIP/300-00000058                                  
!             Channel2 --> SIP/or_m3-00000059                                
!            Uniqueid1 --> 1349303261.88                                     
!            Uniqueid2 --> 1349303261.89                                     
!            CallerID1 -->                                                   
!            CallerID2 --> +420731119303                                     
! ---------------------------------------------------------------------
[2012-10-04 00:27:58]
! --- Event -----------------------------------------------------------
!                Event --> Unlink                                            
!            Privilege --> call,all                                          
!             Channel1 --> SIP/300-00000058                                  
!             Channel2 --> SIP/or_m3-00000059                                
!            Uniqueid1 --> 1349303261.88                                     
!            Uniqueid2 --> 1349303261.89                                     
!            CallerID1 --> <unknown>                                         
!            CallerID2 --> +420731119303                                     
! ---------------------------------------------------------------------
[2012-10-04 00:27:58]
! --- Event -----------------------------------------------------------
!                Event --> Hangup                                            
!            Privilege --> call,all                                          
!              Channel --> SIP/or_m3-00000059                                
!             Uniqueid --> 1349303261.89                                     
!          CallerIDNum --> +420731119303                                     
!         CallerIDName --> CID:                                              
!     ConnectedLineNum --> <unknown>                                         
!    ConnectedLineName --> realexpert_m3                                     
!                Cause --> 16                                                
!            Cause-txt --> Normal Clearing                                   
! ---------------------------------------------------------------------
# +++ findCallByAsteriskId(1349303261.89)
! Found entry in asterisk_log recordId=386fce88-cae9-513c-1de4-506cbb69a4fa
# [1349303261.89] FOUND outbound CALL
Looking for user extension number in: SIP/300-00000058
Channel Matched SIP/### style regex.  Ext is:300
# +++ findUserByAsteriskExtension(300)
! Assigned user id set to 90a50214-4ed1-3bbf-7a05-5055d7a37a5a
# [1349303261.89] Measured call duration is 14 seconds
# +++ find AccountByPhoneNumber(<unknown>)
! No results returned
# +++ find ContactByPhoneNumber(<unknown>)
  findSugarObjectByPhoneNumber: Contact query components- Phone:    RegEx: ()$
Found multiple contacts -- all belong to same account, associating call with account.
! Invalid Arguments passed to setRelationshipBetweenCallAndBean! Call start was 2012-10-03 22:27:43
# [1349303261.89] (OUTBOUND) Now updating record in /Calls/ id=386fce88-cae9-513c-1de4-506cbb69a4fa...
NAME: ** Automatický záznam **
DESCRIPTION: 
[2012-10-04 00:27:59]
! --- Event -----------------------------------------------------------
!                Event --> Dial                                              
!            Privilege --> call,all                                          
!             SubEvent --> End                                               
!              Channel --> SIP/300-00000058                                  
!             UniqueID --> 1349303261.88                                     
!           DialStatus --> ANSWER                                            
! ---------------------------------------------------------------------
[2012-10-04 00:27:59]
! --- Event -----------------------------------------------------------
!                Event --> Hangup                                            
!            Privilege --> call,all                                          
!              Channel --> SIP/300-00000058                                  
!             Uniqueid --> 1349303261.88                                     
!          CallerIDNum --> <unknown>                                         
!         CallerIDName --> realexpert_m3                                     
!     ConnectedLineNum --> +420731119303                                     
!    ConnectedLineName --> CID:                                              
!                Cause --> 16                                                
!            Cause-txt --> Normal Clearing                                   
! ---------------------------------------------------------------------
# +++ findCallByAsteriskId(1349303261.88)
! Warning, results set was empty!
[1349303261.88] FAILED TO FIND A CALL (note: there are two hangups per call, so this might not be an error)

randomf avatar Oct 04 '12 14:10 randomf

Hello,

So, yaai doesn't modify the caller id per se. It might on a click to dial in some cases.

Are you saying that after you install YAAI, when you make a call... the person that is receiving the call when they look at their phone is now different then it was before?

Do you have a custom dial plan?

blak3r avatar Oct 04 '12 19:10 blak3r

No the problem is in displaying "" in the YAII popup instead of CallerID. If I make outbound call to +420222222222 instead of displaying this number in the popup, it displays Phone: .

randomf avatar Oct 04 '12 19:10 randomf

Ok that's a yaai related issue then.

Is your asterisk box version 1.4? If you get the latest asterisk logger file from github it now detects that.

~blake

On Oct 4, 2012, at 3:15 PM, randomf [email protected] wrote:

No the problem is in displaying "" in the YAII popup instead of CallerID. If I make outbound call to +420222222222 instead of displaying this number in the popup, it displays Phone: .

— Reply to this email directly or view it on GitHub.

blak3r avatar Oct 04 '12 19:10 blak3r

Nevermind, looking at your log I see you must have 1.8 since it has ConnectedLineNum in the events.

I'm not sure off top my head. You'll have to excuse me got a migraine today.

What happens on inbound calls?

I don't think the outbound call prefix would be able to mess that up.

~blake

On Oct 4, 2012, at 3:15 PM, randomf [email protected] wrote:

No the problem is in displaying "" in the YAII popup instead of CallerID. If I make outbound call to +420222222222 instead of displaying this number in the popup, it displays Phone: .

— Reply to this email directly or view it on GitHub.

blak3r avatar Oct 04 '12 19:10 blak3r

Yes, it's 1.8. Incoming calls display just fine.

Radek

randomf avatar Oct 04 '12 19:10 randomf

I enabled logging of executed MySQL commands and found out that logger is trying to associate number to yet nonexisting call record (prior to insert). See the log.

mysql> select event_time, thread_id, argument from general_log where argument like '%asterisk_log%' and argument like '%1349381376.103%' LIMIT 100;
+---------------------+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| event_time          | thread_id | argument                                                                                                                                                                                                                                                                                  |
+---------------------+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| 2012-10-04 20:09:36 |    186799 | UPDATE asterisk_log SET CallerID='+420731119303', callstate='Dial' WHERE asterisk_id='1349381376.103'                                                                                                                                                                                     |
| 2012-10-04 20:09:36 |    186799 | INSERT INTO asterisk_log (asterisk_id, call_record_id, channel, remote_channel, callstate, direction, CallerID, timestampCall) VALUES('1349381376.103','7c137b1a-5cb7-c490-fa3c-506ded55fcd7','SIP/300-00000066','SIP/or_m3-00000067','NeedID','O','<unknown>',FROM_UNIXTIME(1349381376)) |
| 2012-10-04 20:09:39 |    186799 | SELECT direction FROM asterisk_log WHERE asterisk_id='1349381376.103' OR asterisk_dest_id='1349381376.103'                                                                                                                                                                                |
| 2012-10-04 20:09:39 |    186799 | UPDATE asterisk_log SET callstate='Connected', timestampLink=FROM_UNIXTIME(1349381379) WHERE asterisk_id='1349381376.102' OR asterisk_id='1349381376.103'                                                                                                                                 |
| 2012-10-04 20:09:52 |    186799 | SELECT direction,contact_id FROM asterisk_log WHERE asterisk_dest_id = '1349381376.103' OR asterisk_id = '1349381376.103'                                                                                                                                                                 |
| 2012-10-04 20:09:52 |    186799 | SELECT * from asterisk_log WHERE asterisk_id='1349381376.103'                                                                                                                                                                                                                             |
| 2012-10-04 20:09:52 |    186799 | UPDATE asterisk_log SET callstate='Hangup', timestampHangup=FROM_UNIXTIME(1349381392), hangup_cause=16, hangup_cause_txt='Normal Clearing' WHERE asterisk_id='1349381376.103'                                                                                                             |
+---------------------+-----------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
7 rows in set (0.01 sec)

randomf avatar Oct 04 '12 20:10 randomf

The problem can be solved by one simple if condition. When inserting into DB the destination number is in my case stored in ConnectedLineNum variable and not in CallerIDNum as asteriskLogger.php expects. Following patch is a quick & dirty fix.

diff --git a/SugarModules/modules/Asterisk/asteriskLogger.php b/SugarModules/modules/Asterisk/asteriskLogger.php
index c489fe8..98841b0 100644
--- a/SugarModules/modules/Asterisk/asteriskLogger.php
+++ b/SugarModules/modules/Asterisk/asteriskLogger.php
@@ -389,6 +389,9 @@

                    $tmpCallerID = trim($e['CallerIDNum']); //Asterisk Manager 1.0 $e['CallerID']

+                   if ($tmpCallerID == '<unknown>') {
+                       $tmpCallerID = trim($e['ConnectedLineNum']);
+                   }

                    if (startsWith($tmpCallerID,$calloutPrefix)) {
                        logLine ("  Stripping callout prefix: $calloutPrefix\n"); 

randomf avatar Oct 04 '12 21:10 randomf

Nice work. I'm really curious what is causing that to be the case on your box. There are a lot of people using asterisk 1.8 and I'm not aware of them having this issue... but I suppose it's also possible that they didn't notice or didn't care.

Any chance you could post a screenshot of how you have an extension configured? I posted an example of how mine looks here: https://github.com/blak3r/yaai/wiki/Log-Examples

blak3r avatar Oct 04 '12 22:10 blak3r

I reproduced this behavior on another box today.

I'll be adding this shortly.

blak3r avatar Oct 15 '12 07:10 blak3r

I'm going to close out my issue - this is the same problem I am having... (sorry I didn't find this sooner)

DavidBogar avatar Oct 18 '12 23:10 DavidBogar

okay not sure about your fix but here is what i needed - I'm in my first 72 Hours of working with PHP (like ever, or any programming for that matter). So Big pat on the back to me

1st I got the $tmpCallerID to finally read the outgoing number (not sure how I did that exactly, but I can paste my entire asteriskLogger.php file if requested)

I Deleted This>>>> $tmpCallerID = trim($e['CallerIDNum']); //Asterisk Manager 1.0 $e['CallerID']

Was messing up everything for me! I believe this is what was changing my $tmpCallerID variable (no clue how, I just know that was it) So I deleted it and added this (i'm sure its messy but it works!). When I echoed $tmpCallerID before that line it showed the proper callerID number. When I echoed $tmpCallerID after that it was changed! So I removed it, when i did I got the correct number, but the "1" was in front of the number. So I removed the one with this:

Personally I needed to get ride of the "1" in front of the number, so I did it with this >>>>>>>>>>>>

$tmpCallerID2 = $tmpCallerID;

function deleteFirstChar( $string ) { return substr( $string, 1 ); }

$tmpCallerID = deleteFirstChar( $tmpCallerID2 );

**Pat myself on back

I hope this helps someone else :+1:

DavidBogar avatar Oct 19 '12 01:10 DavidBogar

whooops broke my click-to-dial - so i renamed the function myfix and it works now lol

DavidBogar avatar Oct 19 '12 01:10 DavidBogar

@dbphoto84 congrats on figuring this out.

Would it be possible for you to provide a diff between your version of asteriskLogger and the stock one?

Also, please shoot me an email at http://www.blakerobertson.com/contact so I can add you to the mailing list.

blak3r avatar Oct 22 '12 18:10 blak3r

What exactly does $e correspond to? Dial Prefix? Dialin Prefix? I know this is a stupid question.

DavidBogar avatar Oct 22 '12 19:10 DavidBogar

$e is the event from Asterisk Manager. It has all the fields related to the event such as channel, destination, etc.

It's set towards the top of asteriskLogger in this code:

                $event_started = false;
                // parse the event and get the result hashtable
                $e             = getEvent($event);
                dumpEvent($e); // prints to screen

blak3r avatar Oct 23 '12 01:10 blak3r

Came across a similar issue.

In their case the fix recommended by @randomf will not work since ConnectedLineNum in this case is also "".

It's also worth noting this was on a non click to dial call.

! --- Event -----------------------------------------------------------
!                Event --> Dial
!            Privilege --> call,all
!             SubEvent --> Begin
!              Channel --> SIP/202-0000003a
!          Destination --> DAHDI/1-1
!          CallerIDNum --> 202
!         CallerIDName --> BR Test
!     ConnectedLineNum --> <unknown>
!    ConnectedLineName --> <unknown>
!             UniqueID --> 1351642223.120
!         DestUniqueID --> 1351642223.121
!           Dialstring --> g0/14102152497
! ---------------------------------------------------------------------

Workaround code I put in.

if( !empty($e['Dialstring']) ) { logLine("Overriding the caller id."); $arr = explode("/", $e['Dialstring']); $tmpCallerID = $arr[1]; logLine(" DIALSTRING CallerID override, setting it to: " . $arr[1] ); }

blak3r avatar Oct 31 '12 00:10 blak3r

This is obviously an asterisk issue... From the above looks like the callerID is the extension number. If your using freepbx there is an option somewhere in there for this.

DavidBogar avatar Oct 31 '12 00:10 DavidBogar