I've opened a few jira tickets: - https://bugs.swift.org/browse/SR-2901 for this bug (has some numbers on the impact in our project) - https://bugs.swift.org/browse/SR-2902 for adding the expression type checker timer, since it's looking like I won't have time to get to in the next 2 weeks
I've also opened a PR to increase the number of decimal places logged by -debug-time-function-bodies from 1 to 3, which was useful to determine the impact of the bug in SR-2901 (i.e. functions that less than 0.1ms to parse, but are parsed many times), here: https://github.com/apple/swift/pull/5200. Thanks again! Ben On Sat, Oct 8, 2016 at 10:34 AM, Ben Asher <benashe...@gmail.com> wrote: > Okay great I'll open one soon! And just to clarify, that 2521 number is > counting the generated setters and getters (there are fewer number of > actual lines of "let" and "var" property code). > > In the main target, there are 607 .swift files (guess we can deduce that > those properties are parsed once per file in the target) and 2012 .m files. > The build times I mentioned earlier (~7min) were debug builds after > cleaning only for the main target (not including test targets). Building > the main target after a clean requires building some framework and > extension targets (iOS extensions), but those are built pretty quickly and > are small. > > Ben > > On Sat, Oct 8, 2016 at 12:04 AM, Mark Lacey <mark.la...@apple.com> wrote: > >> >> On Oct 7, 2016, at 2:35 PM, Ben Asher <benashe...@gmail.com> wrote: >> >> Hello again! I wanted to follow up with some more numbers and feedback. I >> wasn't able to easily compile a single file from our project from the CLI. >> I started putting together a command with all of the necessary framework >> includes, flags, etc., but I moved on because it was taking awhile, >> becoming a mess, and figured the other suggestions might yield results >> quicker. >> >> Moving on, I took a second look at the -debug-time-function-bodies output >> as Mark suggested, and I found that we have 2521 properties that are parsed >> 607 times each. If we got that down to the ideal case of parsing each one >> of those properties once, that would save us ~1.5 million "parses". So, is >> there a ticket already for this issue? I didn't see one when I searched, >> but it does sound like it's known. >> >> >> The fact that we type check the bodies of synthesized accessors multiple >> times is something a handful of people are aware of, but I’m not aware of >> any JIRA bug for it so it would be great to open one if you get a chance. >> >> Out of curiosity, how many files are in your project, and how long does a >> clean build take (debug build, without optimizations)? >> >> Mark >> >> >> I do plan on at least taking a look at adding the suggested timers, but >> that will likely take me into next week or longer depending on what else I >> have going on. >> >> Thanks! >> >> Ben >> >> On Wed, Oct 5, 2016 at 4:31 PM, Ben Asher <benashe...@gmail.com> wrote: >> >>> Ah this is all super helpful. I'll do some more profiling and try to get >>> back with some data in the next several days. >>> >>> Thanks! >>> >>> Ben >>> >>> On Wed, Oct 5, 2016 at 4:28 PM, Mark Lacey <mark.la...@apple.com> wrote: >>> >>>> >>>> On Oct 5, 2016, at 3:37 PM, Ben Asher <benashe...@gmail.com> wrote: >>>> >>>> I just tried with both Xcode 8.1 beta 2 and Xcode 8.0, and 8.1b2 seems >>>> maybe 15s faster (to build our main huge target): 7m28s compared to 7m43s. >>>> It's some improvement, but I'm not exactly sure what kind of improvement >>>> was expected. >>>> >>>> >>>> The kind of benefit you might expect really depends on the specific >>>> code you’ve written. The changes I have in mind attempt to speed up the >>>> expression type checker (the thing that does the work of inferring types >>>> for a given expression, and the case where there is an explicit type the >>>> expression needs to type-check to, ensuring that it does). These >>>> expressions include things like array literals and dictionary literals, >>>> where we sometimes take a long time to type check. >>>> >>>> Is there any profiling/tracing you all would recommend to help find >>>> problem areas? >>>> >>>> >>>> If you’re looking for problem areas in your particular build, I have a >>>> couple suggestions: >>>> >>>> 1. Take a look at the output of -debug-time-function-bodies to see if >>>> the same function is getting type checked multiple times, and determine >>>> what the cumulative time for those functions is. >>>> >>>> For example below is the output I see for a simple test case. Note that >>>> the getter/setter that are generated from a property on line 2 of two.swift >>>> are type checked twice. Although in this case we type check the individual >>>> functions very quickly, if you have enough of this kind of redundant type >>>> checking happening, it can add up. This *particular* case is a known bug >>>> that we hope to address - the synthesized getters/setters for properties >>>> are type checked in each file they are referenced in. >>>> >>>> There may be other cases like this that we’re not already aware of, so >>>> it’s always good to open a bug if you find something like this. >>>> >>>> swiftc -c main.swift two.swift -module-name test -Xfrontend >>>> -debug-time-function-bodies >>>> 0.2ms main.swift:2:7 get {} >>>> 0.2ms main.swift:2:7 set {} >>>> 0.0ms main.swift:1:7 @objc deinit >>>> 0.3ms main.swift:1:13 override init() >>>> 0.2ms two.swift:2:14 get {} >>>> 0.2ms two.swift:2:14 set {} >>>> 0.2ms two.swift:2:14 get {} >>>> 0.2ms two.swift:2:14 set {} >>>> 0.0ms two.swift:1:14 @objc deinit >>>> 0.0ms two.swift:1:14 init() >>>> >>>> 2. Add a timer for expression type checking and see if that helps >>>> narrow down whether there is time being spent type checking expressions >>>> that isn’t accounted for in -debug-time-function-bodies. There are a few >>>> places that might make sense for this, but I suspect >>>> ConstraintSystem::solve() >>>> might be the best. This is ultimately called from a variety of places, and >>>> would provide the most insight into where time is being spent in the >>>> expression type checking. It’s possible something higher up the stack, like >>>> TypeChecker::solveForExpression or TypeChecker::typeCheckExpression() >>>> might make more sense as well. You can model this on how >>>> -debug-time-function-bodies is currently implemented, e.g. look >>>> at swift::performTypeChecking for some help on getting started. I’ll >>>> probably try to add this timer myself in the next few weeks if you don’t >>>> manage to beat me to it. >>>> >>>> Mark >>>> >>>> >>>> I don't mind building from Swift master, using someone's preferred >>>> profiling tools, etc. I'm not really sure where to start. >>>> >>>> Ben >>>> >>>> On Wed, Oct 5, 2016 at 1:05 PM, Ben Asher <benashe...@gmail.com> wrote: >>>> >>>>> Apologies for not starting off with system info: macOS Sierra >>>>> (10.12.0), Xcode 8.0 (from the App Store). >>>>> >>>>> I'll try with Xcode 8.1 beta this afternoon and report back. Ill also >>>>> open a ticket for improving -debug-time-function-bodies if I can confirm >>>>> anything. >>>>> >>>>> Thanks! >>>>> >>>>> Ben >>>>> >>>>> On Wed, Oct 5, 2016 at 1:00 PM, Mark Lacey <mark.la...@apple.com> >>>>> wrote: >>>>> >>>>>> >>>>>> On Oct 4, 2016, at 2:38 PM, Ben Asher via swift-dev < >>>>>> swift-dev@swift.org> wrote: >>>>>> >>>>>> Hello! I work with a large project (~900 .swift files and more .m >>>>>> files). We have a nightly job that compiles the app and calls out >>>>>> function >>>>>> bodies (using -debug-time-function-bodies) that are slower than >>>>>> 100ms to compile. Since upgrading to Swift 3, the number of trouble >>>>>> function bodies has one from > 150 to < 20, so we're really happy about >>>>>> that! The only issue though is that build time overall increased by ~1 >>>>>> min >>>>>> (amount of time to build all targets before automatically merging to >>>>>> master >>>>>> in our integration build). >>>>>> >>>>>> >>>>>> Is this using a particular release of Xcode (8.0 or an 8.1 beta?), or >>>>>> with one of the toolchain builds from swift.org? >>>>>> >>>>>> Xcode 8.1 beta 2 includes some type checker performance improvements >>>>>> which might have an impact here. >>>>>> >>>>>> >>>>>> To dig into this further, we've started a new nightly job that builds >>>>>> the app using the -debug-time-compilation flag, and using that we've >>>>>> found >>>>>> that some files take as long as 2-3 seconds to compile. But, there's no >>>>>> targeted output to help us get this down via the >>>>>> -debug-time-function-bodies flag (i.e. no function bodies that we can >>>>>> refactor to get compile times much faster). >>>>>> >>>>>> >>>>>> One thing to look out for here is that I believe there are some cases >>>>>> where -debug-time-function-bodies isn’t reporting type checking time. >>>>>> From >>>>>> my (potentially faulty) recollection, things like let bindings with >>>>>> literals or closures on the right hand side do not show up in the >>>>>> -debug-time-function-bodies output, and depending on the specifics of the >>>>>> expression these can sometimes take a long time to type check. When these >>>>>> appear within the body of another type declaration they can end up >>>>>> getting >>>>>> type checked multiple times during a full project build, and that time >>>>>> can >>>>>> add up. >>>>>> >>>>>> I don’t believe there is a bug open for improving >>>>>> -debug-time-function-bodies to help diagnose this, but opening a bug >>>>>> would >>>>>> be appreciated if you can confirm that this is the case, and of course >>>>>> patches to fix it are definitely welcome as well. >>>>>> >>>>>> Mark >>>>>> >>>>>> We can see that most of the time is spent in "Type checking / >>>>>> Semantic analysis" for these problem files, but we don't currently have >>>>>> any >>>>>> way of knowing what that means. It feels like we've exhausted the >>>>>> available >>>>>> options at this point (unless there are other flags I'm missing) in terms >>>>>> of existing actionable debugging/profiling/reporting, so now our question >>>>>> is this: what kind of reports would Swift maintainers be interested in >>>>>> seeing in terms of output from profiling tools, etc. to help >>>>>> debug/diagnose >>>>>> these slow compile issues? We're willing to devote time to tooling to >>>>>> help >>>>>> generate such reports and file bugs. >>>>>> >>>>>> Thanks! >>>>>> >>>>>> Ben >>>>>> _______________________________________________ >>>>>> swift-dev mailing list >>>>>> swift-dev@swift.org >>>>>> https://lists.swift.org/mailman/listinfo/swift-dev >>>>>> >>>>>> >>>>>> >>>>> >>>>> >>>>> -- >>>>> -Ben >>>>> >>>> >>>> >>>> >>>> -- >>>> -Ben >>>> >>>> >>>> >>> >>> >>> -- >>> -Ben >>> >> >> >> >> -- >> -Ben >> >> >> > > > -- > -Ben > -- -Ben
_______________________________________________ swift-dev mailing list swift-dev@swift.org https://lists.swift.org/mailman/listinfo/swift-dev
