On Fri, 2005-04-29 at 12:56 -0400, Lee Revell wrote: > Now do you believe me that it's a folder > search bug? > I have attached a debugging patch that times the search phase of the message list generation. These results clearly demonstrate the problem: Test procedure: After applying debug patch, launch Evo, then repeatedly switch back and forth between "Inbox" and "Unread Mail". Unpatched: regen_list_regen: search took 0.778 seconds regen_list_regen: search took 0.073 seconds regen_list_regen: search took 0.008 seconds regen_list_regen: search took 6.248 seconds regen_list_regen: search took 0.091 seconds regen_list_regen: search took 0.064 seconds regen_list_regen: search took 7.886 seconds regen_list_regen: search took 0.060 seconds regen_list_regen: search took 16.395 seconds regen_list_regen: search took 6.674 seconds regen_list_regen: search took 5.605 seconds regen_list_regen: search took 12.937 seconds regen_list_regen: search took 20.375 seconds regen_list_regen: search took 0.170 seconds regen_list_regen: search took 20.913 seconds regen_list_regen: search took 54.960 seconds regen_list_regen: search took 17.991 seconds regen_list_regen: search took 31.834 seconds regen_list_regen: search took 0.165 seconds evo-search-bar-fix.patch: regen_list_regen: search took 0.001 seconds regen_list_regen: search took 0.002 seconds regen_list_regen: search took 0.030 seconds regen_list_regen: search took 1.425 seconds regen_list_regen: search took 1.885 seconds regen_list_regen: search took 3.389 seconds regen_list_regen: search took 0.024 seconds regen_list_regen: search took 11.302 seconds regen_list_regen: search took 3.078 seconds regen_list_regen: search took 0.024 seconds regen_list_regen: search took 8.270 seconds regen_list_regen: search took 3.487 seconds regen_list_regen: search took 0.057 seconds regen_list_regen: search took 3.649 seconds regen_list_regen: search took 0.024 seconds regen_list_regen: search took 8.832 seconds regen_list_regen: search took 0.024 seconds regen_list_regen: search took 9.913 seconds evo-search-bar-fix.patch + hack to disable "hidejunk": regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.005 seconds regen_list_regen: search took 0.004 seconds regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.006 seconds regen_list_regen: search took 0.001 seconds regen_list_regen: search took 0.005 seconds regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.004 seconds regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.000 seconds regen_list_regen: search took 0.005 seconds I was wrong about the impact of the search bar bug relative to the hidejunk issue, but it's impossible to deny that the above numbers represent a problem.
Indeed. It looks to me like lock contention still. You have two threads getting the same lock and freeing it in a small loop - you end up getting many more context switches than normal, and orders of magnitude slow-down as you are seeing here. Perhaps when the search function is retriving each messageinfo while the messagelist is doing the same. I haven't been able to recreate this so far. vFolders were streamlined somewhat in 2.2, that may have had an effect too.
I will look into it when i can, I've been busy with meetings lately.
I'm concerned that even though your patch fixes this symptom, the problem is still in the code somewhere. So even though the 'normal' case will be fixed, if the user sets a search for example, it will re-expose the underlying problem. I'd rather have that get fixed too, and not just the common case.
It would be really handy if you could get a backtrace of WHEN it is in the middle of one of these >10 second update times(i.e. ctrl-c while it is running slow). Of all threads (thread apply all bt). That should show clearly what all threads are doing and help pinpoint how the lock contention (if indeed, thats what it is), is happening. The other trace only has 1 thread, and doesnt show anything other than normal expected operation either. I am guessing a code walkthrough will also pick this up, but a backtrace will reduce the doubt and search time.
Thanks,
Michael
