Recent

Author Topic: Problem with latest Lazarus + Mojave = my app seems much slower on startup  (Read 248 times)

MISV

  • Sr. Member
  • ****
  • Posts: 491

I am sorry for a very vague problem description, but here goes. A few days ago I found that my release builds were extremely slow at startup....

...

If I force quit I get this log from Apple where I can see what my app is doing while I force quit it. I have had this log appear many times, so I suspect this is code taking up much time (simply by "sampling" what is in log - this has been the case 9/10 times):


Quote
Date/Time:       2018-12-06 17:42:06 +0100
End time:        2018-12-06 17:42:07 +0100
OS Version:      Mac OS X 10.14.1 (Build 18B75)
Architecture:    x86_64
Report Version:  27

Data Source:     Stackshots
Shared Cache:    0x1ca10000 F0984AF5-A47F-36FD-92E1-8A46E7033EB8
Shared Cache:    0 86158414-F29E-33E9-8BA3-5EDD6B68DDBE

Command:         Example
Path:            /Users/USER/Desktop/Example.app/Contents/MacOS/Example
Identifier:      com.company.Example
Version:         1.0 (1)
Parent:          launchd [1]
PID:             70735

Event:           hang
Duration:        1.09s (process was unresponsive for 142 seconds before sampling)
Steps:           11 (100ms sampling interval)

Hardware model:  MacBookPro9,2
Active cpus:     4

Time Awake Since Boot: 1000000s

Fan speed:       6196 rpm

--------------------------------------------------
Timeline format: stacks are sorted chronologically
Use -i and -heavy to re-report with count sorting
--------------------------------------------------


Heaviest stack for the main thread of the target process:
  11  ??? (Example + 5957) [0x10a3aa745]
  11  ??? (Example + 1306608) [0x10a4e7ff0]
  11  ??? (Example + 4243466) [0x10a7b500a]
  3   ??? (Example + 2430301) [0x10a5fa55d]
  3   -[NSTextView insertText:] + 327 (AppKit + 3429690) [0x7fff4471e53a]
  2   -[NSTextView insertText:replacementRange:] + 740 (AppKit + 3430886) [0x7fff4471e9e6]
  2   -[NSTextView(NSSharing) shouldChangeTextInRanges:replacementStrings:] + 3653 (AppKit + 3438619) [0x7fff4472081b]
  2   -[NSLayoutManager temporaryAttribute:atCharacterIndex:longestEffectiveRange:inRange:] + 283 (UIFoundation + 501643) [0x7fff6f26e78b]
  1   -[__NSDictionaryM objectForKey:] + 262 (CoreFoundation + 348545) [0x7fff46ec6181]


