Professional UI Solutions
Site Map   /  Register
 
 

Forum

Please Log In to post a new message or reply to an existing one. If you are not registered, please register.

NOTE: Some forums may be read-only if you are not currently subscribed to our technical support services.

Forums » Prof-UIS General Discussion » Performance problems Collapse All
Subject Author Date
Krzysztof Janik Feb 22, 2005 - 5:11 AM

Hello!


I’ve some concerns about performance of ProfUIS 2.30 (commercial). Let’s take for example "ProfStudio" demo. I compiled it in Release configuration. Now, by simply moving a mouse cursor over the application window, I am able to have 100% CPU consumption of my P4 2.4GHz. There is something wrong going on, I think. Resizing of any docking panel is also painfully slow. Below there is a sample output of profiling session (no other actions than moving mouse over the window):


Module Statistics for profstudio-nd.exe
---------------------------------------
    Time in module: 25487.386 millisecond
    Percent of time in module: 100.0%
    Functions in module: 1911
    Hits in module: 4899050
    Module function coverage: 49.8%


        Func          Func+Child           Hit
        Time   %         Time      %      Count  Function
---------------------------------------------------------
    7835.849  30.7    11142.005  43.7      375 CWinApp::OnIdle(long) (mfc42d.dll)
    2952.613  11.6     4436.776  17.4       15 CFrameWnd::RecalcLayout(int) (mfc42d.dll)
    2755.096  10.8     7043.806  27.6        1 CMainFrame::OnCreate(struct tagCREATESTRUCTA *) (mainfrm.obj)
    2063.995   8.1     5645.851  22.2      945 CWinThread::PumpMessage(void) (mfc42d.dll)
     984.677   3.9      984.677   3.9   288939 CMDIFrameWnd::AssertValid(void) (mfc42d.dll)
     983.894   3.9     2851.776  11.2    36847 CWnd::DefWindowProcA(unsigned int,unsigned int,long) (mfc42d.dll)
     802.978   3.2      803.294   3.2        1 CExtControlBar::ProfileBarStateSave(class CFrameWnd *,char const *,char const *,char const *,struct tagWINDOWPLACEMENT *) (profuis230nd.dll)
     586.794   2.3      586.794   2.3   289500 CExtToolControlBar::AssertValid(void) (profuis230nd.dll)
     547.642   2.1     2280.997   8.9    27475 CExtMenuControlBar::OnHookWndMsg(long &,struct HWND__ *,unsigned int,unsigned int &,long &) (profuis230nd.dll)
     396.866   1.6     1395.737   5.5      939 CWinThread::PreTranslateMessage(struct tagMSG *) (mfc42d.dll)
     389.393   1.5      898.662   3.5    32744 CExtMenuControlBar::TranslateMainFrameMessage(struct tagMSG *) (profuis230nd.dll)
     323.886   1.3    11173.844  43.8    45266 CWnd::OnWndMsg(unsigned int,unsigned int,long,long *) (mfc42d.dll)
     251.713   1.0      268.987   1.1      196 CExtToolControlBar::_RecalcPositionsImpl(void) (profuis230nd.dll)
     247.598   1.0     1892.786   7.4     6996 CExtResizableDialog::WindowProc(unsigned int,unsigned int,long) (profuis230nd.dll)
     209.352   0.8      324.867   1.3    15423 CChildView::OnCmdMsg(unsigned int,int,void *,struct AFX_CMDHANDLERINFO *) (childview.obj)
     189.208   0.7     2488.988   9.8    16099 CMDIFrameWnd::OnCmdMsg(unsigned int,int,void *,struct AFX_CMDHANDLERINFO *) (mfc42d.dll)
     188.438   0.7     2784.366  10.9    28804 CMainFrame::OnCmdMsg(unsigned int,int,void *,struct AFX_CMDHANDLERINFO *) (mainfrm.obj)
     187.029   0.7      189.657   0.7        4 CEdit::ReplaceSel(char const *,int) (mfc42d.dll)
     185.848   0.7      185.848   0.7       24 CImageList::Create(unsigned int,int,int,unsigned long) (mfc42d.dll)
     161.226   0.6     3650.125  14.3     3868 CMDIFrameWnd::DefWindowProcA(unsigned int,unsigned int,long) (mfc42d.dll)
     129.361   0.5      129.361   0.5    64226 CExtTabMdiWhidbeyWnd::AssertValid(void) (profuis230nd.dll)
     126.181   0.5      129.313   0.5       18 CExtResDlg::OnInitDialog(void) (profuis230nd.dll)
     122.682   0.5      615.082   2.4    12290 CProfStudioThinFrame::WindowProc(unsigned int,unsigned int,long) (childfrm.obj)
     117.944   0.5      193.780   0.8     3934 CExtToolControlBar::OnUpdateCmdUI(class CFrameWnd *,int) (profuis230nd.dll)
     115.950   0.5      846.865   3.3       18 CExtResDlg::Create(unsigned int,class CWnd *) (profuis230nd.dll)
     100.479   0.4      434.758   1.7      532 CExtResizableDialog::PreTranslateMessage(struct tagMSG *) (profuis230nd.dll)
      99.630   0.4       99.630   0.4    21279 CWnd::GetParent(void) (mfc42d.dll)
      83.254   0.3      130.090   0.5      100 CExtWA<class CExtWS<class CExtResDlg,301> >::ArrangeLayout(int,int) (profstudiobreakpointsview.obj)
      73.235   0.3       73.317   0.3        2 CProfStudioHtmlCtrl::NavigateURL(char const *) (profstudiohtmlctrl.obj)
      71.640   0.3       71.640   0.3   518350 CMainFrame::GetRuntimeClass(void) (mainfrm.obj)
      70.195   0.3       98.214   0.4        1 CExtPaintManager::stat_PassPaintMessages(bool,bool,bool) (profuis230nd.dll)
      66.989   0.3      426.066   1.7    21212 CExtTMWI<class CExtTabWhidbeyWnd>::_GetHwndMdiArea(void) (mainfrm.obj)
      66.033   0.3     1050.710   4.1   288939 CMainFrame::AssertValid(void) (mainfrm.obj)
      61.675   0.2      300.924   1.2   131172 AfxAssertValidObject(class CObject const *,char const *,int) (mfc42d.dll)
      54.694   0.2       54.902   0.2       14 CComboBox::Create(unsigned long,struct tagRECT const &,class CWnd *,unsigned int) (mfc42d.dll)
      52.762   0.2      486.691   1.9     3860 CMDIFrameWnd::GetActiveFrame(void) (mfc42d.dll)
      52.758   0.2      654.351   2.6     3842 CExtMenuControlBar::_KillFrameMenu(void) (profuis230nd.dll)
      52.373   0.2      270.522   1.1        2 CWnd::DestroyWindow(void) (mfc42d.dll)
      51.353   0.2       51.353   0.2   529197 AfxIsValidAddress(void const *,unsigned int,int) (mfc42d.dll)
      50.014   0.2       50.162   0.2        2 CWnd::CreateControl(struct _GUID const &,char const *,unsigned long,struct tagRECT const &,class CWnd *,unsigned int,class CFile *,int,unsigned short *) (mfco42d.dll)
      43.032   0.2      488.986   1.9       79 CWnd::RepositionBars(unsigned int,unsigned int,unsigned int,unsigned int,struct tagRECT *,struct tagRECT const *,int) (mfc42d.dll)
      42.677   0.2       44.507   0.2       31 CWnd::SetFont(class CFont *,int) (mfc42d.dll)
      42.149   0.2      394.424   1.5     3409 CMDIFrameWnd::PreTranslateMessage(struct tagMSG *) (mfc42d.dll)
      41.536   0.2       41.536   0.2   351349 CFrameWnd::IsFrameWnd(void) (mfc42d.dll)

