Performance

Case number:954892-2005677
Topic:Developer Preview
Opened by:LociOiling
Status:Open
Type:Bug
Opened on:Tuesday, September 4, 2018 - 04:27
Last modified:Wednesday, September 12, 2018 - 23:40

The new devprev release seems a bit sluggish at times, so I tried
comparing 20180829-6ed3ad0d20-win_x86-devprev to 20180725-d14dae34c3-win_x86.

On puzzle 1567, I used Rav3n_pl Fuzes v1.5.5 with medium wiggle power.

Starting with a score of 15,345, I ran main and devprev three times, each time increasing the wiggle factor setting used by the recipe. (The Foldit wiggle power setting was medium for all three tests.)

While devprev had a slightly higher score each time, it also took longer.

Interestingly, wiggle factor 4 produced slightly better results than wiggle factor 5, but only by a fraction.

The table below summarizes the results, showing the gain, elapsed time (in hours), and point per hour (PPH) for each test.

While devprev seems a little slower based on this limited testing, the results don't seem to explain the sluggishness I was seeing in 1567. The symptoms included it being difficult to freeze structures by double-clicking on them, an very slow performance in some recipes.

settings main devprev
run wiggle factor gain hours PPH gain hours PPH
1 2 1816.293 0.5 3628.554 1816.86 0.603 3008.599
2 4 1820.476 0.658 2766.447 1820.801 0.807 2254.861
3 5 1820.172 0.662 2748.581 1820.662 0.823 2209.839
(Tue, 09/04/2018 - 04:27  |  10 comments)


LociOiling's picture
User offline. Last seen 3 hours 24 min ago. Offline
Joined: 12/27/2012
Groups: Beta Folders

Sorry that the table is hard to read -- somehow the border attribute didn't get applied to the data rows.

You can copy the table above and paste into a spreadsheet to see the data in a better format.

I'll figure out the table issue tomorrow and post again.

LociOiling's picture
User offline. Last seen 3 hours 24 min ago. Offline
Joined: 12/27/2012
Groups: Beta Folders

Here's an attempt at a more readable table.

settings main devprev
run __ wiggle factor __ gain __ hours __ PPH __ gain __ hours __ PPH __
1 __ 2 __ 1816.293 __ 0.5 __ 3628.554 __ 1816.86 __ 0.603 __ 3008.599 __
2 __ 4 __ 1820.476 __ 0.658 __ 2766.447 __ 1820.801 __ 0.807 __ 2254.861 __
3 __ 5 __ 1820.172 __ 0.662 __ 2748.581 __ 1820.662 __ 0.823 __ 2209.839 __

Kind of ugly, but maybe a bit more readable than before. Seems like something needs to be updated in Drupal-land.

jflat06's picture
User offline. Last seen 6 hours 35 min ago. Offline
Joined: 09/29/2010
Groups: Window Group

Does this happen in non symmetry puzzles?

LociOiling's picture
User offline. Last seen 3 hours 24 min ago. Offline
Joined: 12/27/2012
Groups: Beta Folders

The non-symmetry puzzles seem to be performing normally, but I haven't tried a similar test. I'll do something similar with the current revisiting puzzle and post the results here.

jflat06's picture
User offline. Last seen 6 hours 35 min ago. Offline
Joined: 09/29/2010
Groups: Window Group

This might be related to the fix for the asymmetry problem. I'll see if I cant improve the performance a bit.

LociOiling's picture
User offline. Last seen 3 hours 24 min ago. Offline
Joined: 12/27/2012
Groups: Beta Folders

I did some further testing on puzzle 1571, with the solution "1571 performance test base" that's shared with scientists.

I again ran Fuzes on both main and devprev, 10 times each on low and high wiggle power. I set the recipe's wiggle factor to 2 on low wiggle power, and 4 on high wiggle power.

Devprev was just slightly slower on low wiggle power, a 4.65% increase over main. Main actually had a higher average gain by a small fraction.

On high wiggle power, devprev was 11.67% slower, but the average gain was over 13 points higher.

I don't see these differences as being significant, since there seemed to be a mix of slower runs and faster runs. A little bad luck may have skewed the results. I notice that the first devprev run took 9.66 minutes, about 1.5 minutes longer than the next highest time. I'd need to run a lot more tests to conclude there's really a difference.

No table this time, but a spreadsheet-ready CSV file (just drop the .txt) for those who are interested.

