18:06:47 <SotK> #startmeeting storyboard
18:06:48 <openstack> Meeting started Thu Jul 16 18:06:47 2020 UTC and is due to finish in 60 minutes.  The chair is SotK. Information about MeetBot at http://wiki.debian.org/MeetBot.
18:06:49 <openstack> Useful Commands: #action #agreed #help #info #idea #link #topic #startvote.
18:06:51 <openstack> The meeting name has been set to 'storyboard'
18:07:15 <SotK> #link https://wiki.openstack.org/wiki/Meetings/StoryBoard Agenda-ish
18:07:43 <SotK> I don't think there's any announcements or migration updates, so lets go straight to in-progress
18:07:56 <SotK> #topic In Progress Work
18:08:00 <fungi> yes! eager to hear what performance insights you've gleaned
18:12:11 <diablo_rojo> As am I :)
18:12:33 <SotK> I didn't actually get round to generating a dataset comparable to the production db yet (my test data currently has 10000 stories, compared with the 28138 reported by storyboard.o.o)
18:13:19 <fungi> it's within the same order of magnitude
18:13:24 <SotK> indeed
18:13:58 <SotK> as memory serves the worst query we have (according to the old log) was the general story browsing one
18:14:14 <fungi> in aggregate, yes
18:14:39 <SotK> which is approximately this: http://paste.openstack.org/show/796021/
18:15:31 <fungi> multiple joins in a nested query
18:16:24 <SotK> on my test data that takes ~100ms to execute
18:16:43 <diablo_rojo> Yeah that matches my recollections as well
18:17:27 <SotK> part of the problem is the ORDER BY, since story_summary is the massive subquery rather than an actual table, there's no useful index there
18:18:12 <fungi> oh, right
18:18:25 <SotK> moving that into the filtered_stories subquery maintains the ordering in the result, and gets the time down to ~80ms
18:18:54 <diablo_rojo> Step in the right direction.
18:19:07 <fungi> a 20% improvement is nothing to sneeze at, but may also not be a noticeable speedup on human timescales
18:21:08 <SotK> indeed, so I then moved the filtering that currently lives in filtered_stories into the story_summary subquery, removing the big join
18:21:24 <fungi> that seems like it should have far greater impact
18:21:49 <SotK> yeah, that got it down to ~14ms
18:21:54 <fungi> yowza
18:22:20 <fungi> i'm always dubious of subqueries anyway, and that's a great illustration of why
18:22:24 <diablo_rojo> Holy moly.
18:25:41 <SotK> so the hard part is going to be working out how best to get SQLAlchemy to emit that query using the ORM
18:26:14 <fungi> how/where in the code is it currently built?
18:26:44 <SotK> the `story_summary` subquery comes from https://opendev.org/opendev/storyboard/src/branch/master/storyboard/db/models.py#L465-L490
18:27:21 <SotK> then the rest is https://opendev.org/opendev/storyboard/src/branch/master/storyboard/db/api/stories.py#L73-L134
18:28:15 <SotK> the `_story_build_query` function called in that second link constructs the `filtered_stories` subquery
18:31:13 <fungi> so basically need to dereference what _story_build_query() is doing i guess
18:31:54 <fungi> mordred: ^  if you're around, can you suggest an orm-friendly alternative to how that's been designed?
18:32:08 <SotK> I think really we just need to stop using StorySummary entirely
18:32:48 <fungi> oh, right, we talked about that
18:32:51 <SotK> or at least come up with a way to filter it directly and efficiently rather than joining to a filtered set of IDs
18:33:19 <fungi> basically just replace it with a custom search, and then we can optimize the hell out of search instead
18:33:32 <SotK> yeah
18:34:03 <SotK> the main thing it provides is ability to aggregate the task statuses in the ORM directly
18:34:20 <fungi> which we already identified need to be done differently too
18:34:47 <fungi> because showing "active" stories for a project with no active tasks in those stories is counter-intuitive and probably not what the user wants anyway
18:35:27 <SotK> aha, I hadn't even considered that aspect
18:35:57 <SotK> yeah, we'll be able to do that much more easily in a rewritten way
18:38:15 <diablo_rojo> Seems like a good way to go to me.
18:38:30 <diablo_rojo> Heh yeah that makes a lot of sense
18:39:04 <SotK> I'll continue work in that direction then
18:39:26 <SotK> hopefully I should have a patch up for that before next week's meeting
18:39:57 <SotK> my first attempt didn't work even slightly as intended, but did a good job to testing out my laptop's fans
18:40:41 <diablo_rojo> Lol a nice little space heater?
18:41:09 <fungi> or white noise generator
18:41:30 <fungi> SotK: thanks for working on that!
18:42:02 <diablo_rojo> Yes thank you so much for all your hard work on that.
18:42:03 <fungi> i started looking back over what i might have done wrong with the swift acls in rackspace for storyboard-dev's attachments, but so far no real insights
18:42:11 <diablo_rojo> People will be ecstatic when we get that merged.
18:42:28 <SotK> yeah it should improve quality of life quite a lot hopefully
18:42:46 <fungi> i think it's plumbed correctly in the sb config because i'm getting a permission failure rather than something else like auth failure or connection error
18:43:35 <fungi> i think my next step is going to be trying to use client tools to write to the container
18:43:39 <SotK> it'd be nice to test it on storyboard-dev when I do get a patch up, to get an idea of the kind of improvement we get on a still bigger db
18:43:48 <SotK> fungi: that would be my recommendation, yeah
18:43:52 <fungi> and see if i can debug by repeating the same things sb is trying to do
18:45:01 <fungi> on query optimization, i wonder how we can identify what the slowdown is for rendering automatic boards/worklists
18:45:36 <fungi> while not as frequently called as the story summary pages, those are the most noticeably slow views
18:46:03 <SotK> agreed, I think that's what I'll investigate next
18:46:04 <diablo_rojo> Aside from search yeah
18:46:08 <fungi> but i'm not sure what queries are at fault, or if it's an only moderately slow query getting called an explosive number of times
18:46:22 <diablo_rojo> I could see that
18:47:25 <SotK> I suspect StorySummary is somewhat to blame there too
18:48:34 <fungi> oh, could that be getting called to get data for the cards?
18:49:14 <fungi> but also, more generally, as we optimize the more commonly called queries we free up resources so other queries don't have to compete for cpu/io
18:50:02 <diablo_rojo> That would be nice if it was two birds with one stone so to speak
18:50:22 <SotK> yeah, we use it in the filters because we want to support filtering by story status
18:51:01 <SotK> the code there is pretty questionable in general I think, there should be plenty of room for improvement
18:51:59 <SotK> (there is nothing worse than reading your own old code :D)
18:52:15 <diablo_rojo> LOL yep.
18:52:21 <diablo_rojo> Made sense at the time though I imagine
18:52:31 <SotK> haha, it always does
18:53:10 <fungi> i always think of it as hatemail my past self sent me
18:56:09 <SotK> #topic Open Discussion
18:56:11 <SotK> anything else?
18:56:21 <fungi> not on my end
18:56:49 <diablo_rojo> Nothing from me either.
18:57:24 <diablo_rojo> ..aside from apologizing for not being all that helpful lately.
18:58:37 <SotK> no need to apologise :)
18:58:59 <SotK> anyway, time for me to make dinner, thank you for the meeting!
18:59:09 <fungi> thanks SotK!
18:59:11 <SotK> #endmeeting