Krzysztof Janik Feb 22, 2005 - 5:19 AM

It seems to me that you are flooding the application with unnecessary messages so that it recalculates its layout (or maybe repaints) on every mouse motion.

Technical Support Feb 22, 2005 - 11:20 AM

Dear Krzysztof,

Thank you for the performance report but we cannot confirm the 100% CPU consumption. We tested several samples, including ProfStudio on Celeron 2 GHz machines. The CPU time depends on how complex the application is. Of course, ProfStudio is the most complex application (it was specially designed for ultimate tests) and eats up to 60% in debug or 50% in release. Simple programs like SDI or MDI samples consume 12-16% both in debug and release. We also checked whether the layout is recalculated or unwanted repainting is invoked when the mouse pointer is hovering around over windows and found no unwanted consumption at all. Let’s now get to your report:


  • CWinApp::OnIdle()is invoked each time when the thread’s message queue becomes empty. This happens very often and that is why it’s at the top.

  • CFrameWnd::RecalcLayout() is in the second place because ProfStudio contains a big number of toolbars, resizable control bars and their container windows.

  • CMainFrame::OnCreate() creates all these control bars (see the previous item) and loads their GUI states.

  • CWinThread::PumpMessage() gets each message of any window from the thread’s message queue and invokes the MFC’s message pre-translating and routing mechanism which delivers messages to particular MFC objects such as CCmdTarget or CWnd.

  • CWnd::DefWindowProcA() is to where most messages come for default handling by ::DefWindowProcA(). This is where the most messages end their life cycle.

  • CExtControlBar::ProfileBarStateSave() loads and applies GUI states of all control bars declared in ProfStudio.

  • CExtToolControlBar::AssertValid() may often be called because we really use it very often.

  • CExtMenuControlBar::OnHookWndMsg() is called often because the menu bar traces the state of the main frame window, MDI client area window, and active MDI child frame window. The CExtMenuControlBar::TranslateMainFrameMessage() is finally called from CExtMenuControlBar::OnHookWndMsg(). So, the number of its invocations is quite big. If we avoid calling CExtMenuControlBar::OnHookWndMsg(), we can make everything work up to 15% faster but the menu bar will lose its features.

  • CWnd::OnWndMsg() works with message maps of any CWnd-derived classes.

  • CExtToolControlBar::_RecalcPositionsImpl() re-computes positions of toolbar buttons inside toolbar windows. This mechanism is tricky and eats some time.

  • CExtResizableDialog::WindowProc() is not last in the list because many resizable control bars in ProfStudio contains resizable dialog windows inside.

