Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

App launch time increased #586

Closed
alloy opened this issue Jul 4, 2015 · 142 comments
Closed

App launch time increased #586

alloy opened this issue Jul 4, 2015 · 142 comments

Comments

@alloy
Copy link
Contributor

alloy commented Jul 4, 2015

The LaunchImage is shown way longer than before. I wonder if this could be DYLD loading all the frameworks.

@alloy alloy added the QA label Jul 4, 2015
@alloy alloy added this to the Sprint June 2 - July 14 milestone Jul 4, 2015
@alloy alloy self-assigned this Jul 4, 2015
@alloy
Copy link
Contributor Author

alloy commented Jul 4, 2015

Ouch, yeah, 4.3 sec to load all images 😭

total time: 4.6 seconds (100.0%)
total images loaded:  290 (235 from dyld shared cache)
total segments mapped: 162, into 2414 pages with 312 pages pre-fetched
total images loading time: 4.3 seconds (93.8%)
total dtrace DOF registration time: 0.14 milliseconds (0.0%)
total rebase fixups:  91,464
total rebase fixups time: 55.97 milliseconds (1.2%)
total binding fixups: 261,574
total binding fixups time: 111.74 milliseconds (2.3%)
total weak binding fixups time: 0.33 milliseconds (0.0%)
total bindings lazily fixed up: 0 of 0
total initializer time: 118.93 milliseconds (2.5%)
    libSystem.B.dylib : 76.47 milliseconds (1.6%)
libBacktraceRecording.dylib : 0.57 milliseconds (0.0%)
       libc++.1.dylib : 0.05 milliseconds (0.0%)
      libobjc.A.dylib : 0.03 milliseconds (0.0%)
       CoreFoundation : 0.87 milliseconds (0.0%)
               vImage : 0.01 milliseconds (0.0%)
     libGLImage.dylib : 0.14 milliseconds (0.0%)
libFosl_dynamic.dylib : 0.02 milliseconds (0.0%)
            CoreImage : 0.01 milliseconds (0.0%)
        CoreTelephony : 0.01 milliseconds (0.0%)
     HockeySDK_Source : 0.56 milliseconds (0.0%)
                Artsy : 30.45 milliseconds (0.6%)
total symbol trie searches:    87386
total symbol table binary searches:    0
total images defining weak symbols:  15
total images using weak symbols:  46

@alloy
Copy link
Contributor Author

alloy commented Jul 4, 2015

Looks like we’ll have to enable prebinding 😭 The images should have a vmaddr other than 0 and a unique one for each.

For more info see https://developer.apple.com/library/ios/documentation/MacOSX/Conceptual/BPFrameworks/Concepts/FrameworkBinding.html#//apple_ref/doc/uid/20002256-106894

otool -l /Users/eloy/Library/Developer/Xcode/DerivedData/Artsy-dvyztngmkwpjoxercvsdsplrzfzz/Build/Products/Debug-iphoneos/AFNetworking.framework/AFNetworking
Load command 0
      cmd LC_SEGMENT_64
  cmdsize 872
  segname __TEXT
   vmaddr 0x0000000000000000
   vmsize 0x0000000000030000
  fileoff 0
 filesize 196608
  maxprot 0x00000005
 initprot 0x00000005
   nsects 10
    flags 0x0
otool -l /Users/eloy/Library/Developer/Xcode/DerivedData/Artsy-dvyztngmkwpjoxercvsdsplrzfzz/Build/Products/Debug-iphoneos/AFHTTPRequestOperationLogger.framework/AFHTTPRequestOperationLogger 
Load command 0
      cmd LC_SEGMENT_64
  cmdsize 792
  segname __TEXT
   vmaddr 0x0000000000000000
   vmsize 0x0000000000008000
  fileoff 0
 filesize 32768
  maxprot 0x00000005
 initprot 0x00000005
   nsects 9
    flags 0x0
[SNIP]

@alloy
Copy link
Contributor Author

alloy commented Jul 4, 2015

There’s also the option of lazy loading the frameworks, i.e. on demand, but that’s not automatable.

