Summary:	ASTERISK-11838: Gtalk channel allocation fails after large number of buddy
Reporter:	Visu Kaka (visu)	Labels:
Date Opened:	2008-04-14 01:17:57	Date Closed:	2011-06-07 14:02:56
Priority:	Major	Regression?	No
Status:	Closed/Complete	Components:	Channels/chan_gtalk
Versions:		Frequency of Occurrence
Related Issues:
Environment:		Attachments:
Description:	I am running asterisk from latest trunk (Asterisk SVN-trunk-r114093M) Gtalk works fine as long as few buddies are present. As soon as number of buddies goes up, Gtalk channel allocation starts failing when making new Gtalk call ERROR[4917]: chan_gtalk.c:908 gtalk_alloc: no gtalk capable clients to talk to. I can see that Gtalk client is online, and jabber messages are flowing. I can even enter text from the Gtalk client and see that it is received by asterisk. Hence Gtalk is connected but no calls go through. System is not out of resource and asterisk is only taking few tens MB of RAM and ample of RAM is available As I mentioned, Gtalk call works fine if number of buddies are less and hence I do not see this as a setup issue. ****** ADDITIONAL INFORMATION ****** Let me know if additional information needed
Comments:	By: phsultan (phsultan) 2008-04-15 04:45:58 Hi visu, please issue the following command to check gtalk voice capabilities on buddies : *CLI> jabber show buddies Buddies connected with XMPP clients that don't have voice capabilities (eg. the gmail web interface, googletalk gadget, ..) appear as connected, but you cannot make voice calls to them. Thanks! By: Visu Kaka (visu) 2008-04-16 12:13:45 Hi Phsultan, The problem is the that it does not creates ->resources at all even. So when it iterates to find jingle capable client, it does not have any because resources are not created at all. I tried to login using Gtalk client and call still fails. Thanks Visu By: Visu Kaka (visu) 2008-04-16 12:27:54 When I do following from loaded system *CLI> jabber show buddies Buddy:  visuxxx@gmail.com        Resource: None Even thought I loggedin from Gtalk client. Interestingly, another system using different Gtalk id shows the same user jingle capable (the system having no load/limited buddies) *CLI> jabber show buddies Buddy:  visuxxx@gmail.com        Resource: Talk.v104914B51D2        node: http://www.google.com/xmpp/client/caps        version: 1.0.0.104        Jingle capable: yes        Status: 1        Priority: 24 By: phsultan (phsultan) 2008-04-16 12:27:55 Can you post the output of the 'jabber show buddies' command before and after you log in with your GoogleTalk client (please attach two files)? Sometimes you have to wait for a while before the presence information reaches Asterisk and updates the resource information. Please also post Asterisk's jabber debug messages you get when you connect with the GoogleTalk client. I'd like to see the presence messages Asterisk receives. Thanks! By: Visu Kaka (visu) 2008-04-16 12:34:12 Hi Phsultan, Below is presence message: <presence from="visuxxx@gmail.com/Talk.v104914B51D2" to="gtast@gmail.com"><priority>24</priority><c node="http://www.google.com/xmpp/client/caps" ver="1.0.0.104" ext="share-v1 voice-v1" xmlns="http://jabber.org/protocol/caps"/><x stamp="20080416T17:35:54" xmlns="jabber:x:delay"/><status/><x xmlns="vcard-temp:x:update"><photo>ff692f4053b4ce36d834a6da224d0ba71e345c0a</photo></x></presence> Thanks By: phsultan (phsultan) 2008-04-16 12:40:37 Ok do you get this presence update on both Asterisk servers? If so, what are the differences between the respectives jabber.conf files? Please post the debug output along with verbosity and debug set to 10 ('core set debug 10' and 'core set verbose 10') By: Visu Kaka (visu) 2008-04-16 13:11:22 Hi Phsultan, Status is updated on both the computers now. However, it takes really long on loaded system compared to relatively free system. I restarted the loaded system after status was changed to jingle capable and again it took long to reflect the correct status, even though both system received presence message at the same time. No additional messages in verbose/debug 10 mode Both the system are identical except that both uses different gtalk ID. Although, status is updated on both the systems now, call does not go through via loaded system. Even after status changes on loaded system and channels get allocated, call does not go though. ast_request and ast_call returns success but Gtalk never receives call. However, on non-loaded system it works fine. Thanks By: phsultan (phsultan) 2008-04-16 13:23:20 How many buddies do you handle on both systems? Have you tried to swap the gtalk IDs on you servers? If you agree, can I ssh your server to test it up? You can email me : philippe dot sultan at gmail dot com Thanks! By: Visu Kaka (visu) 2008-04-16 13:35:10 Hi Phsultan, On loaded system, buddies could be close to thosand or sometime even more. On non-loades system, maximum 4 buddies. I will have to take permission to get access so let me get back to you but in mean time I will be happy to provide any information you need. When I issue on loaded system *CLI>gtalk show channels I can see that the is channel estabilised. But call never received by gtalk client (happens only on loaded system). Thanks Visu By: Visu Kaka (visu) 2008-04-16 14:15:19 Hi Phsultan, As I can see, on loaded system, when client logs out, it still maintain the resources. While on non loaded system, the resources become none and it works fine. So when client login again, loaded system now has two resources (old and new). So when during finding the roster ID, first one which is not valid gets picked up and call never goes through. I yet to understand why call fails on loaded system when there is single resources In anycase, gtalk call does not go though once system is loaded. SIP call works fine. Let me know if more information required. Thanks By: phsultan (phsultan) 2008-04-17 03:14:50 Ok, as resources are dynamically attributed by Google's XMPP server, that can explain the problem. Do you actually receive the presence updates that reflect the login/logout processes on time, or are they delayed for some reason? If those packets are not processed by Asterisk, that's definitely a bug. You should actually see verbose and debug messages on the console output (stating for example 'JABBER: Handling paktype PRESENCE'). Also, can you test on an intermediate loaded system (eg. between 4 and thousands of contacts :)) ? Thanks! By: Visu Kaka (visu) 2008-04-17 05:28:07 Hi Phsultan, As I can see after turning on jabber debug (jabber set debug on) that both the system are receiving messages almost simultaneously. However, somehow loaded system is unable to process it on time. Currently, I can see processing verbose messages but at times I do not see any. Occasionally, one more phenomena occurs on loaded system quite frequently that it goes offline for 3-4 seconds and than again comes online. And this happens quite often. Systems are on reliable 100MB public network. Let me know if more information required. Thanks By: phsultan (phsultan) 2008-04-17 05:32:16 Are the resources updated then when the presence packets are processed? If so, can you place a call to the proper resource? By: Visu Kaka (visu) 2008-04-17 07:17:00 yes, resources are update if packets are processed but as I mentioned, there is a significant delay in add and remove so sometime old resources are present. We modified code a little bit to pickup the latest resource having jaingle cpabilities but it's kind of hack. Another thing as I mentioned, status of gtalk id used in asterisk. It often changes to offline for 3-4 seconds and than comes online again. Thanks Visu By: Digium Subversion (svnbot) 2008-04-17 08:37:14 Repository: asterisk Revision: 114198 U   branches/1.4/res/res_jabber.c ------------------------------------------------------------------------ r114198 | phsultan | 2008-04-17 08:37:12 -0500 (Thu, 17 Apr 2008) | 2 lines Use keepalives effectively in order diagnose bug ASTERISK-11838. ------------------------------------------------------------------------ http://svn.digium.com/view/asterisk?view=rev&revision=114198 By: Digium Subversion (svnbot) 2008-04-17 08:41:19 Repository: asterisk Revision: 114199 _U  trunk/ U   trunk/res/res_jabber.c ------------------------------------------------------------------------ r114199 | phsultan | 2008-04-17 08:41:18 -0500 (Thu, 17 Apr 2008) | 10 lines Merged revisions 114198 via svnmerge from https://origsvn.digium.com/svn/asterisk/branches/1.4 ........ r114198 | phsultan | 2008-04-17 15:42:23 +0200 (Thu, 17 Apr 2008) | 2 lines Use keepalives effectively in order diagnose bug ASTERISK-11838. ........ ------------------------------------------------------------------------ http://svn.digium.com/view/asterisk?view=rev&revision=114199 By: Digium Subversion (svnbot) 2008-04-17 08:49:58 Repository: asterisk Revision: 114200 _U  branches/1.6.0/ U   branches/1.6.0/res/res_jabber.c ------------------------------------------------------------------------ r114200 | phsultan | 2008-04-17 08:49:57 -0500 (Thu, 17 Apr 2008) | 18 lines Merged revisions 114199 via svnmerge from https://origsvn.digium.com/svn/asterisk/trunk ................ r114199 | phsultan | 2008-04-17 15:46:17 +0200 (Thu, 17 Apr 2008) | 10 lines Merged revisions 114198 via svnmerge from https://origsvn.digium.com/svn/asterisk/branches/1.4 ........ r114198 | phsultan | 2008-04-17 15:42:23 +0200 (Thu, 17 Apr 2008) | 2 lines Use keepalives effectively in order diagnose bug ASTERISK-11838. ........ ................ ------------------------------------------------------------------------ http://svn.digium.com/view/asterisk?view=rev&revision=114200 By: phsultan (phsultan) 2008-04-17 08:52:34 Ok, can you update to latest trunk revision, and turn keepalives off (keepalive=no in jabber.conf)? The keepalives sent every minute by Asterisk are certainly unnecessary in your case. By: Digium Subversion (svnbot) 2008-04-17 12:30:50 Repository: asterisk Revision: 114214 _U  team/group/multiparking/ U   team/group/multiparking/CHANGES U   team/group/multiparking/Makefile U   team/group/multiparking/apps/app_chanspy.c U   team/group/multiparking/apps/app_externalivr.c U   team/group/multiparking/apps/app_festival.c U   team/group/multiparking/apps/app_ices.c U   team/group/multiparking/apps/app_mp3.c U   team/group/multiparking/apps/app_nbscat.c U   team/group/multiparking/apps/app_zapras.c U   team/group/multiparking/channels/chan_sip.c U   team/group/multiparking/channels/chan_zap.c U   team/group/multiparking/configs/sip.conf.sample U   team/group/multiparking/doc/CODING-GUIDELINES A   team/group/multiparking/doc/chan_sip-perf-testing.txt U   team/group/multiparking/include/asterisk/app.h U   team/group/multiparking/include/asterisk/astobj2.h A   team/group/multiparking/include/asterisk/dlinkedlists.h U   team/group/multiparking/include/asterisk/dsp.h U   team/group/multiparking/include/asterisk/frame.h U   team/group/multiparking/include/asterisk/lock.h U   team/group/multiparking/include/asterisk/logger.h U   team/group/multiparking/include/asterisk/sched.h U   team/group/multiparking/main/app.c U   team/group/multiparking/main/asterisk.c U   team/group/multiparking/main/astobj2.c U   team/group/multiparking/main/dsp.c U   team/group/multiparking/main/event.c U   team/group/multiparking/main/frame.c U   team/group/multiparking/main/logger.c U   team/group/multiparking/main/sched.c U   team/group/multiparking/main/utils.c U   team/group/multiparking/res/res_agi.c U   team/group/multiparking/res/res_jabber.c U   team/group/multiparking/res/res_musiconhold.c A   team/group/multiparking/tests/test_dlinklists.c U   team/group/multiparking/utils/Makefile A   team/group/multiparking/utils/refcounter.c ------------------------------------------------------------------------ r114214 | mvanbaak | 2008-04-17 12:30:47 -0500 (Thu, 17 Apr 2008) | 189 lines Merged revisions 114172,114174-114175,114181-114183,114185,114187-114188,114190,114192,114194,114196,114199,114201-114202,114205,114208,114212 via svnmerge from https://origsvn.digium.com/svn/asterisk/trunk ................ r114172 | murf | 2008-04-16 19:14:18 +0200 (Wed, 16 Apr 2008) | 1 line Introducing doubly linked lists to trunk from branch team/murf/bug11210. ................ r114174 | qwell | 2008-04-16 19:31:02 +0200 (Wed, 16 Apr 2008) | 14 lines Blocked revisions 114173 via svnmerge ........ r114173 | qwell | 2008-04-16 12:30:09 -0500 (Wed, 16 Apr 2008) | 7 lines Fix "fallthrough" behavior here, so config options in a previously configured user don't override settings in general. (closes issue ASTERISK-11863) Reported by: tzafrir Patches:      chanzap_users_sections.diff uploaded by tzafrir (license 46) ........ ................ r114175 | murf | 2008-04-16 19:45:28 +0200 (Wed, 16 Apr 2008) | 1 line Introducing various astobj2 enhancements, chief being a refcount tracing feature, and various documentation updates in astobj2.h, and the addition of standalone utility, refcounter, that will filter the trace output for unbalanced, unfreed objects. This comes from the team/murf/bug11210 branch. ................ r114181 | tilghman | 2008-04-16 22:00:27 +0200 (Wed, 16 Apr 2008) | 10 lines Blocked revisions 114180 via svnmerge ........ r114180 | tilghman | 2008-04-16 14:59:37 -0500 (Wed, 16 Apr 2008) | 3 lines Backport revisions for latest vpb drivers to 1.4 (Closes issue ASTERISK-11862) ........ ................ r114182 | murf | 2008-04-16 22:09:39 +0200 (Wed, 16 Apr 2008) | 1 line Introducing a small upgrade to the ast_sched_xxx  facility, to keep it from eating up lots of cpu cycles. See CHANGES. From the team/murf/bug11210 branch. ................ r114183 | murf | 2008-04-16 22:28:08 +0200 (Wed, 16 Apr 2008) | 1 line Introducing a small optimization to event_unsubscribe; events now use a Doubly-Linked list for events, gives fast deletions, for the sake of channel driver mwi events. From team/murf/bug11210. ................ r114185 | kpfleming | 2008-04-16 22:47:30 +0200 (Wed, 16 Apr 2008) | 14 lines Merged revisions 114184 via svnmerge from https://origsvn.digium.com/svn/asterisk/branches/1.4 ........ r114184 | kpfleming | 2008-04-16 15:46:38 -0500 (Wed, 16 Apr 2008) | 6 lines use the ZT_SET_DIALPARAMS ioctl properly by initializing the structure to all zeroes in case it contains fields that we don't write values into (which it does as of Zaptel 1.4.10) (closes issue ASTERISK-11861) Reported by: fnordian ........ ................ r114187 | murf | 2008-04-16 22:54:41 +0200 (Wed, 16 Apr 2008) | 1 line A small enhancement-- I added the routine log_show_lock to utils.c, which if the mentioned lock has been acquired, this routine will log to the console the normal info about that lock you'd see from the CLI when you do a 'core show locks'. It's solely for debug-- if the lock is NOT acquired, there is no output. I use it to show 'unexpected' locks, to see where/why a lock is pre-locked. This command is to be called from points of interest, like just before a trylock, and helps to spot fleeting, highly temporal locks that normally are not locked... ................ r114188 | tilghman | 2008-04-17 00:57:54 +0200 (Thu, 17 Apr 2008) | 2 lines Standardized routines for forking processes (keeps all the specialized code in one place). ................ r114190 | murf | 2008-04-17 01:53:27 +0200 (Thu, 17 Apr 2008) | 1 line This is the scariest commit I've done in a long time. This is the astobj2-ification of chan_sip. I've tested a number of scenarios like crazy. It used to have 4x the call setup/teardown performance of trunk, but now it's roughly at parity. I will attempt to find the bottlenecks and get it back to the 4x mark. The changes made were somewhat invasive, but the value to the community of these upgrades outweighs waiting further for more testing. Every change being made to chan_sip was lousing this code up when we tried to merge. Peers, Users, Dialogs, are all now astobj2 objects, indexed via hashtables. Refcounting is used to track objects and free them at the bitter end of their lives. Please file issues on bugs.digium.com, and PLEASE, please, please be patient. One natural advantage to all the hash-table work is that loading large sip.conf files full of thousands of peers now goes much faster. One more please: PLEASE help thrash this code and test it. ................ r114192 | seanbright | 2008-04-17 12:55:05 +0200 (Thu, 17 Apr 2008) | 9 lines Merged revisions 114191 via svnmerge from https://origsvn.digium.com/svn/asterisk/branches/1.4 ........ r114191 | seanbright | 2008-04-17 06:51:20 -0400 (Thu, 17 Apr 2008) | 1 line Make sure we have enough room for the recording's filename. ........ ................ r114194 | seanbright | 2008-04-17 14:25:23 +0200 (Thu, 17 Apr 2008) | 1 line Update the CHANGES file with yesterday's ChanSpy change.  Sorry Kevin, just saw your e-mail. ................ r114196 | tilghman | 2008-04-17 14:59:04 +0200 (Thu, 17 Apr 2008) | 16 lines Merged revisions 114195 via svnmerge from https://origsvn.digium.com/svn/asterisk/branches/1.4 ........ r114195 | tilghman | 2008-04-17 07:56:38 -0500 (Thu, 17 Apr 2008) | 8 lines Add special case for when the agi cannot be executed, to comply with the documentation that we return failure in that case. (closes issue ASTERISK-11866) Reported by: fmueller Patches:       20080416__bug12462.diff.txt uploaded by Corydon76 (license 14) Tested by: fmueller ........ ................ r114199 | phsultan | 2008-04-17 15:46:17 +0200 (Thu, 17 Apr 2008) | 10 lines Merged revisions 114198 via svnmerge from https://origsvn.digium.com/svn/asterisk/branches/1.4 ........ r114198 | phsultan | 2008-04-17 15:42:23 +0200 (Thu, 17 Apr 2008) | 2 lines Use keepalives effectively in order diagnose bug ASTERISK-11838. ........ ................ r114201 | murf | 2008-04-17 16:45:16 +0200 (Thu, 17 Apr 2008) | 1 line Thanks to snuff for finding these omissions ................ r114202 | tilghman | 2008-04-17 17:12:52 +0200 (Thu, 17 Apr 2008) | 2 lines fileio.h does not exist; io.h does, though. ................ r114205 | russell | 2008-04-17 18:25:29 +0200 (Thu, 17 Apr 2008) | 11 lines Merged revisions 114204 via svnmerge from https://origsvn.digium.com/svn/asterisk/branches/1.4 ........ r114204 | russell | 2008-04-17 11:23:45 -0500 (Thu, 17 Apr 2008) | 3 lines Fix the bininstall target to install from subdirs, as well. (closes issue AST-8, patch from bmd at switchvox) ........ ................ r114208 | mmichelson | 2008-04-17 18:40:12 +0200 (Thu, 17 Apr 2008) | 20 lines Merged revisions 114207 via svnmerge from https://origsvn.digium.com/svn/asterisk/branches/1.4 ........ r114207 | mmichelson | 2008-04-17 11:28:03 -0500 (Thu, 17 Apr 2008) | 12 lines It was possible for a reference to a frame which was part of a freed DSP to still be referenced, leading to memory corruption and eventual crashes. This code change ensures that the dsp is freed when we are finished with the frame. This change is very similar to a change Russell made with translators back a month or so ago. (closes issue ASTERISK-11443) Reported by: destiny6628 Patches:      11999.patch uploaded by putnopvut (license 60) Tested by: destiny6628, victoryure ........ ................ r114212 | mmichelson | 2008-04-17 18:51:09 +0200 (Thu, 17 Apr 2008) | 11 lines Blocked revisions 114211 via svnmerge ........ r114211 | mmichelson | 2008-04-17 11:50:46 -0500 (Thu, 17 Apr 2008) | 4 lines Add prototype for ast_dsp_frame_freed. I'm not sure how this was compiling before... ........ ................ ------------------------------------------------------------------------ http://svn.digium.com/view/asterisk?view=rev&revision=114214 By: phsultan (phsultan) 2008-05-06 04:51:39 Hi visu, did you turn the keepalives off on Asterisk? Does it have any positive effect? Thanks for your feedback. By: phsultan (phsultan) 2008-05-22 16:55:12 Closing, no feedback from reporter for more than a month. Please reopen if you still experience this bug, after having tried what's been proposed to fix the bug.