Process:         Example [70735]
UUID:            D6E590E0-07C1-30B1-89A6-253009BE3289
Path:            /Users/USER/Desktop/Example.app/Contents/MacOS/Example
Architecture:    x86_64
Parent:          launchd [1]
UID:             501
Footprint:       154.51 MB
Start time:      2018-12-06 17:42:06 +0100
End time:        2018-12-06 17:42:07 +0100
Num samples:     11 (1-11)
CPU Time:        0.984s (2.8G cycles, 4.3G instructions, 0.64c/i)
Note:            Unresponsive for 142 seconds before sampling
Note:            1 idle work queue thread omitted

  Thread 0x1eaa3a           DispatchQueue 1           11 samples (1-11)         priority 4-46 (base 46)   cpu time 0.984s (2.8G cycles, 4.3G instructions, 0.64c/i)
  <thread QoS user interactive (requested user interactive), process unclamped, IO tier 0, priority 46 (46)>
  11  ??? (Example + 5957) [0x10a3aa745] 1-11
    11  ??? (Example + 1306608) [0x10a4e7ff0] 1-11
      11  ??? (Example + 4243466) [0x10a7b500a] 1-11
        1   ??? (Example + 1970168) [0x10a589ff8] 1
          1   __CFStringEncodeByteStream + 1876 (CoreFoundation + 268432) [0x7fff46eb2890] 1
            1   CFStringEncodingUnicodeToBytes + 241 (CoreFoundation + 270953) [0x7fff46eb3269] 1
              1   __CFToUTF8 + 73 (CoreFoundation + 327282) [0x7fff46ec0e72] (running) 1
        1   ??? (Example + 2429976) [0x10a5fa418] 2
          1   -[NSString getLineStart:end:contentsEnd:forRange:] + 34 (Foundation + 1234909) [0x7fff493417dd] 2
            1   -[NSString _getBlockStart:end:contentsEnd:forRange:stopAtLineSeparators:] + 1264 (Foundation + 591295) [0x7fff492a45bf] 2
              1   __sel_registerName(char const*, bool, bool) + 41 (libobjc.A.dylib + 128113) [0x7fff73064471] 2
                1   search_builtins(char const*) + 32 (libobjc.A.dylib + 128027) [0x7fff7306441b] 2
                  1   objc_opt::objc_stringhash_t::hash(char const*, unsigned long) const + 949 (libobjc.A.dylib + 11685) [0x7fff73047da5] (running) 2
  <priority 4 (46)>
        1   ??? (Example + 1970168) [0x10a589ff8] 3
          1   __CFStringEncodeByteStream + 1876 (CoreFoundation + 268432) [0x7fff46eb2890] 3
            1   CFStringEncodingUnicodeToBytes + 241 (CoreFoundation + 270953) [0x7fff46eb3269] 3
              1   __CFToUTF8 + 87 (CoreFoundation + 327296) [0x7fff46ec0e80] (running) 3
  <priority 38 (46)>
        1   ??? (Example + 33829) [0x10a3b1425] (running) 4
  <priority 41 (46)>
        1   ??? (Example + 2429976) [0x10a5fa418] 5
          1   -[NSString getLineStart:end:contentsEnd:forRange:] + 34 (Foundation + 1234909) [0x7fff493417dd] 5
            1   -[NSString _getBlockStart:end:contentsEnd:forRange:stopAtLineSeparators:] + 1625 (Foundation + 591656) [0x7fff492a4728] (running) 5
  <priority 43 (46)>
        1   ??? (Example + 8313) [0x10a3ab079] (running) 6
  <priority 45 (46)>
        1   ??? (Example + 2430301) [0x10a5fa55d] 7
          1   -[NSTextView insertText:] + 327 (AppKit + 3429690) [0x7fff4471e53a] 7
            1   -[NSTextView insertText:replacementRange:] + 740 (AppKit + 3430886) [0x7fff4471e9e6] 7
              1   -[NSTextView(NSSharing) shouldChangeTextInRanges:replacementStrings:] + 3653 (AppKit + 3438619) [0x7fff4472081b] 7
                1   -[NSLayoutManager temporaryAttribute:atCharacterIndex:longestEffectiveRange:inRange:] + 283 (UIFoundation + 501643) [0x7fff6f26e78b] 7
                  1   -[__NSDictionaryM objectForKey:] + 262 (CoreFoundation + 348545) [0x7fff46ec6181] (running) 7
        1   ??? (Example + 2429048) [0x10a5fa078] (running) 8
        1   ??? (Example + 2430301) [0x10a5fa55d] 9
          1   -[NSTextView insertText:] + 327 (AppKit + 3429690) [0x7fff4471e53a] 9
            1   -[NSTextView insertText:replacementRange:] + 2964 (AppKit + 3433110) [0x7fff4471f296] 9
              1   -[NSTextStorage endEditing] + 127 (UIFoundation + 135878) [0x7fff6f2152c6] 9
                1   -[NSTextStorage processEditing] + 380 (UIFoundation + 42848) [0x7fff6f1fe760] 9
                  1   -[NSTextStorage _notifyEdited:range:changeInLength:invalidatedRange:] + 165 (UIFoundation + 61770) [0x7fff6f20314a] 9
                    1   -[NSLayoutManager processEditingForTextStorage:edited:range:changeInLength:invalidatedRange:] + 35 (UIFoundation + 136124) [0x7fff6f2153bc] 9
                      1   -[NSLayoutManager textStorage:edited:range:changeInLength:invalidatedRange:] + 584 (UIFoundation + 136714) [0x7fff6f21560a] 9
                        1   _enableTextViewResizing + 228 (UIFoundation + 70633) [0x7fff6f2053e9] 9
                          1   -[NSLayoutManager(NSPrivate) _recalculateUsageForTextContainerAtIndex:] + 1602 (UIFoundation + 72392) [0x7fff6f205ac8] 9
                            1   _NSLayoutTreeLineFragmentUsedRectForGlyphAtIndex + 217 (UIFoundation + 493918) [0x7fff6f26c95e] (running) 9
  <priority 46 (46)>
        1   ??? (Example + 2429029) [0x10a5fa065] (running) 10
        1   ??? (Example + 2430301) [0x10a5fa55d] 11
          1   -[NSTextView insertText:] + 327 (AppKit + 3429690) [0x7fff4471e53a] 11
            1   -[NSTextView insertText:replacementRange:] + 740 (AppKit + 3430886) [0x7fff4471e9e6] 11
              1   -[NSTextView(NSSharing) shouldChangeTextInRanges:replacementStrings:] + 3653 (AppKit + 3438619) [0x7fff4472081b] 11
                1   -[NSLayoutManager temporaryAttribute:atCharacterIndex:longestEffectiveRange:inRange:] + 283 (UIFoundation + 501643) [0x7fff6f26e78b] 11
                  1   -[__NSDictionaryM objectForKey:] + 160 (CoreFoundation + 348443) [0x7fff46ec611b] (running) 11

  Binary Images:
           0x10a3a9000 -        0x10a921fff  com.company.Example 1.0 (1) <D6E590E0-07C1-30B1-89A6-253009BE3289>  /Users/USER/Desktop/Example.app/Contents/MacOS/Example
        0x7fff443d9000 -     0x7fff451f9fff  com.apple.AppKit 6.9 (1671.10.106)           <179A5F4A-6467-31BD-93F2-CC27E046221E>  /System/Library/Frameworks/AppKit.framework/Versions/C/AppKit
        0x7fff46e71000 -     0x7fff472bffff  com.apple.CoreFoundation 6.9 (1560.12)       <E1F39C45-A37D-3A28-81CB-4B0BBDC290F4>  /System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation
        0x7fff49214000 -     0x7fff495e2fff  com.apple.Foundation 6.9 (1560.12)           <B5DC275C-12C9-320A-A117-C8FE9034931A>  /System/Library/Frameworks/Foundation.framework/Versions/C/Foundation
        0x7fff6f1f4000 -     0x7fff6f3aefff  com.apple.UIFoundation 1.0 (551)             <7B73C4E0-256B-3C59-8E18-475A42BE0B12>  /System/Library/PrivateFrameworks/UIFoundation.framework/Versions/A/UIFoundation
        0x7fff73045000 -     0x7fff737cefff  libobjc.A.dylib (750.1)                      <8CD466AD-D084-35D4-8760-59180F0220BF>  /usr/lib/libobjc.A.dylib
       

