Comment by Ben A (JIRA)

Based on Mark's comments here, there may be some cases in which -debug-time-function-bodies isn't reporting type-checking time. In that case, the 40sec number I reported in the description may be an underestimate. I haven't had time to confirm this yet.

I think you mean "type-checked" rather than "parsed".

As part of chasing this down, someone could consider getting accessors to print more nicely in the output of -debug-time-function-bodies. The SourceLoc is the important thing, though.

Comment by Ben A (JIRA)

What kind of additional information would be useful? The SourceLoc is already logged. I should have mentioned that I omitted it because I didn't think that info would be useful in aggregate (i.e. each line has a different SourceLoc, and knowing that for my project would probably just be noise here). Were you looking for something to the effect of: "these are mostly properties with access level <level>", "are mostly of type <t>", etc.?

Those are all things I can easily collect in my script, since I have the SourceLoc available, while I file another ticket to add extra, needed information for the log.

Oh, not for us, or for any real analysis, just to make the output a little prettier. "getter for 'foo'" instead of just "get".

Comment by Ben A (JIRA)

Ah gotcha. Filed SR-2910

Comment by Ben A (JIRA)

Confirmed that this only happens when you pass the -module-name flag to swiftc. I have a lot of time at the end of this week (long flight) to stare at this. If anyone has any tips for where to start looking in terms of how/where swiftc changes when a module name is specified, that'd be helpful!

That makes absolutely no sense. Every module has a name; it's just that that name is sometimes inferred and sometimes explicit. How did you confirm this?

Comment by Ben A (JIRA)

Oh your right. I thought the only difference between the two commands I was running was the -module-name flag, but it now seems like that incorrect. Here's the concrete example:

test_file1.swift:

class B {
    let a: A
    init() {
        a = A(s: "test")
    }
}

test_file2.swift:

struct A {
    let s: String
}

Here are the 2 similar commands and their varying outputs:

1. swift -frontend -debug-time-function-bodies -c test_file2.swift test_file1.swift yields:

1.4ms test_file2.swift:2:9 get {}
0.2ms test_file1.swift:2:9 final get {}
14.1ms test_file1.swift:3:5 init()
0.0ms test_file1.swift:1:7 @objc deinit

2. swiftc -c test_file1.swift test_file2.swift -module-name test -Xfrontend -debug-time-function-bodies yields:

0.4ms test_file1.swift:2:9 final get {}
18.7ms test_file1.swift:3:5 init()
0.0ms test_file1.swift:1:7 @objc deinit
0.1ms test_file2.swift:2:9 get {}
1.5ms test_file2.swift:2:9 get {}

In 2, test_file2.swift:2:9 is type-checked twice, whereas it's only type checked once in 1. I'm still not quite sure why these 2 commands have different output though (note: even though the order of the file list is different for the two commands, re-ordering the list has no effect).

Order of files sounds much more plausible (and still a problem, of course). Thanks, Ben.

Comment by Ben A (JIRA)

Sorry to clarify, I meant that file order here has no impact. You can reorder the files in either command and get the same results, in terms of number of times each method is type-checked.

Comment by Ben A (JIRA)

That still leaves the question: what is different about these two commands that would cause one to type-check properties fewer times?

Comment by Graydon Hoare (JIRA)

The first invocation is passing -frontend which means that it's bypassing the driver and running a single frontend job; the second invocation is hitting the driver which is then running two frontend jobs (one for each file) and you're seeing the output of the two runs concatenated.

(To be clear: there looks to be some redundant work in the typechecker, in terms of checking synthesized get/set bodies merely referenced from another file, but that redundant work is not quite as quadratic as it might seem from this example; it's only checking each synthesized body once per frontend run. I am currently investigating ways to limit this.)

Comment by Steven Sheldon (JIRA)

I think we were seeing the synthesized bodies checked once per file, on the mailing list Ben mentioned:

[...] I found that we have 2521 properties that are parsed 607 times each. [...] In the main target, there are 607 .swift files

Does Xcode use a frontend job per Swift file?

Ah, wow, I completely missed that. Yes, a non-whole-module build uses one frontend process per .swift file. (Additionally, calling the frontend directly is unsupported.)

@rudkx has actually already fixed some of this redundant work, and as graydon (JIRA User) said he's looking into more cases of it.

Comment by Ben A (JIRA)

Ah okay that makes sense. Thanks!

Comment by Graydon Hoare (JIRA)

A PR that seems to fix it is here: #5588

Comment by Graydon Hoare (JIRA)

Merged 9351843

Comment by Ben A (JIRA)

Awesome