LociOiling's picture
User offline. Last seen 3 hours 24 min ago. Offline
Joined: 12/27/2012
Groups: Beta Folders

Back on 1570, the experience for me is that everything gets slower as the time remaining gets shorter.

I've also noticed an error popup, as seen below:

Wiggle encountered a bug: 'Internal symmetry error' Cancelling tool.

Despite what the message says, it only pops up when I cancel wiggle, it's not as though wiggle stops by itself. It seems to happen regardless of the wiggle power setting.

On one cycle with pose shown, wiggle was producing distorted shapes. When I reverted to the previous position and tried again, wiggle seemed to behave more normally, although very slowly.

When I close the client directly after another wiggle, I see the following "FOLD_TREE" lines in log.txt, and "REPORTING CRASH: 476462". The client appeared to close normally, however, and there's nothing in the Windows event log showing a crash.

FOLD_TREE EDGE 214 216 19 EDGE 214 218 20 EDGE 214 215 21 EDGE 216 217 22 EDGE 218 219 23 EDGE 215 71 16 EDGE 217 142 17 EDGE 219 213 18 EDGE 71 12 1 EDGE 142 83 2 EDGE 213 154 3 EDGE 71 29 4 EDGE 142 100 5 EDGE 213 171 6 EDGE 71 40 7 EDGE 142 111 8 EDGE 213 182 9 EDGE 71 52 10 EDGE 142 123 11 EDGE 213 194 12 EDGE 71 65 13 EDGE 142 136 14 EDGE 213 207 15 EDGE 12 1 -1 EDGE 12 23 -1 EDGE 29 24 -1 EDGE 29 35 -1 EDGE 40 36 -1 EDGE 40 45 -1 EDGE 52 46 -1 EDGE 52 59 -1 EDGE 65 60 -1 EDGE 65 70 -1 EDGE 83 72 -1 EDGE 83 94 -1 EDGE 100 95 -1 EDGE 100 106 -1 EDGE 111 107 -1 EDGE 111 116 -1 EDGE 123 117 -1 EDGE 123 130 -1 EDGE 136 131 -1 EDGE 136 141 -1 EDGE 154 143 -1 EDGE 154 165 -1 EDGE 171 166 -1 EDGE 171 177 -1 EDGE 182 178 -1 EDGE 182 187 -1 EDGE 194 188 -1 EDGE 194 201 -1 EDGE 207 202 -1 EDGE 207 212 -1
REPORTING CRASH: 476462
***** PREMATURELY ENDING THREAD ActionGlobalMinimize
Couldn't quit: Illegal operation for this state (..\..\..\source\src\game\util\IRC.cc:374)
closing boinc...
Sending SOPs:

Sending SOPs:

exiting...
done.

jflat06's picture
User offline. Last seen 6 hours 35 min ago. Offline
Joined: 09/29/2010
Groups: Window Group

Thanks Loci - the 'crash' is actually a bit of a misnomer at this point. We've recently expanded our crash reporting system to also be a general bug reporting system so that we can see when non-critical issues are popping up in players' clients. Our hope is that it can help in some situations like this to track down problems.

We should probably rename it, though.

LociOiling's picture
User offline. Last seen 3 hours 24 min ago. Offline
Joined: 12/27/2012
Groups: Beta Folders
Type: Question » Bug

Ended up with a crash while wiggling, lots of interesting stuff in log.txt, but no debug.txt generated. Upgrading this feedback to bug. A little bit of a change in topic, but it seems related to the issues with this puzzle. I'm giving up on the original subject, since devprev has now been pushed to main. The old main did really seem much better than devprev on puzzle 1570, and devprev/new main are fine on other puzzles.

The log.txt is almost 7,500 lines, so there's a lot to look at.

Early on, it appears to loop for a while while loading the hotkeys.

There are lots of Rosetta warnings, and numerous "Resymmetrized pose" messages.

jflat06's picture
User offline. Last seen 6 hours 35 min ago. Offline
Joined: 09/29/2010
Groups: Window Group

Currently working on a release which should alleviate the performance problems. Stay tuned!

Sitemap

Developed by: UW Center for Game Science, UW Institute for Protein Design, Northeastern University, Vanderbilt University Meiler Lab, UC Davis
Supported by: DARPA, NSF, NIH, HHMI, Amazon, Microsoft, Adobe, RosettaCommons