@alloy
Copy link
Contributor Author

alloy commented Jul 4, 2015

This prints out the list of vmaddrs of the frameworks in the app after letting DYLD figure it out without prebinding, which could be used to assign the -seg1addr flags to the corresponding framework’s OTHER_LDFLAGS:

#import <mach-o/dyld.h>
#import <inttypes.h>
static void
PrintImageLoadAddresses(void)
{
    const char *frameworks_path = [[[[NSBundle mainBundle] bundlePath] stringByAppendingPathComponent:@"Frameworks"] UTF8String];
    unsigned long frameworks_path_length = strlen(frameworks_path);
    for (uint32_t i = 0; i < _dyld_image_count(); i++) {
        const char *image_path = _dyld_get_image_name(i);
        if (strncmp(image_path, frameworks_path, frameworks_path_length) == 0) {
            NSString *frameworkName = [[NSString stringWithUTF8String:image_path] lastPathComponent];
            intptr_t slide = _dyld_get_image_vmaddr_slide(i);
            printf("0x%" PRIxPTR ": %s\n", slide, [frameworkName UTF8String]);
        }
    }
}
    0x100474000: AFHTTPRequestOperationLogger
    0x100494000: AFNetworking
    0x1004f4000: AFOAuth1Client
    0x100524000: ALPValidator
    0x100560000: ARASCIISwizzle
    0x100588000: ARAnalytics
    0x1005c4000: ARCollectionViewMasonryLayout
    0x1005f0000: ARGenericTableViewController
    0x100610000: ARTiledImageView
    0x100630000: Analytics
    0x100690000: Artsy_UIButtons
    0x1006b0000: Artsy_UIColors
    0x1006d8000: Artsy_UIFonts
    0x1006f8000: Artsy_UILabels
    0x100718000: Bolts
    0x10076c000: CocoaLumberjack
    0x1007d0000: DHCShakeNotifier
    0x1007f8000: DRKonamiCode
    0x100828000: EDColor
    0x100858000: FBSDKCoreKit
    0x100944000: FBSDKLoginKit
    0x100998000: FLKAutoLayout
    0x1009b0000: FODFormKit
    0x100a10000: FXBlurView
    0x100a34000: HockeySDK_Source
    0x100b9c000: ISO8601DateFormatter
    0x100bcc000: InterAppCommunication
    0x100bf0000: JLRoutes
    0x100c10000: JSBadgeView
    0x100c34000: JSDecoupledAppDelegate
    0x100c5c000: KSDeferred
    0x100c74000: Keys
    0x100c88000: MMMarkdown
    0x100cbc000: Mantle
    0x100d08000: MultiDelegate
    0x100d20000: NAMapKit
    0x100d60000: ORKeyboardReactingApplication
    0x100d90000: ORStackView
    0x100db4000: ObjectiveSugar
    0x100de4000: RSSwizzle
    0x100e0c000: ReactiveCocoa
    0x100f10000: SDWebImage
    0x100f7c000: TPDWeakProxy
    0x100f8c000: TRVSDictionaryWithCaseInsensitivity
    0x100fb8000: TSMiniWebBrowser_dblock
    0x100fdc000: UIAlertView_Blocks
    0x101008000: UICKeyChainStore
    0x101028000: UIView_BooleanAnimations
    0x101048000: VCRURLConnection
    0x101084000: iRate
    0x1010c0000: libextobjc

@alloy
Copy link
Contributor Author

alloy commented Jul 4, 2015

I set the pre bindings with the following Podfile post install hook, but either I’m doing something wrong or prebinding makes no difference in load time :-/

