SoS non-responsive when watching a large number of builds

[pvandervelde]

I've connected SoS to our buildservers, one TFS one (200ish build definitions), the other one Jenkins (10 build jobs). Now the UI just sits there trying to reload all the builds. It never seems to finish repainting itself.
The task manager shows the memory usage slowly growing and the UI is unresponsive to user interaction.

I'd remove some of the builds to see if the responsiveness gets better but I can't figure out where the configuration data is stored.

[lprichar]

Well the configuration data is stored at: C:\Users[username]\AppData\Local\Automated Architecture\SirenOfShame. That's the easy part.

As far as responsiveness, I believe others are doing TFS with 200ish builds, so I'm wondering if the addition of Jenkins is killing it or if I'm just misremembering. Please do write back with your findings.

[pvandervelde]

Ok so I deleted all the projects and then only added TFS projects. I added 50 build definitions first. And at the moment the main UI of SoS is flickering due to the rapid updates (CPU at 100%). It looks like it's going over all the builds trying to find the users and assigning them points for builds that happened in the past?

It seems that this behaviour only happens when looking at the main page. As soon as a user gets an achievement and the UI switches away from the main page to the user page the CPU drops and everything is fine again.

I've set the update interval to 60 seconds but that doesn't seem to make any difference.

[pvandervelde]

Also running this against TFS2013. Not sure if that makes a difference

[lprichar]

Using 2.3.3? How does it do against a single build definition? Also, is it git based or traditional tfs source control?

[pvandervelde]

Using 2.3.3 against traditional TFS 2013. It seems pretty happy with a single build definition. No UI updates going on. No excessive increase in memory usage either.

The only thing I just noticed is that I happen to have selected a running build. The icon for the build said it was started 8 minutes ago. Then at some point the UI updated and suddenly the build was started 2 minutes ago. It looks like that might be due to the fact that there are currently two instances of this build running. Once CI build and one manually triggered one. Normally that shouldn't happen very much but TFS doesn't seem to stop it from happening so I guess that's something to maybe take into account?

[pvandervelde]

Just tried with a few more builds, this time carefully selected to be the ones pointing to the developer main branch (i.e the branch that the developers commit to) and the main release branch. Sitting at 45 projects at the moment and going ok. Will try adding more obscure projects on monday when I get back to work.

[lprichar]

The multiple builds theory could be the problem. It could also like you said be a more obscure project doing something I didn't account for. I really appreciate you helping to track it down. I wish there was more I could do to help.

btw the build dates issue you mentioned may be Issue #21. Basically sos normally uses the local computer's datetime to determine when a build last fired to compute the 2 minutes ago. But when it first starts up it could have been off for weeks, so it's local cache is wrong. Instead it uses what the server gave it for the last build date, hoping that is more accurate. Unfortunately in cases where the server is in a different time zone or has a different clock setting that can make the dates look wrong until the next build occurs. Still not sure how to solve that problem.

[pvandervelde]

No worries. I'll check again on monday. If nothing else I can always grab the source and debug it from there. Hopefully it won't need to come to that though :)

[pvandervelde]

I tried again and managed to add lots of builds early this morning and everything went ok. I then started from scratch and with about 40 builds in the list I got it to go nuts again. I attached the debugger and from a quick look it seems that the issue is with the RulesEngine.TimerTick method. If there are builds in progress it refreshes the screen (seems sensible). However it does this every second (the timer ticks over every second) and it refreshes all the items on the screen. I think in our case it takes longer than a second to refresh the screen so every time it's done a refresh it refreshes again. Note that my poll interval is set to 30 seconds.

Also noted something else weird but I've opened another issue for that.

[pvandervelde]

This seems to be the same issue as with #16. That one looks to be timer related too.

[lprichar]

Nice find! So ideally it would update only the build that changed rather than refreshing all of them. That totally makes sense. It shouldn't be too hard to implement either, but I won't be able to get to it this week. If all goes as planned I should be able to get back to this next week. Thanks again so much @pvandervelde for helping track that one down!

[lprichar]

p.s. Nice, I bet you're right about #16, that's been bugging me.

[pvandervelde]

You're more than welcome. I hope it helps. I don't have time otherwise I could have put in a PR :(

[scullinan]

Any update on this fix at all?

[lprichar]

It's literally next in my queue. Should have some action on it soon.

[lprichar]

I've taken a stab at this by limiting the UI to displaying the most recent 50 builds on the main build list, and fixing an issue when clearing all items where I wasn't suspending drawing. It made things better for me, although even at 200 builds performance wasn't too bad. Can you please try out 2.3.5 and let me know if it helps: http://sirenofshame.com/Downloads/View?downloadId=23.

[pvandervelde]

Just installed it. Not sure if this issue is fixed because SoS is losing connection to the TFS server every 30-60 seconds. It then reconnects 30-60 seconds later and redraws the whole UI.

After leaving it up for a bit the whole display still refreshes constantly, even when it stays connected (at least the build panels keep their build failure mode colors)

[pvandervelde]

Oh and that's for 36 builds

[lprichar]

Hey @pvandervelde Are you in full screen mode or regular? If regular can you easily determine if ViewBuilds.CreateControlsAndAddToPanels() is getting called frequently? I should have added some logging there, and I still can, but theoretically that should only get called when a new build is added, removed, or the app first starts.

[pvandervelde]

I will have a look now. VS debugger to the rescue .... :)

[pvandervelde]