....


In debugger the slowness starts in the call to ".Show" (I have no OnShow even handler so not my own code taking up time there)

And I think one of the culprits (that also fit the Apple log) is at:

CocoaWSStdCtrls - FTextView.InsertText(...)
(called somehow from a TRichEdit constructor ...)
« Last Edit: December 07, 2018, 01:49:17 pm by MISV »

MISV

  • Sr. Member
  • ****
  • Posts: 491
Re: Problem with latest Lazarus + Mojave = my app seems much slower on startup
« Reply #1 on: December 07, 2018, 02:24:03 pm »
It seems moving (20+) memo.text initialization out of .loaded (and to after formshow) is helping. Still researching

Hansaplast

  • Sr. Member
  • ****
  • Posts: 481
  • Tweaking4All.com
    • Tweaking4All
Re: Problem with latest Lazarus + Mojave = my app seems much slower on startup
« Reply #2 on: December 09, 2018, 05:10:32 pm »
I experience this when using a debugger ... set debugger to "none", and the build to "release" - things start much faster. At least - that's my experience.  ::)

Martin_fr

  • Administrator
  • Hero Member
  • *
  • Posts: 4938
    • wiki
Re: Problem with latest Lazarus + Mojave = my app seems much slower on startup
« Reply #3 on: December 09, 2018, 06:41:15 pm »
I experience this when using a debugger ... set debugger to "none", and the build to "release" - things start much faster. At least - that's my experience.  ::)
I think the OT is not debugger related.

Running an app inside a debugger, will introduce a delay before/until the app is started at all. How much depends on the debugger. There are few options, but all of them have a delay.
- using gdb may be a bit less slow
- using lldb(alpha) -> without fpdebug, may also be a bit less slow, but will require c-style syntax for watches "form1->fvisible"

Feel free to start a new thread to discuss this.