post_install do |installer|
  vmaddrs = <<-EOS
    0x100474000: AFHTTPRequestOperationLogger
    0x100494000: AFNetworking
    0x1004f4000: AFOAuth1Client
    0x100524000: ALPValidator
    0x100560000: ARASCIISwizzle
    0x100588000: ARAnalytics
    0x1005c4000: ARCollectionViewMasonryLayout
    0x1005f0000: ARGenericTableViewController
    0x100610000: ARTiledImageView
    0x100630000: Analytics
    0x100690000: Artsy_UIButtons
    0x1006b0000: Artsy_UIColors
    0x1006d8000: Artsy_UIFonts
    0x1006f8000: Artsy_UILabels
    0x100718000: Bolts
    0x10076c000: CocoaLumberjack
    0x1007d0000: DHCShakeNotifier
    0x1007f8000: DRKonamiCode
    0x100828000: EDColor
    0x100858000: FBSDKCoreKit
    0x100944000: FBSDKLoginKit
    0x100998000: FLKAutoLayout
    0x1009b0000: FODFormKit
    0x100a10000: FXBlurView
    0x100a34000: HockeySDK_Source
    0x100b9c000: ISO8601DateFormatter
    0x100bcc000: InterAppCommunication
    0x100bf0000: JLRoutes
    0x100c10000: JSBadgeView
    0x100c34000: JSDecoupledAppDelegate
    0x100c5c000: KSDeferred
    0x100c74000: Keys
    0x100c88000: MMMarkdown
    0x100cbc000: Mantle
    0x100d08000: MultiDelegate
    0x100d20000: NAMapKit
    0x100d60000: ORKeyboardReactingApplication
    0x100d90000: ORStackView
    0x100db4000: ObjectiveSugar
    0x100de4000: RSSwizzle
    0x100e0c000: ReactiveCocoa
    0x100f10000: SDWebImage
    0x100f7c000: TPDWeakProxy
    0x100f8c000: TRVSDictionaryWithCaseInsensitivity
    0x100fb8000: TSMiniWebBrowser_dblock
    0x100fdc000: UIAlertView_Blocks
    0x101008000: UICKeyChainStore
    0x101028000: UIView_BooleanAnimations
    0x101048000: VCRURLConnection
    0x101084000: iRate
    0x1010c0000: libextobjc
  EOS

  vmaddrs = Hash[*vmaddrs.split("\n").flat_map { |line| line.match(/(0x\w+): (.+)/)[1..2].reverse }]

  installer.pods_project.targets.each do |target|
    path = target.product_reference.path
    if File.extname(path) == '.framework'
      name = File.basename(path, '.framework')
      if vmaddr = vmaddrs[name]
        target.build_configurations.each do |config|
          config.build_settings['OTHER_LDFLAGS'] = "$(inherited) -seg1addr #{vmaddr}"
        end
      else
        puts "[!] No vmaddr found for: #{name}"
      end
    end
  end
end
total time: 4.4 seconds (100.0%)
total images loaded:  290 (235 from dyld shared cache)
total segments mapped: 162, into 2414 pages with 312 pages pre-fetched
total images loading time: 4.2 seconds (94.8%)
total dtrace DOF registration time: 0.14 milliseconds (0.0%)
total rebase fixups:  91,470
total rebase fixups time: 29.95 milliseconds (0.6%)
total binding fixups: 261,576
total binding fixups time: 94.93 milliseconds (2.1%)
total weak binding fixups time: 0.33 milliseconds (0.0%)
total bindings lazily fixed up: 0 of 0
total initializer time: 107.66 milliseconds (2.3%)
    libSystem.B.dylib : 72.95 milliseconds (1.6%)
libBacktraceRecording.dylib : 0.58 milliseconds (0.0%)
       libc++.1.dylib : 0.05 milliseconds (0.0%)
      libobjc.A.dylib : 0.03 milliseconds (0.0%)
       CoreFoundation : 0.83 milliseconds (0.0%)
               vImage : 0.01 milliseconds (0.0%)
     libGLImage.dylib : 0.14 milliseconds (0.0%)
libFosl_dynamic.dylib : 0.02 milliseconds (0.0%)
            CoreImage : 0.01 milliseconds (0.0%)
        CoreTelephony : 0.01 milliseconds (0.0%)
     HockeySDK_Source : 0.54 milliseconds (0.0%)
                Artsy : 19.80 milliseconds (0.4%)
