| 00:16.20 | *** join/#asterisk-dev infobot (ibot@c-174-52-60-165.hsd1.ut.comcast.net) |
| 00:16.20 | *** topic/#asterisk-dev is Take the March 2019 Asterisk User Survey! https://goo.gl/forms/xL1VUHRsf95saly13 -- Asterisk Development Discussion -=- http://www.asterisk.org/developers -=- Tier 2 and 3.14159265 support is in #asterisk -=- Check out our blog! blogs.asterisk.org -=- Follow on Twitter at @AsteriskDev |
| 06:21.18 | *** join/#asterisk-dev CELYA_ (~Thunderbi@2a01:e0a:d:1111:b749:768d:ed77:7c9a) |
| 06:39.44 | *** join/#asterisk-dev jkroon (~jkroon@41.183.141.208) |
| 06:59.09 | *** join/#asterisk-dev jkroon (~jkroon@41.113.32.246) |
| 07:50.26 | *** join/#asterisk-dev jkroon (~jkroon@41.113.32.246) |
| 08:16.35 | *** join/#asterisk-dev pchero_work (~pchero@87.213.247.82) |
| 08:18.44 | *** join/#asterisk-dev jkroon_ (~jkroon@41.113.32.246) |
| 08:53.25 | *** join/#asterisk-dev jkroon (~jkroon@41.183.141.202) |
| 09:04.19 | *** join/#asterisk-dev hehol (~hehol@gatekeeper.loca.net) |
| 09:14.45 | *** join/#asterisk-dev jkroon (~jkroon@41.113.19.199) |
| 11:28.02 | *** join/#asterisk-dev pc-m (~pcm@modemcable094.94-70-69.static.videotron.ca) |
| 12:37.34 | *** join/#asterisk-dev jkroon (~jkroon@41.113.19.199) |
| 13:25.32 | *** join/#asterisk-dev Corydon76 (~quassel@96.69.98.139) |
| 13:25.32 | *** mode/#asterisk-dev [+o Corydon76] by ChanServ |
| 13:31.52 | *** join/#asterisk-dev scgm11_ (~scgm11@r186-50-173-196.dialup.adsl.anteldata.net.uy) |
| 14:07.22 | *** join/#asterisk-dev bford (uid283514@gateway/web/irccloud.com/x-vbtmszokhpvnybai) |
| 14:07.22 | *** mode/#asterisk-dev [+o bford] by ChanServ |
| 14:37.42 | *** join/#asterisk-dev kharwell (uid358942@gateway/web/irccloud.com/x-moivzjqczmfxkoxc) |
| 14:37.42 | *** mode/#asterisk-dev [+o kharwell] by ChanServ |
| 14:47.21 | *** join/#asterisk-dev jkroon (~jkroon@165.16.203.101) |
| 15:22.18 | *** join/#asterisk-dev CELYA_ (~Thunderbi@2a01:e0a:d:1111:b749:768d:ed77:7c9a) |
| 15:29.05 | seanbright | gtjoseph: did you use svn bisect to figure that out? |
| 15:29.09 | seanbright | or intuition? |
| 15:29.09 | *** join/#asterisk-dev pchero_work (~pchero@87.213.247.82) |
| 15:29.46 | file | he narrowed it down to connection reuse, and went from there |
| 15:29.50 | seanbright | gotcha |
| 15:29.54 | seanbright | i approve |
| 15:35.46 | *** join/#asterisk-dev scgm11_ (~scgm11@r186-50-173-196.dialup.adsl.anteldata.net.uy) |
| 15:36.46 | coreyfarrell | does anyone know if the stasis_cache leak is serious? |
| 15:37.14 | file | stasis_cache leak? |
| 15:37.20 | file | do you mean the sorcery cache leak? |
| 15:37.24 | seanbright | ASTERISK-28523 |
| 15:37.26 | seanbright | i assume |
| 15:37.48 | file | kharwell is working on it, dunno yet |
| 15:39.06 | coreyfarrell | I'm finding a leak in stasis_cache.c that happens with autoload=no, so probably not sorcery cache? testing against head of 13. |
| 15:39.47 | coreyfarrell | haven't determined if it's a one-time leak or if it can pile up. |
| 15:41.52 | file | I believe there are circumstances where things aren't removed from the stasis cache but to be a leak requires specific circumstances like one time use endpoints |
| 15:48.24 | bford | is someone here familiar with the app_queue code? specifically, penalties and what their purpose is in a ringall strategy? |
| 15:48.43 | coreyfarrell | I think https://github.com/asterisk/asterisk/blob/13/main/stasis_cache.c#L873 is leaking the return value of cache_remove? in the !is_remote path anyhow cache_remove steals and returns the reference to cached_entry->local |
| 16:02.34 | file | coreyfarrell: I think so? |
| 16:03.12 | coreyfarrell | well I'm running the testsuite with ao2_cleanup on the result of cache_remove at line 873, going to see if that causes any problems. it's resolved a leak that happened for every test, going to let the full testsuite run to see if it causes any crashes. |
| 16:17.44 | seanbright | bford: i would assume that penalties don't affect ringall... but that might make too much sense |
| 16:28.59 | *** join/#asterisk-dev pc-m (~pcm@cable-66-129-132-216.b2b2c.ca) |
| 16:55.29 | *** join/#asterisk-dev scgm11_ (~scgm11@r186-50-173-196.dialup.adsl.anteldata.net.uy) |
| 17:13.41 | bford | seanbrght: that's what i was thinking too |
| 17:13.41 | bford | i commented out the line of code that was calculating the metric for RINGALL based on weight and my scenario started working, but that code change was done in 2003 by mark spencer and the commit message was this: |
| 17:13.42 | bford | "Do the right thing with ringall queues with entries that have penalties" |
| 17:13.54 | bford | based on penalty* |
| 17:14.16 | seanbright | which line specifically? |
| 17:16.31 | bford | line 5605 (ish, my comments may throw that off) |
| 17:16.35 | bford | tmp->metric = mem->penalty * 1000000 * usepenalty; |
| 17:16.37 | bford | usepenalty was added later |
| 17:17.49 | bford | the comment above is "/* Everyone equal, except for penalty */" |
| 17:18.31 | seanbright | well then there is this |
| 17:18.31 | seanbright | https://github.com/asterisk/asterisk/blob/master/apps/app_queue.c#L4678-L4681 |
| 17:19.35 | seanbright | yeah i don't get it |
| 17:19.53 | coreyfarrell | lame.. my cache_remove cleanup patch caused all of tests/apps/voicemail/polling/* except tests/apps/voicemail/polling/poll_no_subs to assert so something must be holding an unclaimed reference to that object. |
| 17:20.23 | seanbright | bford: might be interesting to look at it in context of app_queue when mspencer added that line |
| 17:21.09 | coreyfarrell | gtjoseph / rmudgett: git blame tells me to ask if you have any ideas/thoughts |
| 17:21.14 | seanbright | and github can't do a blame because that file is ridonkulous |
| 17:25.22 | bford | seanbright: yep, i was looking at that too... i don't get why "best metric" is used for RINGALL |
| 17:26.04 | bford | may be worth shooting an email to users list and see how people are using penalties in RINGALL and what they expect to happen if i can't make heads or tails of this logic |
| 17:31.23 | seanbright | so in 465a7518, the way that 'best' was calculated was different |
| 17:31.28 | seanbright | it was calculated as you went |
| 17:32.52 | seanbright | ok... so here is what it is doing |
| 17:33.21 | seanbright | it was ringing people in "groups" by penalty |
| 17:33.44 | seanbright | so if you have 5 people with penalty 10, 5 with 20, and 5 with 30 |
| 17:34.03 | seanbright | it's going to ring them 5 at a time in ascending penalty order |
| 17:34.12 | seanbright | at least that is what i am getting from looking at 465a7518 |
| 17:34.52 | seanbright | BUT app_queue is bad and it should feel bad. so i could be wrong. |
| 17:35.30 | bford | lol that would make sense, im curious how that penalty actually kicks in then and triggers the different "groups" |
| 17:35.44 | seanbright | i think this may have been before autofill was even implemented |
| 17:36.11 | bford | at least, when MAX_QUEUE_PENALTY is in effect, it doesn't seem to do anything |
| 17:36.24 | seanbright | that's quite possible |
| 17:37.35 | bford | ill have to do some more digging, i don't think removing that line is the correct fix if grouping by penalty is possible |
| 17:37.55 | seanbright | i am basing my assessment off of looking at 16 year old code |
| 17:38.16 | bford | unfortunately, that's all we have :D |
| 17:38.30 | seanbright | but i think the loop in ring_one() is finding the "best" metric, ringing everyone with that metric, and then finding the next best metric and repeating that over and over. |
| 17:39.11 | seanbright | and it filters out the previous people it tried by seeing if they are already ringing (have a non-NULL 'chan') |
| 17:40.22 | bford | right. the problem im experiencing is incrementing the MAX_QUEUE_PENALTY is not allowing additional agents to be called that now fit the criteria, which may be trampled on by what you mentioned |
| 17:40.58 | bford | at least in a RINGALL strategy, from what I've tested |
| 17:41.42 | seanbright | well, if it doesn't work... setting 'tmp->metric = 42' if ringall is probably an adequate change |
| 17:42.37 | bford | it sounds too good to be true haha |
| 17:45.40 | kharwell | gtjoseph: re-running my test with your gerrit patch and appears memory is still climbing for me. |
| 17:46.03 | kharwell | at least the pjsip pool allocations continue to rise as well as the resident memory |
| 17:48.52 | kharwell | the memory growth does however to have seemed to have lessened a bit though |
| 17:49.11 | kharwell | meaning it's not rising as fast, but still rising |
| 17:55.23 | kharwell | I do keep getting a number of the following on the receiving side: https://pastebin.com/Z5J8bTv3 |
| 17:55.40 | kharwell | Which then results in the following on the sending (UUT) side: https://pastebin.com/2y6wZCJs |
| 18:21.53 | seanbright | i wish there were some good visualization tools in debuggers |
| 18:22.24 | seanbright | like if you could right-click on an address offset and say "view as pointer" |
| 18:22.35 | seanbright | but alas. |
| 19:32.56 | gtjoseph | seanbright: you can do that in the eclipse debugger |
| 19:49.01 | seanbright | fancy |
| 19:49.06 | seanbright | will check it out |
| 20:35.57 | coreyfarrell | I figured out why fixing the leak caused a frack. res_pjsip_mwi.c had an unneeded ao2_ref(topic, -1) since 13.26.0. not sure what happens in 17+ though, ast_mwi_topic() isn't used anymore. guess I have to run the testsuite against 17 as well to see if that also has issues after the leak is fixed. |
| 21:09.05 | kharwell | mwi core, and mwi related functionality in app_voicemail were reworked in 17 to make way for the eventual removal of the stasis cache from those backends. We added a new stasis_state mechanism that is kind a combination of stasis cache and stasis pool |
| 21:09.22 | *** join/#asterisk-dev pc-m (~pcm@cable-66-129-132-216.b2b2c.ca) |
| 21:27.45 | coreyfarrell | kharwell: yeah I'm digging in that. fixed one leak in stasis_state.c so far but still looking for the larger one |
| 21:29.01 | kharwell | It seems to be leak week in Asterisk |
| 21:41.28 | coreyfarrell | kharwell: got a minute? I think I'm looking at a circular reference in stasis_state, want to make sure I'm not missing something simple before I go down the weakproxy path. |
| 21:49.10 | kharwell | yeah where ya looking? |
| 21:49.54 | coreyfarrell | https://github.com/asterisk/asterisk/blob/17/main/stasis_state.c#L319-L320 - manager->states is owned by manager |
| 21:49.58 | coreyfarrell | https://github.com/asterisk/asterisk/blob/17/main/stasis_state.c#L211 - state->manager is owned by state |
| 21:50.00 | coreyfarrell | https://github.com/asterisk/asterisk/blob/17/main/stasis_state.c#L239 - state is linked into manager->states |
| 21:54.01 | coreyfarrell | kharwell: hmmm actually I think it's leaking because AST_VECTOR_SIZE(&state->eids) != 0 in state_remove, once this happens I don't think it can ever be released? |
| 21:54.03 | kharwell | hrm yeah that was a tricky one when thinking about it. |
| 21:55.09 | kharwell | but I think the manager->states one should be okay. I'd have to think more on it again. I think I even built it in the unit test to check to make sure the ref count got eventually to zero |
| 21:56.03 | kharwell | yeah if that vector's size doesn't go to zero then the state wont' be released |
| 21:57.22 | kharwell | but add/remove of eid should eventually clear it. See stasis_state_remove_publish_by_id |
| 21:58.29 | coreyfarrell | it leaks in tests/channels/pjsip/subscriptions/nat_notify, doesn't look like stasis_state_remove_publish_by_id is being run |
| 21:58.37 | file | unless the user of the API isn't doing that, which would then be a problem there |
| 21:58.48 | kharwell | ya what file said |
| 21:59.31 | kharwell | every call to "stasis_state_publish_by_id" should eventually be matched to a call to "stasis_state_remove_publish_by_id" |
| 21:59.48 | coreyfarrell | ah ok was just going to ask that :) |
| 21:59.49 | kharwell | well for a given eid |
| 22:00.31 | kharwell | sorry kinda take a little back. You should be able to call "stasis_state_publish_by_id" multiple times. But once you call it once you eventually have to call "stasis_state_remove_publish_by_id" |
| 22:01.06 | coreyfarrell | so stasis_state_publish_by_id is find_or_create and remove_publish is destroy? |
| 22:01.25 | kharwell | I think so yeah basically |
| 22:06.31 | kharwell | one place it would be known to leak is if "stasis_state_topic" was called directly before the topic was created via one of the other methods |
| 22:07.03 | kharwell | the ability to get a topic like that was left that way for legacy reasons if I recall |
| 22:07.32 | kharwell | Although in master 17 at the time now that I think about it we could have maybe removed it |
| 22:08.06 | kharwell | aah it might have been a "we were going to get to it" as it was maybe going to require refactoring more modules |
| 22:09.24 | kharwell | or maybe not? It appears it's only called from ast_mwi_topic and searching the code for that method I am not seeing any place it's called |
| 22:09.52 | kharwell | nvm I see it now. It's in app_minivm |
| 22:10.16 | kharwell | prob not it either then |
| 22:11.32 | coreyfarrell | the only calls to stasis_state_publish_by_id are via ast_publish_mwi_state_full, the only calls to stasis_state_remove_publish_by_id are via ast_delete_mwi_state_full |
| 22:11.49 | coreyfarrell | app_voicemail is the only caller to ast_delete_mwi_state_full :( |
| 22:12.44 | coreyfarrell | oddly enough app_voicemail never calls ast_publish_mwi_state_full. res_corosync, res_pjsip_publish_asterisk and res_xmpp do call it. so probably res_pjsip_publish_asterisk creating the eid? |
| 22:13.27 | coreyfarrell | hmmm I might have missed macros :( |
| 22:14.20 | coreyfarrell | yeah definitely missed macros |
| 22:14.29 | kharwell | outbound publishing would have to be enabled for it to start publishing things |
| 22:16.01 | kharwell | looking at the test and dependencies it might be in res_mwi_external |
| 22:17.08 | kharwell | it eventually calls delete, but only if the sorcery observer delete callback is raised |
| 22:21.44 | coreyfarrell | running `git grep -e ast_publish_mwi_state -e ast_delete_mwi_state` does not give very good looking results - from what I can tell this covers all calls into stasis_state publish/remove_publish by_id. |
| 22:28.56 | coreyfarrell | for that specific test you're probably right that the test needs to run the AMI command MWIDelete so not really a leak in asterisk there. |
| 22:30.46 | kharwell | I think the reasoning at the time was to do things in steps towards the removal of the stasis cache altogether. Eventually even reworking device state too |
| 22:31.36 | kharwell | Some things were left knowing they essentially would leak objects, but unless I am wrong it shouldn't be any different than before as the mwi api should not really have nor how some things called it. |
| 22:31.56 | kharwell | and that those things leaking now would be the same as those leaking before |
| 22:32.27 | kharwell | since they never called "ast_delete_mwi_state_full" and were not ever removed from the stasis cache |
| 22:32.46 | kharwell | at the time voicemail was the most problematic so went that route first |
| 22:34.22 | coreyfarrell | well for now I think I'm just going to post the simple fixes to 17 |
| 22:37.56 | kharwell | yeah makes sense. Thanks for looking into these! |