| 00:00.13 | *** join/#asterisk-dev Qwell (north@asterisk/developer/Qwell) |
| 00:00.13 | *** mode/#asterisk-dev [+o Qwell] by ChanServ |
| 03:22.13 | *** join/#asterisk-dev mjordan (mjordan@nat/digium/x-ukdzezoysbrjggfd) |
| 03:22.13 | *** mode/#asterisk-dev [+o mjordan] by ChanServ |
| 03:33.11 | *** join/#asterisk-dev leedm777 (~leedm777@50-81-28-152.client.mchsi.com) |
| 05:10.05 | *** join/#asterisk-dev Kobaz (~kobaz@its.kobaz.net) |
| 05:34.06 | *** join/#asterisk-dev mjordan (~mjordan@75.76.55.191) |
| 05:34.06 | *** mode/#asterisk-dev [+o mjordan] by ChanServ |
| 07:07.39 | *** join/#asterisk-dev oej (~Adium@h87-96-134-129.dynamic.se.alltele.net) |
| 07:07.40 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 08:15.30 | *** join/#asterisk-dev moy (sid47040@gateway/web/irccloud.com/x-xaehgjrvxufwfiwm) |
| 08:17.49 | *** join/#asterisk-dev tonyclewis (sid6025@gateway/web/irccloud.com/x-bazfrduocvijfszg) |
| 08:28.01 | *** join/#asterisk-dev tzafrir (~tzafrir@local.xorcom.com) |
| 08:28.01 | *** mode/#asterisk-dev [+o tzafrir] by ChanServ |
| 12:04.20 | *** join/#asterisk-dev oej (~Adium@h87-96-134-129.dynamic.se.alltele.net) |
| 12:04.20 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 13:55.17 | *** join/#asterisk-dev oej (~Adium@h87-96-134-129.dynamic.se.alltele.net) |
| 13:55.17 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 14:01.55 | *** join/#asterisk-dev oej (~Adium@h87-96-134-129.dynamic.se.alltele.net) |
| 14:01.55 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 14:45.38 | *** join/#asterisk-dev mjordan (~mjordan@75.76.55.191) |
| 14:45.38 | *** mode/#asterisk-dev [+o mjordan] by ChanServ |
| 16:06.15 | *** join/#asterisk-dev oej (~Adium@h87-96-134-129.dynamic.se.alltele.net) |
| 16:06.15 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 16:29.48 | *** join/#asterisk-dev [TK]D-Fender (~joe@64.235.216.2) |
| 17:00.49 | *** join/#asterisk-dev oej (~Adium@h87-96-134-129.dynamic.se.alltele.net) |
| 17:00.49 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 17:26.16 | *** join/#asterisk-dev mjordan (~mjordan@75.76.55.191) |
| 17:26.16 | *** mode/#asterisk-dev [+o mjordan] by ChanServ |
| 18:31.47 | *** join/#asterisk-dev oej (~Adium@h87-96-134-129.dynamic.se.alltele.net) |
| 18:31.47 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 19:48.39 | *** join/#asterisk-dev mjordan (~mjordan@75.76.55.191) |
| 19:48.39 | *** mode/#asterisk-dev [+o mjordan] by ChanServ |
| 19:54.05 | mjordan | Hm. Format attributes make things tricky. |
| 19:57.16 | file | burn them |
| 20:03.52 | *** join/#asterisk-dev Synthase_ (uid63346@gateway/web/irccloud.com/x-nmcsxvprazcumwad) |
| 20:11.14 | mjordan | I'm just wondering if we've hampered ourselves too much by worrying about an edge case |
| 20:11.30 | mjordan | The real problem comes when you have to use a frame to determine format equality with a format on a channel |
| 20:11.47 | mjordan | you almost want to say "tell me if these things are equal, and oh by the way, I don't care about anything other than the raw type" |
| 20:12.03 | mjordan | if you could somehow put that on a frame, and keep formats as they are on channels, it'd probably work. |
| 20:12.51 | file | that's what happens - is the pointer the same? is the codec id the same? is there an interface - does it say its the same? |
| 20:14.01 | mjordan | well, except that in the case of a format on a frame, we can probably skip the last part |
| 20:14.16 | mjordan | and, if we disregard format attributes, we really don't need formats to be ref counted |
| 20:14.26 | mjordan | as all formats can be represented by formats in the cache, which are effectively static |
| 20:14.32 | file | yes |
| 20:14.36 | mjordan | it's when formats have attributes that they become ephemeral |
| 20:14.44 | file | if you disregard format attributes then it's much easier |
| 20:14.57 | mjordan | tis a hard problem |
| 20:15.05 | mjordan | Maybe it should be two objects? |
| 20:15.23 | mjordan | as in, completely separate |
| 20:15.29 | file | actually... |
| 20:15.38 | file | what if you could know if a format is cached or not? |
| 20:15.42 | mjordan | hm |
| 20:15.56 | *** join/#asterisk-dev oej (~Adium@h87-96-134-129.dynamic.se.alltele.net) |
| 20:15.56 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 20:15.57 | mjordan | the problem is I want to avoid any checks on a format in the critical path |
| 20:16.16 | mjordan | i.e., if you have to test to see whether or not you need to ref bump, then it's already too late |
| 20:17.16 | mjordan | it we did split up a format into its core component and its attributes (which is already the case, just hidden), and a channel stored both on itself, then we could keep the format attributes ref counted and de-ref count (or at least not as much) the actual format object |
| 20:17.40 | mjordan | I hesitate to do any of this, given how much fun this was the *last* time around |
| 20:18.07 | file | it feels like we're just moving the problem around |
| 20:18.23 | file | trying to chase something that may not be achievable |
| 20:18.50 | mjordan | I'm not sure I feel that way just yet |
| 20:20.15 | *** join/#asterisk-dev oej (~Adium@h87-96-134-129.dynamic.se.alltele.net) |
| 20:20.15 | *** mode/#asterisk-dev [+o oej] by ChanServ |
| 20:22.38 | mjordan | The more I think about things, the more I think that if we're in the critical path, we want to avoid ref counting. Not if it isn't necessary mind you, but each atomic increment has to bypass the cache to ensure atomicity |
| 20:23.41 | file | if you know you are in the critical path and that which exists in the critical path holds refs elsewhere... then it's doable |
| 20:24.20 | file | if you escape it and something is deferred, that's where it would go wrong |
| 20:24.41 | mjordan | yup |
| 20:25.02 | mjordan | in this case, if the only reason a format has to be ref bumped are attributes, and frames don't really care about attributes, then it may work to separate those two concepts out slightly |
| 20:25.16 | mjordan | or |
| 20:25.42 | mjordan | we could have a function that assigns to a frame the 'core' format - which is the cached version - on frames. |
| 20:25.46 | mjordan | maybe. |
| 20:25.50 | mjordan | I'll play around with it some. |
| 20:25.55 | file | how would you separate them out? |
| 20:26.38 | mjordan | well, if you *know* that a frame only has a cached variant on it, then you can eschew ref counting |
| 20:26.56 | mjordan | the problem comes when you invoke comparison functions, which often happens on every frame read in a channel driver |
| 20:27.13 | mjordan | there, you want it to return True if you have two formats that have the same "core type" but different attributes |
| 20:27.20 | mjordan | which is not the case if you take two channels and compare them |
| 20:27.31 | mjordan | i.e. |
| 20:27.45 | mjordan | ast_cmp_format(frame, channel) => Ignore attributes |
| 20:27.53 | mjordan | ast_cmp_format(channel, channel) => Don't ignore attributes |
| 20:28.12 | file | ah |
| 20:28.32 | mjordan | True was a bad word, "Equal" |
| 20:29.00 | file | mjordan, if you hack in non reffing... how does that impact things? |
| 20:29.11 | mjordan | well, at first, we'll just leak memory like a sieve |
| 20:29.25 | mjordan | so I'll do that first to see what the impact on performance really is |
| 20:29.30 | mjordan | if it buys us only 1%, meh |
| 20:29.44 | mjordan | I'll test it in a bit, just compiled a new check out. |
| 20:29.45 | file | if you aren't using stuff with attributes it won't, they are cached |
| 20:29.51 | mjordan | true |
| 20:30.03 | mjordan | and I'm not, this should just be g722 or ulaw (whatever SIPp decides it can emulate) |
| 20:30.08 | mjordan | er |
| 20:30.12 | mjordan | nm, g722 |
| 20:30.30 | mjordan | looks at code |
| 20:34.46 | coreyfarrell | mjordan: If you do hack non-reffing into format stuff, I'd like to see an 'ao2_fake_ref' that would normally do nothing. have that macro write something to the refs log when REF_DEBUG is enabled. |
| 20:35.18 | mjordan | coreyfarrell: when would you invoke it? |
| 20:35.40 | coreyfarrell | instead of removing ao2_ref(fmt, +1), change it to ao2_fake_ref(fmt, +1) |
| 20:35.44 | mjordan | ah. |
| 20:35.54 | mjordan | Right now I just want to see if this is even worth it |
| 20:36.20 | mjordan | I did some profiling last night and saw the ao2_bump called during ast_frdup via ast_translate show up higher than I'd like |
| 20:36.26 | mjordan | but it may be that this doesn't really buy us much |
| 20:37.31 | coreyfarrell | that's fine.. if it does buy us something I'd like to see that we have a way to troubleshoot bugs that it causes... |
| 20:41.08 | mjordan | sure |
| 20:41.15 | coreyfarrell | so I'm trying to fix some of the testsuites that leave channels open. http://pastebin.ubuntu.com/10131238/ has 'core show channels' right before it tries 'core stop gracefully'. strange thing is that priority 3 doesn't exist in context dial-alice. |
| 20:41.27 | coreyfarrell | am I looking at some weird bug in pbx.c or app_dial? adding a call to Hangup() for priority 3 fixes the test, but seems like the wrong way to handle it. |
| 20:42.29 | coreyfarrell | this is against asterisk 11, haven't tested against 13/trunk |
| 20:50.37 | mjordan | hm. That bought about 7.6% |
| 20:50.55 | file | ooh |
| 20:51.17 | mjordan | file: yeah, just removing the ao2_bump in frame.c |
| 20:51.24 | mjordan | granted, that's only 2 minutes of perf samples |
| 20:51.35 | mjordan | and I should probably re-run last night's, but it looks significant on first pass |
| 20:51.55 | mjordan | coreyfarrell: if it's an outbound channel, you can't always trust the priority |
| 20:52.09 | mjordan | it may be the priority of what it thinks would be the next thing it would go off and execute if it went back to dialplan |
| 20:52.34 | mjordan | I'm going to re-run it again |
| 20:55.16 | mjordan | file: in the gprof output, that pushed ast_frdup/ast_translate both a bit lower. We also spend more time in waitstream_core, which makes sense |
| 20:55.30 | file | nods |
| 20:59.10 | coreyfarrell | ok I just figured it out.. when n+1 doesn't exist after Dial, auto-fallthrough runs pbx_builtin_busy(c, "10"). that holds the channel open longer than the shutdown timeout. |
| 21:00.13 | mjordan | file: I was worried for a second - the original 13 did much better. Than I realized I had optimization still enabled. |
| 21:00.15 | mjordan | whoops |
| 21:00.21 | mjordan | even with optimization, it only performed 1% better |
| 21:00.39 | mjordan | comparing apples to apples: tricky |
| 21:00.57 | mjordan | coreyfarrell: huh. I had no idea. |
| 21:01.06 | mjordan | makes sense. That way you get the tone. |
| 21:02.14 | mjordan | goes to re-run this stuff again |
| 21:38.54 | mjordan | so, that's disappointing |
| 21:39.07 | mjordan | I don't think it really made any difference. Or at least, not enough to say with certainty |
| 21:39.26 | mjordan | CPU bounces all over the place, and on average, it looks about the same both with and without the ref bump. Which doesn't make a lot of sense. |
| 21:40.50 | coreyfarrell | mjordan: how many calls to ao2_ref with / without your changes? |
| 21:40.54 | mjordan | no idea |
| 21:40.59 | mjordan | looks |
| 21:42.29 | mjordan | 19239039 (without) vs. 4225282 (with changes) |
| 21:42.44 | mjordan | hm. |
| 21:42.54 | mjordan | let me make sure I'm comparing the right two outputs, as that's larger than I'd think |
| 21:45.28 | mjordan | yeah, this doesn't make much sense. |
| 21:45.32 | mjordan | sighs |
| 21:46.01 | mjordan | Somehow, there are more calls to internal_ao2_ref in the branch with modifications. I suspect things are wonky. |
| 21:46.19 | mjordan | this is why when people quote performance comparisons to me, I get very suspicious. |
| 21:46.47 | coreyfarrell | is gprof as accurate as callgrind for counting calls? |
| 21:46.50 | *** join/#asterisk-dev leedm777 (~leedm777@50-81-28-152.client.mchsi.com) |
| 21:53.56 | *** join/#asterisk-dev mjordan (~mjordan@75.76.55.191) |
| 21:53.56 | *** mode/#asterisk-dev [+o mjordan] by ChanServ |
| 21:53.59 | mjordan | granted, both of these are running on my laptop |
| 21:54.13 | mjordan | which has other stuff running |
| 21:54.17 | mjordan | so it isn't as "clean" as I'd like |
| 21:54.25 | coreyfarrell | you're using gprof? |
| 21:54.49 | mjordan | yeah |
| 21:54.59 | mjordan | I could remove gprof, as I really don't need this for the CPU usage. |
| 21:56.08 | coreyfarrell | I don't remember does gprof determine exact number of calls to functions? |
| 21:56.27 | mjordan | it tries to |
| 21:58.05 | coreyfarrell | I often use callgrind instead of gprof since it doesn't require rebuild and it gets exact counts |
| 21:58.26 | mjordan | yeah, I just know callgrind slows things down a lot |
| 21:58.35 | mjordan | really, I'm probably trying to compare too many things, and skewing things as a result |
| 21:59.07 | coreyfarrell | does gprof allow you to produce a 'per thread' report? |
| 21:59.35 | mjordan | maybe - I just used the default flat/call-graph report |
| 22:00.24 | coreyfarrell | sometimes per thread can be useful since you can find the thread that ran a specific call |
| 22:02.09 | mjordan | yeah. I've used callgrind for that in the past. Right now I'm just trying to see if removing the ao2_bumps from frame.c make any real difference. |
| 22:02.15 | mjordan | runs again |
| 22:03.31 | coreyfarrell | startup / shutdown functions have a big influence on the total results when you're only doing a couple test calls |
| 22:11.44 | mjordan | yeah |
| 22:12.00 | mjordan | I'm running for 6 minutes, with only taking measurement once 100 simultaneous calls at 10cps are sustained |
| 22:12.14 | mjordan | and the measurements are taken after startup/before shutdown |
| 22:16.51 | mjordan | blech. No real difference. |
| 22:17.03 | mjordan | interesting, and weird. |
| 22:24.04 | *** join/#asterisk-dev leedm777 (~leedm777@50-81-28-152.client.mchsi.com) |