total symbol trie searches:    87387
total symbol table binary searches:    0
total images defining weak symbols:  15
total images using weak symbols:  46

@alloy
Copy link
Contributor Author

alloy commented Jul 5, 2015

The timing info can be seen by setting both the DYLD_PRINT_APIS and the DYLD_PRINT_STATISTICS env variables. You’d expect just the latter, but it only seems to get printed when combined with the former. The timing info will be in the middle of all the API usage.

https://developer.apple.com/library/mac/documentation/Darwin/Reference/ManPages/man1/dyld.1.html

@OliverLetterer
Copy link

@alloy I'm just curious because I recently reevaluated CocoaPods dynamic frameworks vs. statically linking all of them in one shared dynamic framework. Sry if this has already been answered or discussed anywhere else. Is this tested with or without an attached debugger? My Podfile looks like this

source "[email protected]:Sparrow-Labs/Specs.git"
source "https://github.com/CocoaPods/Specs.git"

use_frameworks!

def framework_dependencies
    pod "AFNetworking", "2.5.3"
    pod "MBProgressHUD", "~> 0.9.1"
    pod "SGKeychain", "~> 1.1.0"
    pod "KissXML", "~> 5.0.0.2"
    pod "CCVFly", "~> 0.3.3"
    pod "SWFSemanticVersion", "~> 0.3.1"

    pod "SHAlertViewBlocks", "~> 1.2.0"
    pod "SHBarButtonItemBlocks", "~> 1.2.0"
    pod "SHControlBlocks", "~> 1.2.0"
    pod "SHControlBlocks", "~> 1.2.0"
    pod "SHKeyValueObserverBlocks", "~> 2.0.0"

    pod "CloudBridge", "~> 1.2.0"
    pod "CBRRESTConnection", "~> 1.2.0"
    pod "CBRRelationshipResolver", "~> 1.0.0"

    pod "CTOpenSSLWrapper", "~> 1.3.0"
    pod "Flow", "~> 1.6.1"
    pod "SPLBadgeView", "~> 1.0.0"
    pod "SLObjectiveCRuntimeAdditions", "~> 1.1.0"
    pod "SLScrollViewKeyboardSupport", "~> 1.1.0"
    pod "SPLSpeechBubblePopoverController", "~> 2.1.3"
    pod "SPLTextFieldChain", "~> 1.0.0"
    pod "SPLTransparentDropShadowView", "~> 1.0.0"
    pod "SPLFoundation", "~> 1.4.2"
    pod "SPLMobilePrinting", "~> 2.4.4"
    pod "SPLOptionsViewController", "~> 1.1.2"
    pod "SPLStickyHeaderTableViewController", "~> 0.1.3"
    pod "SPLFormular", "~> 0.8.1"

    pod "MultipeerCommunication", "~> 0.4.0"
    pod "MCSwipeTableViewCell", "~> 2.1.2"
end


target "CocoaPodsDemo" do
    framework_dependencies

    pod "pop", "~> 1.0.0", :inhibit_warnings => true
    pod "Shimmer", "~> 1.0.2"
    pod "CDZQRScanningViewController", "~> 1.0.7.3"

    pod "UITextField+SPLAutoCompletion", "~> 1.0.0"
    pod "UIAlertControllerConvenienceAPI", "~> 0.2.0"

    pod "SPLPing", "~> 1.1.1"
    pod "SPLWindow", "~> 1.3.1"
    pod "SPLInlayLabel", "~> 1.1.0"
    pod "SPLMobilePayment", "~> 1.2.0"
    pod "SPLRoundImageCache", "~> 1.0.0"
    pod "SPLPagesViewController", "~> 1.0.0"
    pod "SPLTiltedTabsViewController", "~> 1.0.0"
    pod "SPLZoomingViewControllerTransition", "~> 1.1.2"
    pod "SPLBlurredBackgroundViewController", "~> 1.0.0"
    pod "SPLTableViewRowReorderGestureRecognizer", "~> 1.0.0"
end

target "DynamicFramework" do
    framework_dependencies
end