Oh and that was in normal mode but not hiden in the system tray if that makes sense.

[pvandervelde]

Yup that still gets called each time the screen refreshes. The stack I'm seeing is:

SirenOfShame.exe!SirenOfShame.ViewBuilds.CreateControlsAndAddToPanels(System.Collections.Generic.IEnumerable<SirenOfShame.Lib.Watcher.BuildStatusDto> buildStatusDtos) Line 244 C#

SirenOfShame.exe!SirenOfShame.ViewBuilds.RefreshBuildStatuses() Line 120 C#
SirenOfShame.exe!SirenOfShame.ViewBuilds.RefreshBuildStatuses(SirenOfShame.Lib.Watcher.RefreshStatusEventArgs args) Line 111 C#
SirenOfShame.exe!SirenOfShame.MainForm.RulesEngineRefreshRefreshStatus.AnonymousMethod__7() Line 282 C#
SirenOfShame.Lib.dll!SirenOfShame.Lib.Helpers.ControlHelpers.Invoke(System.Windows.Forms.Control ctrl, System.Action a) Line 58 C#
SirenOfShame.Lib.dll!SirenOfShame.FormBase.Invoke(System.Action a) Line 16 C#
SirenOfShame.exe!SirenOfShame.MainForm.RulesEngineRefreshRefreshStatus(object sender, SirenOfShame.Lib.Watcher.RefreshStatusEventArgs args) Line 279 C#
SirenOfShame.Lib.dll!SirenOfShame.Lib.Watcher.RulesEngine.InvokeRefreshStatus(System.Collections.Generic.IEnumerable<SirenOfShame.Lib.Watcher.BuildStatus> buildStatuses) Line 333 C#
SirenOfShame.Lib.dll!SirenOfShame.Lib.Watcher.RulesEngine.TimerTick(object sender, System.EventArgs e) Line 340 C#
[External Code]
SirenOfShame.exe!SirenOfShame.Program.RealMain(string[] args) Line 57 C#
SirenOfShame.exe!SirenOfShame.Program.Main(string[] args) Line 27 C#

Looks like ViewBuilds.RemoveAllChildControlsIfBuildCountOrBuildNamesChanged removes the controls because in my case the buildStatusDtosAndControl.Count = 51 and buildStatusDtos.Count = 39. Not entirely sure what that means though.

If there's anything else you want me to look at let me know.

[pvandervelde]

Oh and and a question about ViewBuilds.RefreshBuildStatuses.

_lastBuildStatusDtos = args.BuildStatusDtos
.OrderByDescending(i => i.LocalStartTime)
.Take(50)
.ToList();
if (!Visible) return;
RefreshBuildStatuses();

If the window isn't visible you do you still need to update the list?

[lprichar]

Right, no need to update if minimized, good point. Changing from 51 found builds to 39 and then probably back again. Are you watching multiple servers by chance?

[pvandervelde]

Nope just a single one. The odd thing is that I'm only watching 36 different build definitions. So neither 51 nor 39 makes sense to me

[lprichar]

So this is beginning to sound like a TFS issue. At this point I'm inclined to shift focus to MyBuildServer.GetBuildStatuses(). I hate to keep asking more of you, but I only have access to a pretty simple TFS server. Could you please put a breakpoint at the end of GetBuildStatuses() and see if how many items buildStatuses contains? I would normally expect it to contain 36 items, but in your case I'm guessing it will return 51 some times and 39 others. If so can you tell me if you 36 url's are being passed in under buildDefinitionsQuery?

Thank you again so much for your help in tracking this down @pvandervelde I can't tell you how much I appreciate your help.

[pvandervelde]

Ok so I did that and I think I have it figured out. Well sort of. The numbers I got back were 24 and 13. It turns out that I had selected 24 builds from one project collection and 13 from another project collection. I can only guess that one of these builds hasn't build anything because otherwise I'd have to be seeing 37 builds.

Note that both project collections live on the same TFS server. I'll try this again with one project collection and see what happens.

[pvandervelde]

Running with one project collection seems to make it quiet down. The display doesn't refresh insanely anymore and everything is ticking along fine. I wonder how well it works if I now throw the Jenkins server back in.

[lprichar]

Got it! I was able to reproduce! Thanks so much @pvandervelde, that was exactly what I needed. Hopefully I'll be able to get a fix out to you shortly.

[pvandervelde]

Glad to be of service :) Can't wait to put all our TFS and Jenkins builds in SoS so that I don't have to have several notifiers running anymore. One notifier to display all our build failures :)

[lprichar]

I haven't verified the above fix works while watching Jenkins and TFS yet, but it should fix the issue of watching builds that exist in different project collections. If @pvandervelde you could please verify and write back I'd appreciate it. Let me know if you'd like an install package.

[pvandervelde]

I'll do that tomorrow morning (it's evening in NZ now, no access to the work machine). I'll just grab the latest code from GitHub, no need to build a package just yet.

[pvandervelde]

It seems to work now although there is another issue that I'm seeing if I have a TFS server with 2 collections and a Jenkins server. It looks like there are builds missing from the display. I can file another issue for that if you want though.

[lprichar]

Yes please, if you don't mind creating a separate issue. Probably 34 comments is enough for one issue :). So glad we've made some progress on this one, thanks again for all your help.

[pvandervelde]

Added the separate issue. Will add more comments on monday from the work machine if I remember.

[lprichar]

fyi published this in 2.3.6 http://sirenofshame.com/Downloads/View?downloadId=24