The rest is not so interesting.

Krzysztof Janik Feb 23, 2005 - 4:18 AM

Thank you for the detailed explanation!


I’m not sure about CWinApp::OnIdle() though. If I start the application, do nothing for a while and terminate it, profiling output is as follows:


30135.576  72.7    32859.437  79.3      291 CWinThread::PumpMessage(void) (mfc42d.dll)
    3486.433   8.4     5150.996  12.4       15 CFrameWnd::RecalcLayout(int) (mfc42d.dll)
    1592.279   3.8     5894.735  14.2        1 CMainFrame::OnCreate(struct tagCREATESTRUCTA *) (mainfrm.obj)


Most of the time is spent in PumpMessage function, probably because it waits for messages there. It is normal for idle applications. Now, let’s take a look at my previous output:


7835.849  30.7    11142.005  43.7      375 CWinApp::OnIdle(long) (mfc42d.dll)
    2952.613  11.6     4436.776  17.4       15 CFrameWnd::RecalcLayout(int) (mfc42d.dll)
    2755.096  10.8     7043.806  27.6        1 CMainFrame::OnCreate(struct tagCREATESTRUCTA *) (mainfrm.obj)
    2063.995   8.1     5645.851  22.2      945 CWinThread::PumpMessage(void) (mfc42d.dll)


OnIdle takes 43% of application time. Aren’t you really doing any heavyweight lifting there? ;) Or maybe it waits for something as PumpMessage does? Taking into account that I was hovering the mouse over areas that did not react on this (no pop-up panels, no tooltips, should be no repainting at all), the amount of CPU power consumed is pretty high.


Nonetheless, ProfUIS is great, but if it only could be a little bit faster... If I ever find what causes these slowdowns, will let you know.


Oh, by the way, your forums are incompatible with Firefox browser (cannot post new threads).

Technical Support Feb 23, 2005 - 8:10 AM

We are sure that it is possible to make some parts of code work at least a bit faster and hope that this will be done in the next releases step by step. Unfortunately, the platform portability (including Win95/NT4) is also important for us. This makes improving and debugging the code more difficult. We appreciate any your report and feedback.

As for FireFox, this very message was posted with FireFox 1.0 Preview Release (Mozilla/5.0 (Windows; U; Windows NT 5.0; rv:1.7.3) Gecko/20041001 Firefox/0.10.1). We will download the latest version and check whether it is possible to post messages with it. Of course, we will try to fix the problem.


Krzysztof Janik Feb 23, 2005 - 9:35 AM

As of Firefox, there s no way to create new topics. Replying works fine.