which results in 52 CocoaPods targets. Launch time on my end with a basic demo app with debugger is ~10s. Without debugger <1s which is reasonably fast enough for my use case.

@orta
Copy link
Contributor

orta commented Jul 5, 2015

I noticed this initially on a device beta which doesn't have a debugger attached, though I think it's definitely worth a look.

@johnno1962
Copy link

@alloy, got the "total images loading time” down from 2.5 seconds to 0.9 seconds by statically linking all frameworks’ object flles into the app. Add the following as a "run script" before the app is linked:

ls -t $OBJROOT/Pods.build/$CONFIGURATION$EFFECTIVE_PLATFORM_NAME/Pods-*.build/Objects-normal/$CURRENT_ARCH/*.o | egrep -v '/(_?FBSDK|BF|BIT)|Dummy' >$OBJROOT/Pods.build/$CONFIGURATION$EFFECTIVE_PLATFORM_NAME.filelist

and replace all -framework arguments in the .xcconfig’s OTHER_LDFLAGS with -filelist $OBJROOT/Pods.build/$CONFIGURATION$EFFECTIVE_PLATFORM_NAME.filelist

This leaves one pod "Artsy+OSSUIFonts” which uses [NSBundle bundleForClass:self] to locate resources in the pod which can be added to the main project now that ARFontLoader is in the main bundle.

@alloy
Copy link
Contributor Author

alloy commented Jul 5, 2015

@OliverLetterer I think that might actually be it. It’s fast without a debugger, so possibly @orta was running into another issue and it appeared to me to be this. Not sure, will have to take another look tomorrow when I’m sharper.

@alloy
Copy link
Contributor Author

alloy commented Jul 5, 2015

@johnno1962 That’s an impressive command! But I wasn’t looking for static linking, we can do that simply by omitting use_frameworks! from the Podfile, the point was more about finding a solution for dynamic linking.

@johnno1962
Copy link

Oops, shows how much I know... Works for Swift micro-frameworks though so could be handy for inlining frameworks in future.

@alloy
Copy link
Contributor Author

alloy commented Jul 6, 2015

@johnno1962 Good point! And thanks for taking the time anyways, there can never be enough knowledge sharing ;)

@alloy
Copy link
Contributor Author

alloy commented Sep 9, 2015

Just an update, the performance has been getting better over the betas, and without a debugger attached the impact is only really noticeable the first time an app is launched. Still something that I’d like to improve, but not a blocker for us anymore.

@alloy alloy removed this from the Sprint August 25 - October 6 milestone Sep 9, 2015
@alloy alloy reopened this Jun 23, 2016
@alloy alloy closed this as completed Jun 23, 2016
@weissi
Copy link

weissi commented Jun 23, 2016

@alloy dylibs in dyld_shared_cache must be referenced by absolute path which must start with /System/Library or /usr/lib/system and maybe a few other paths IIRC. So don't think that works. @samdmarshall told me via Twitter that they're normally just in the app bundle with other frameworks. Wonder what "optimised by the system" then means 🤔

@fabb
Copy link

fabb commented Jun 24, 2016

Maybe when using Bitcode, Apple servers could recompile the app to reference the specific Swift system libraries instead? Just guessing into the blue.

@alloy
Copy link
Contributor Author

alloy commented Jun 27, 2016

@weissi Hmm, yeah then I’m not sure either.

This is the latest I heard, which appears there might be some special treatment indeed, but not in what way http://twitter.com/jckarter/status/746081961173671936

@hei9gag
Copy link

hei9gag commented Aug 11, 2016

What is the good way to fix the images loading time problem? My project contains 64 items in Link Binary with Libraries (1 dynamic library, others are system framework / static framework). It took 1.3 seconds to load all images in iPhone 5S (is it really a image or resource files?). Many thanks.

total time: 2.2 seconds (100.0%)
total images loaded: 323 (309 from dyld shared cache)
total segments mapped: 41, into 2315 pages with 136 pages pre-fetched
total images loading time: 1.3 seconds (60.8%)
total dtrace DOF registration time: 0.17 milliseconds (0.0%)
total rebase fixups: 276,863
total rebase fixups time: 90.22 milliseconds (3.9%)
total binding fixups: 386,278
total binding fixups time: 308.50 milliseconds (13.6%)
total weak binding fixups time: 1.34 milliseconds (0.0%)
total bindings lazily fixed up: 0 of 0
total time in initializers and ObjC setup: 486.74 milliseconds (21.5%)
libSystem.B.dylib : 80.18 milliseconds (3.5%)
libBacktraceRecording.dylib : 15.14 milliseconds (0.6%)
libc++.1.dylib : 0.08 milliseconds (0.0%)
CoreFoundation : 1.26 milliseconds (0.0%)
CFNetwork : 0.01 milliseconds (0.0%)
vImage : 0.01 milliseconds (0.0%)
libGLImage.dylib : 0.20 milliseconds (0.0%)
QuartzCore : 0.01 milliseconds (0.0%)
libViewDebuggerSupport.dylib : 0.08 milliseconds (0.0%)
libglInterpose.dylib : 218.70 milliseconds (9.6%)
libTelephonyUtilDynamic.dylib : 0.00 milliseconds (0.0%)
CoreTelephony : 0.03 milliseconds (0.0%)
pop : 0.07 milliseconds (0.0%)
libswiftCore.dylib : 0.01 milliseconds (0.0%)
App STG : 165.22 milliseconds (7.3%)
total symbol trie searches: 902568
total symbol table binary searches: 0
total images defining weak symbols: 28
total images using weak symbols: 68

@foobra
Copy link

foobra commented Oct 24, 2016

@fabb do you find a way to merge dynamic frameworks

@fabb
Copy link

fabb commented Oct 24, 2016

We don't yet use dynamic frameworks. We'll wait and see if a SwiftPM integration for Xcode emerges.

@bzdybowicz
Copy link

bzdybowicz commented Feb 2, 2017

Can this problem be worked around using one big framework, which encapsulates all of the dependencies? Is loading time dependent on amount of dependencies or does their size matter as well?

@hborders
Copy link

Has anyone tested this with the new dyld 3 daemon on iOS 11? Referenced in WWDC 2017 Session 413 App Startup Time: Past, Present, and Future

@JaviSoto
Copy link

I was disappointed that the session didn't even mention the issue of slow launches with many dynamic frameworks and how that is just the reality of Swift...
That been said I have high hopes for dyld 3, however unless I understood incorrectly, it seems it won't be enabled for 3rd party apps until a later iOS release this year?

@hborders
Copy link

hborders commented Jun 12, 2017

I'll watch it again, but I thought it was only disabled for side-loaded macOS apps.

@erichoracek
Copy link

There's an unofficial solution for building Swift dynamic frameworks as static frameworks (works with Obj-C too) from @keith documented here — we've had luck merging 30 dylibs into one mega-dylib with it which dramatically improved our launch time.

@fabb
Copy link

fabb commented Jun 13, 2017

@JaviSoto last year's session had a lot of details on this

@JaviSoto
Copy link

Sure, but the onus was on us to somehow just use few dylibs. Given that they rewrote dyld it would've been great to hear about the practical change that has when on an iOS app that uses a certain # of frameworks.

@mfclarke
Copy link

mfclarke commented Mar 8, 2018

@erichoracek I've attempted the mega-dylib approach with a project here. But the only way I can get it to work is to provide the targets with framework search paths to the original dynamic frameworks. This feels pretty hacky... The linker links to the mega-dylib but the module definitions come from somewhere else. And this rightly throws up a bunch of linker warnings about attempts to link non-dylibs. Though the app builds and runs correctly.

Am I missing something here? I've tried a lot of variations of search paths for headers and such but can't get around it. It seems like a really custom modulemap might be needed for the mega-dylib for this to work correctly?

@orta
Copy link
Contributor

orta commented Mar 10, 2018

https://twitter.com/alloy/status/972503674009288705 🎉

#2561

@mfclarke

This comment has been minimized.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests