Uploaded image for project: 'Swift'
  1. Swift
  2. SR-2741

Provide Structured Output Of debug-time-function-bodies

    Details

    • Type: New Feature
    • Status: Open
    • Priority: Medium
    • Resolution: Unresolved
    • Component/s: Compiler
    • Labels:
      None

      Description

      Right now when a user runs the Swift compiler with the debug-time-function-bodies parameter the important output yielded by this parameter is dumped inline with the rest of the build information similar to the following:

      CompileSwift normal armv7 /Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift
          cd /Users/brianmichel/Development/Personal/Sketchy
          /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/swift -frontend -c /Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/AppDelegate.swift /Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/PaletteColorView.swift /Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/DrawingViewController.swift /Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CameraManager.swift /Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/Drawing.swift /Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/ViewController.swift -primary-file /Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift /Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/StillUIImageProcessor.swift /Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSessionProcessor.swift -target armv7-apple-ios9.2 -enable-objc-interop -sdk /Applications/Xcode.app/Contents/Developer/Platforms/iPhoneOS.platform/Developer/SDKs/iPhoneOS10.0.sdk -I /Users/brianmichel/Development/Personal/Sketchy/build/Debug-iphoneos -F /Users/brianmichel/Development/Personal/Sketchy/build/Debug-iphoneos -enable-testing -g -debug-time-function-bodies -serialize-debugging-options -Xcc -I/Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/swift-overrides.hmap -Xcc -iquote -Xcc /Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/Sketchy-generated-files.hmap -Xcc -I/Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/Sketchy-own-target-headers.hmap -Xcc -I/Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/Sketchy-all-target-headers.hmap -Xcc -iquote -Xcc /Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/Sketchy-project-headers.hmap -Xcc -I/Users/brianmichel/Development/Personal/Sketchy/build/Debug-iphoneos/include -Xcc -I/Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/DerivedSources/armv7 -Xcc -I/Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/DerivedSources -Xcc -DDEBUG=1 -Xcc -working-directory/Users/brianmichel/Development/Personal/Sketchy -emit-module-doc-path /Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/Objects-normal/armv7/CaptureSession~partial.swiftdoc -Onone -module-name Sketchy -emit-module-path /Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/Objects-normal/armv7/CaptureSession~partial.swiftmodule -serialize-diagnostics-path /Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/Objects-normal/armv7/CaptureSession.dia -emit-dependencies-path /Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/Objects-normal/armv7/CaptureSession.d -emit-reference-dependencies-path /Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/Objects-normal/armv7/CaptureSession.swiftdeps -o /Users/brianmichel/Development/Personal/Sketchy/build/Sketchy.build/Debug-iphoneos/Sketchy.build/Objects-normal/armv7/CaptureSession.o -embed-bitcode-marker
      0.1ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:17:21	final get {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:18:21	final get {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:20:21	final get {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:22:21	final get {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:23:21	final get {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:25:21	get {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:25:21	set {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:27:21	get {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:27:21	set {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:29:21	get {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:29:21	set {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:31:14	@objc get {}
      0.0ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:31:14	@objc set {}
      0.1ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:33:47	@objc get {}
      0.7ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:37:47	get {}
      12.2ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:41:59	@objc get {}
      0.3ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:45:14	@objc override init()
      2.6ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:52:15	open func addProcessor(_ processor: CaptureSessionProcessor!)
      0.2ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:56:15	open func removeProcessor(_ processor: CaptureSessionProcessor!)
      0.8ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:66:47	(closure)
      1.4ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:60:15	open func switchCameraInput(_ position: CaptureDevicePosition!) -> Bool!
      2.1ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:82:106	(closure)
      2.5ms	/Users/brianmichel/Development/Personal/Sketchy/Sketchy/Classes/CaptureSession.swift:80:15	@objc open func captureStillImage()
      

      This means that in order to extract the information relevant to compile time complexity, each end user must craft some sort of output parsing logic to extract the relevant logs while not breaking them at the same time.

      I'd like if the Swift compiler was able to accept an option to output the debug-time-function-bodies into a structured data format like XML to make it easy to both locate and parse this data in a machine friendly ways (like for continuous integration environments)

        Attachments

          Activity

          Hide
          modocache Brian Ivan Gesiak added a comment -

          /cc Jordan Rose. Maybe we could hook this up to the serialized diagnostics consumer...? I'd be interested in taking this task on, so if you have any tips I'd love to hear them.

          Show
          modocache Brian Ivan Gesiak added a comment - /cc Jordan Rose . Maybe we could hook this up to the serialized diagnostics consumer...? I'd be interested in taking this task on, so if you have any tips I'd love to hear them.
          Hide
          jrose Jordan Rose added a comment -

          I'm leery of "productizing" -debug-time-function-bodies in any way because it's already not a true story. Import and decl-checking costs that come up for the first time during a particular function get ascribed to that function. SILGen, optimization, and LLVM costs are ignored entirely. Decl-checking costs that are not within a particular function are also ignored.

          The only useful purpose of -debug-time-function-bodies is to see if the type checker is spinning on a particular function.

          Show
          jrose Jordan Rose added a comment - I'm leery of "productizing" -debug-time-function-bodies in any way because it's already not a true story. Import and decl-checking costs that come up for the first time during a particular function get ascribed to that function. SILGen, optimization, and LLVM costs are ignored entirely. Decl-checking costs that are not within a particular function are also ignored. The only useful purpose of -debug-time-function-bodies is to see if the type checker is spinning on a particular function.
          Hide
          brianmichel Brian Michel added a comment -

          Jordan Rose yeah I totally understand this is a debug option (it's even in the name!), but I guess I'm unsure what else to do to keep an eye on Swift compile times in larger applications across an entire team of engineers. Granted, we've already somewhat built tooling around this here, https://github.com/tumblr/SwiftCompilationPerformanceReporter, it'd be nice to see this as a first class feature.

          I would understand that if the larger conversation should be around how to not get into these slow compile paths, or totally eliminating these kinds of possibilities elsewhere in the compiler, but those seems like very long term conversations. I'm also not sure how widespread this problem actually is. We at Tumblr have certainly experienced this, but maybe we're a one off.

          Would love to hear more of your thoughts on the matter.

          Show
          brianmichel Brian Michel added a comment - Jordan Rose yeah I totally understand this is a debug option (it's even in the name!), but I guess I'm unsure what else to do to keep an eye on Swift compile times in larger applications across an entire team of engineers. Granted, we've already somewhat built tooling around this here, https://github.com/tumblr/SwiftCompilationPerformanceReporter , it'd be nice to see this as a first class feature. I would understand that if the larger conversation should be around how to not get into these slow compile paths, or totally eliminating these kinds of possibilities elsewhere in the compiler, but those seems like very long term conversations. I'm also not sure how widespread this problem actually is. We at Tumblr have certainly experienced this, but maybe we're a one off. Would love to hear more of your thoughts on the matter.
          Hide
          modocache Brian Ivan Gesiak added a comment -

          I've seen a fair amount of "how to figure out what's slowing down your Swift compile times" blog posts:

          I think providing structured output to analyze compilation times would help Brian Michel and many others. Maybe -debug-time-function-bodies isn't the best data to format. In that case, perhaps we can provide formatting for a different format (-driver-time-compilation?), or add options for other interesting profile data.

          I would understand that if the larger conversation should be around how to not get into these slow compile paths, or totally eliminating these kinds of possibilities elsewhere in the compiler, but those seems like very long term conversations.

          I agree. I also think these tools would help end users discover situations that lead to slow compilation times, so that they can submit Swift reports for those situations.

          Show
          modocache Brian Ivan Gesiak added a comment - I've seen a fair amount of "how to figure out what's slowing down your Swift compile times" blog posts: https://thatthinginswift.com/debug-long-compile-times-swift/ http://irace.me/swift-profiling I think providing structured output to analyze compilation times would help Brian Michel and many others. Maybe -debug-time-function-bodies isn't the best data to format. In that case, perhaps we can provide formatting for a different format ( -driver-time-compilation ?), or add options for other interesting profile data. I would understand that if the larger conversation should be around how to not get into these slow compile paths, or totally eliminating these kinds of possibilities elsewhere in the compiler, but those seems like very long term conversations. I agree. I also think these tools would help end users discover situations that lead to slow compilation times, so that they can submit Swift reports for those situations.

            People

            • Assignee:
              Unassigned
              Reporter:
              brianmichel Brian Michel
            • Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

              • Created:
                Updated: