[Home]

Summary:ASTERISK-10052: [have fix] Transfers stopped working when migrating from 1.4.9 to 1.4.10
Reporter:Atis Lezdins (atis)Labels:
Date Opened:2007-08-09 03:47:44Date Closed:2007-08-14 10:12:17
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Resources/res_features
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 0010415_console_output.txt
Description:I use SIP and Zap channels, and when switching from version 1.4.9 to 1.4.10 transfers stopped working.

Solution was to unmerge changes in res_features.c (ASTERISK-9976).

2007-07-30 17:11 +0000 [r77768-77778]  Joshua Colp <jcolp@digium.com>

       * res/res_features.c: (closes issue ASTERISK-9976) Reported by: kkiely
         Instead of directly mucking with the extension/context/priority
         of the channel we are transferring when it has a PBX simply call
         ast_async_goto on it. This will ensure that the channel gets
         handled properly and sent to the right place.



****** ADDITIONAL INFORMATION ******

[Aug  9 02:00:08] VERBOSE[12077] logger.c:     -- Started music on hold, class 'default', on SIP/21169-ac330de0
[Aug  9 02:00:08] VERBOSE[12077] logger.c:     -- <SIP/21168-00dc62e0> Playing 'pbx-transfer' (language 'en')
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Update SQL: UPDATE sip_buddies SET ipaddr = '192.168.0.37', port = '5060', regseconds = '1186650188', username = '90044' WHERE name = '90044'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Updated 1 rows on table: sip_buddies
[Aug  9 02:00:08] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '90044'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '90035'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '90041'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Update SQL: UPDATE sip_buddies SET ipaddr = '192.168.0.37', port = '5060', regseconds = '1186650188', username = '90041' WHERE name = '90041'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Updated 1 rows on table: sip_buddies
[Aug  9 02:00:08] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '90041'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '90029'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Update SQL: UPDATE sip_buddies SET ipaddr = '192.168.0.37', port = '5060', regseconds = '1186650188', username = '90029' WHERE name = '90029'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Updated 1 rows on table: sip_buddies
[Aug  9 02:00:08] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '90029'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '21120'
[Aug  9 02:00:08] DEBUG[4847] db.c: Unable to find key '21120' in family 'SIP/Registry'
[Aug  9 02:00:08] DEBUG[4847] db.c: Unable to find key '21120' in family 'SIP/Registry'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '90035'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Update SQL: UPDATE sip_buddies SET ipaddr = '192.168.0.37', port = '5060', regseconds = '1186650188', username = '90035' WHERE name = '90035'
[Aug  9 02:00:08] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Updated 1 rows on table: sip_buddies
[Aug  9 02:00:08] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:08] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '90035'
[Aug  9 02:00:11] VERBOSE[12077] logger.c:     -- Stopped music on hold on SIP/21169-ac330de0
[Aug  9 02:00:11] VERBOSE[12077] logger.c:     -- Transferring SIP/21169-ac330de0 to '21114' (context transfer) priority 1
[Aug  9 02:00:11] ERROR[12077] cdr_addon_mysql.c: cdr_mysql: Unknown connection error: (2006) MySQL server has gone away
[Aug  9 02:00:11] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:11] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '21168'
[Aug  9 02:00:11] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:11] DEBUG[4837] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '21169'
[Aug  9 02:00:11] DEBUG[4837] db.c: Unable to find key '21169' in family 'SIP/Registry'
[Aug  9 02:00:11] DEBUG[12077] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
[Aug  9 02:00:11] DEBUG[12077] 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,userfield) VALUES ('2007-08-09 02:00:03','\"device\" <21169>','21169','21114','transfer', 'SIP/21169-ac330de0','SIP/21168-00dc62e0','Dial','SIP/21168|25|gtM(agent_call_answer^21168)',8,7,'ANSWERED',3,'1186650003.17006','#call_id=1186650003.17006-1#agent=21168#t_id=2#s_type=agent#s_num=21169#s_id=70')
[Aug  9 02:00:12] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Everything is fine.
[Aug  9 02:00:12] DEBUG[4847] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sip_buddies WHERE name = '21120'
[Aug  9 02:00:12] DEBUG[4847] db.c: Unable to find key '21120' in family 'SIP/Registry'
[Aug  9 02:00:12] DEBUG[4847] db.c: Unable to find key '21120' in family 'SIP/Registry'
Comments:By: Joshua C. Colp (jcolp) 2007-08-10 08:43:14

What is the exact callflow that is causing it to fail? Dialplan involved? Complete console output? Dial arguments?
By: Atis Lezdins (atis) 2007-08-10 10:05:41

For example:

1) SIP/90090 dials SIP/90220

Dial(SIP/90220|25|gtM(agent_call_answer^21167))

2) SIP/90220 transfers to SIP/90221 (by using blindxfer from features.conf).

Both channels hungs up without any messages in log/console.

Providing dialplan would be quite complex for me - i believe you can read affected dialplan from console output, but if you need it - ask me, ill try to create test case.

Console output goes in attached file.
Here goes SIP config (from mysql realtime) for 90090/90220/90221 (basically the same)

*************************** 1. row ***************************
           id: 601
       ext_id: 34648
         name: 90090
  accountcode: NULL
     amaflags: NULL
    callgroup: NULL
     callerid: device <90090>
  canreinvite: no
      context: default-sip
    defaultip: NULL
     dtmfmode: rfc2833
     fromuser: NULL
   fromdomain: NULL
  fullcontact: NULL
         host: dynamic
     insecure: NULL
     language: NULL
      mailbox: 90090@device
    md5secret: NULL
          nat: yes
         deny: NULL
       permit: NULL
         mask: NULL
  pickupgroup: NULL
         port: 5060
      qualify: no
  restrictcid: NULL
   rtptimeout: NULL
rtpholdtimeout: NULL
       secret: xxxxx
         type: friend
     username: 90090
     disallow:
        allow: all
  musiconhold: NULL
   regseconds: 1186797160
       ipaddr: 81.198.164.2
     regexten:
cancallforward: yes
       setvar:
By: jiddings (jiddings) 2007-08-13 11:47:26

I had a similar problem, calls that came into a queue and then were transfered would be dropped. Reverting to res_features.c from 1.4.9 also fixed the problem for us.

Thanks!
By: Digium Subversion (svnbot) 2007-08-14 10:09:27

Repository: asterisk
Revision: 79397

------------------------------------------------------------------------
r79397 | file | 2007-08-14 10:09:26 -0500 (Tue, 14 Aug 2007) | 4 lines

(closes issue ASTERISK-10052)
Reported by: atis
Revert fix for ASTERISK-9976 as it causes more issues then it solves.

------------------------------------------------------------------------
By: Digium Subversion (svnbot) 2007-08-14 10:12:17

Repository: asterisk
Revision: 79403

------------------------------------------------------------------------
r79403 | file | 2007-08-14 10:12:16 -0500 (Tue, 14 Aug 2007) | 12 lines

Merged revisions 79397 via svnmerge from
https://origsvn.digium.com/svn/asterisk/branches/1.4

........
r79397 | file | 2007-08-14 12:27:13 -0300 (Tue, 14 Aug 2007) | 4 lines

(closes issue ASTERISK-10052)
Reported by: atis
Revert fix for ASTERISK-9976 as it causes more issues then it solves.

........

------------------------------------------------------------------------