Skip to content

Commit 8eb931d

Browse files
abertelrudabertelrud
authored
[Sema] Playground transform should also log function and closure parameter values (#63929)
Add logging of function and closure parameter values when the playground transform is enabled and its "high-performance" mode is off. MOTIVATION The goal of the optional "playground transform" step in Sema is to instrument the code by inserting calls to `__builtin_log()` and similar log functions, in order to record the execution of the compiled code. Some IDEs (such as Xcode) enable this transform by passing -playground and provide implementations of the logger functions that record information that can then be shown in the IDE. The playground transform currently logs variable assignments and return statements, but it doesn't log the input parameters received by functions and closures. Knowing these values can be very useful in order to understand the behaviour of functions and closures. CHANGES - add a `ParameterList` parameter to `InstrumenterSupport::transformBraceStmt()` - this is an optional parameter list that, if given, specifies the parameters that should be logged at the start of the brace statement - this has to be passed into the function because it comes from the owner of the BraceStmt - adjust `PlaygroundTransform.cpp` to make use of this list - the transform will insert calls to `__builtin_log()` for each of the parameters, in order - adjust `PCMacro.cpp` to accept the parameter, though this instrumenter doesn't currently make use of the new information - add two new unit tests (one for functions and one for closures) - adjust four existing unit tests to account for the new log calls REMARKS - this is currently guarded by the existing "high performance" option (parameter logging is omitted in that case) rdar://104974072
1 parent afa76e2 commit 8eb931d

10 files changed

+168
-12
lines changed

‎lib/Sema/InstrumenterSupport.h

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -49,6 +49,7 @@ class InstrumenterBase {
4949
virtual ~InstrumenterBase() = default;
5050
virtual void anchor();
5151
virtual BraceStmt *transformBraceStmt(BraceStmt *BS,
52+
const ParameterList *PL = nullptr,
5253
bool TopLevel = false) = 0;
5354

5455
/// Create an expression which retrieves a valid ModuleIdentifier or
@@ -79,7 +80,8 @@ class InstrumenterBase {
7980
if (auto *CE = dyn_cast<ClosureExpr>(E)) {
8081
BraceStmt *B = CE->getBody();
8182
if (B) {
82-
BraceStmt *NB = I.transformBraceStmt(B);
83+
const ParameterList *PL = CE->getParameters();
84+
BraceStmt *NB = I.transformBraceStmt(B, PL);
8385
CE->setBody(NB, false);
8486
// just with the entry and exit logging this is going to
8587
// be more than a single expression!

‎lib/Sema/PCMacro.cpp

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -337,7 +337,8 @@ class Instrumenter : InstrumenterBase {
337337
return D;
338338
if (auto *FD = dyn_cast<FuncDecl>(D)) {
339339
if (BraceStmt *B = FD->getBody()) {
340-
BraceStmt *NB = transformBraceStmt(B);
340+
const ParameterList *PL = FD->getParameters();
341+
BraceStmt *NB = transformBraceStmt(B, PL);
341342
// Since it would look strange going straight to the first line in a
342343
// function body, we throw in a before/after pointing at the function
343344
// decl at the start of the transformed body
@@ -366,7 +367,9 @@ class Instrumenter : InstrumenterBase {
366367
return D;
367368
}
368369

369-
BraceStmt *transformBraceStmt(BraceStmt *BS, bool TopLevel = false) override {
370+
BraceStmt *transformBraceStmt(BraceStmt *BS,
371+
const ParameterList *PL = nullptr,
372+
bool TopLevel = false) override {
370373
ArrayRef<ASTNode> OriginalElements = BS->getElements();
371374
SmallVector<swift::ASTNode, 3> Elements(OriginalElements.begin(),
372375
OriginalElements.end());
@@ -692,7 +695,7 @@ void swift::performPCMacro(SourceFile &SF) {
692695
if (!TLCD->isImplicit()) {
693696
if (BraceStmt *Body = TLCD->getBody()) {
694697
Instrumenter I(ctx, TLCD, TmpNameIndex);
695-
BraceStmt *NewBody = I.transformBraceStmt(Body, true);
698+
BraceStmt *NewBody = I.transformBraceStmt(Body, nullptr, true);
696699
if (NewBody != Body) {
697700
TLCD->setBody(NewBody);
698701
TypeChecker::checkTopLevelEffects(TLCD);

‎lib/Sema/PlaygroundTransform.cpp

Lines changed: 29 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -290,8 +290,9 @@ class Instrumenter : InstrumenterBase {
290290
return D;
291291
if (auto *FD = dyn_cast<FuncDecl>(D)) {
292292
if (BraceStmt *B = FD->getBody()) {
293+
const ParameterList *PL = FD->getParameters();
293294
TargetKindSetter TKS(BracePairs, BracePair::TargetKinds::Return);
294-
BraceStmt *NB = transformBraceStmt(B);
295+
BraceStmt *NB = transformBraceStmt(B, PL);
295296
if (NB != B) {
296297
FD->setBody(NB, AbstractFunctionDecl::BodyKind::TypeChecked);
297298
TypeChecker::checkFunctionEffects(FD);
@@ -380,7 +381,9 @@ class Instrumenter : InstrumenterBase {
380381
return uniqueRef;
381382
}
382383

383-
BraceStmt *transformBraceStmt(BraceStmt *BS, bool TopLevel = false) override {
384+
BraceStmt *transformBraceStmt(BraceStmt *BS,
385+
const ParameterList *PL = nullptr,
386+
bool TopLevel = false) override {
384387
ArrayRef<ASTNode> OriginalElements = BS->getElements();
385388
using ElementVector = SmallVector<swift::ASTNode, 3>;
386389
ElementVector Elements(OriginalElements.begin(), OriginalElements.end());
@@ -593,6 +596,27 @@ class Instrumenter : InstrumenterBase {
593596
}
594597
}
595598

599+
// If we were given any parameters that apply to this brace block, we insert
600+
// log calls for them now (before any of the other statements). We only log
601+
// named parameters (not `{ _ in ... }`, for example).
602+
if (PL && !HighPerformance) {
603+
size_t EI = 0;
604+
for (const auto &PD : *PL) {
605+
if (PD->hasName()) {
606+
DeclBaseName Name = PD->getName();
607+
Expr *PVVarRef = new (Context)
608+
DeclRefExpr(PD, DeclNameLoc(), /*implicit=*/true,
609+
AccessSemantics::Ordinary, PD->getType());
610+
Added<Stmt *> Log(buildLoggerCall(PVVarRef, PD->getSourceRange(),
611+
Name.getIdentifier().str()));
612+
if (*Log) {
613+
Elements.insert(Elements.begin() + EI, *Log);
614+
EI++;
615+
}
616+
}
617+
}
618+
}
619+
596620
if (!TopLevel && !HighPerformance && !BS->isImplicit()) {
597621
Elements.insert(Elements.begin(), *buildScopeEntry(BS->getSourceRange()));
598622
Elements.insert(Elements.end(), *buildScopeExit(BS->getSourceRange()));
@@ -869,8 +893,9 @@ void swift::performPlaygroundTransform(SourceFile &SF, bool HighPerformance) {
869893
if (auto *FD = dyn_cast<AbstractFunctionDecl>(D)) {
870894
if (!FD->isImplicit()) {
871895
if (BraceStmt *Body = FD->getBody()) {
896+
const ParameterList *PL = FD->getParameters();
872897
Instrumenter I(ctx, FD, RNG, HighPerformance, TmpNameIndex);
873-
BraceStmt *NewBody = I.transformBraceStmt(Body);
898+
BraceStmt *NewBody = I.transformBraceStmt(Body, PL);
874899
if (NewBody != Body) {
875900
FD->setBody(NewBody, AbstractFunctionDecl::BodyKind::TypeChecked);
876901
TypeChecker::checkFunctionEffects(FD);
@@ -882,7 +907,7 @@ void swift::performPlaygroundTransform(SourceFile &SF, bool HighPerformance) {
882907
if (!TLCD->isImplicit()) {
883908
if (BraceStmt *Body = TLCD->getBody()) {
884909
Instrumenter I(ctx, TLCD, RNG, HighPerformance, TmpNameIndex);
885-
BraceStmt *NewBody = I.transformBraceStmt(Body, true);
910+
BraceStmt *NewBody = I.transformBraceStmt(Body, nullptr, true);
886911
if (NewBody != Body) {
887912
TLCD->setBody(NewBody);
888913
TypeChecker::checkTopLevelEffects(TLCD);

‎test/IRGen/playground.swift

Lines changed: 7 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -9,10 +9,13 @@ import Swift
99

1010
@objc class C { }
1111

12-
private func __builtin_log_scope_entry(_ startLine: Int, _ startColumn: Int,
13-
_ endLine: Int, _ endColumn: Int, _ moduleID: Int, _ fileID: Int) { }
14-
private func __builtin_log_scope_exit(_ startLine: Int, _ startColumn: Int,
15-
_ endLine: Int, _ endColumn: Int, _ moduleID: Int, _ fileID: Int) { }
12+
private func __builtin_log_with_id<T>(_ object: T, _ name: String, _ id: Int,
13+
_ startLine: Int, _ endLine: Int, _ startColumn: Int, _ endColumn: Int,
14+
_ moduleId : Int, _ fileId : Int) -> AnyObject? { return .none }
15+
private func __builtin_log_scope_entry(_ startLine: Int, _ endLine: Int,
16+
_ startColumn: Int, _ endColumn: Int, _ moduleID: Int, _ fileID: Int) { }
17+
private func __builtin_log_scope_exit(_ startLine: Int, _ endLine: Int,
18+
_ startColumn: Int, _ endColumn: Int, _ moduleID: Int, _ fileID: Int) { }
1619
private func __builtin_send_data<T>(_ object: T) { }
1720

1821
public func anchor() {}

‎test/PlaygroundTransform/closure_parameters.swift

Lines changed: 60 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,60 @@
1+
// RUN: %empty-directory(%t)
2+
// RUN: cp %s %t/main.swift
3+
// RUN: %target-build-swift -whole-module-optimization -module-name PlaygroundSupport -emit-module-path %t/PlaygroundSupport.swiftmodule -parse-as-library -c -o %t/PlaygroundSupport.o %S/Inputs/SilentPCMacroRuntime.swift %S/Inputs/PlaygroundsRuntime.swift
4+
// RUN: %target-build-swift -Xfrontend -playground -Xfrontend -debugger-support -o %t/main -I=%t %t/PlaygroundSupport.o %t/main.swift
5+
// RUN: %target-codesign %t/main
6+
// RUN: %target-run %t/main | %FileCheck %s
7+
// RUN: %target-build-swift -Xfrontend -pc-macro -Xfrontend -playground -Xfrontend -debugger-support -o %t/main2 -I=%t %t/PlaygroundSupport.o %t/main.swift
8+
// RUN: %target-codesign %t/main2
9+
// RUN: %target-run %t/main2 | %FileCheck %s
10+
// REQUIRES: executable_test
11+
12+
import PlaygroundSupport
13+
14+
// Both implicitly named and explicitly named parameters are logged.
15+
let foo = [1, 2, 3, 4, 5].filter { $0 % 2 == 1 }.map { x in "\(x)" }
16+
17+
// Unnamed parameters do are not logged.
18+
["A", "B", "C"].map { _ in 1 }
19+
20+
// CHECK: {{.*}} __builtin_log_scope_entry
21+
// CHECK-NEXT: {{.*}} __builtin_log[$0='1']
22+
// CHECK-NEXT: {{.*}} __builtin_log[='true']
23+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
24+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
25+
// CHECK-NEXT: {{.*}} __builtin_log_scope_entry
26+
// CHECK-NEXT: {{.*}} __builtin_log[$0='2']
27+
// CHECK-NEXT: {{.*}} __builtin_log[='false']
28+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
29+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
30+
// CHECK-NEXT: {{.*}} __builtin_log_scope_entry
31+
// CHECK-NEXT: {{.*}} __builtin_log[$0='3']
32+
// CHECK-NEXT: {{.*}} __builtin_log[='true']
33+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
34+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
35+
// CHECK-NEXT: {{.*}} __builtin_log_scope_entry
36+
// CHECK-NEXT: {{.*}} __builtin_log[$0='4']
37+
// CHECK-NEXT: {{.*}} __builtin_log[='false']
38+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
39+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
40+
// CHECK-NEXT: {{.*}} __builtin_log_scope_entry
41+
// CHECK-NEXT: {{.*}} __builtin_log[$0='5']
42+
// CHECK-NEXT: {{.*}} __builtin_log[='true']
43+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
44+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
45+
// CHECK-NEXT: {{.*}} __builtin_log_scope_entry
46+
// CHECK-NEXT: {{.*}} __builtin_log[x='1']
47+
// CHECK-NEXT: {{.*}} __builtin_log[='1']
48+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
49+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
50+
// CHECK-NEXT: {{.*}} __builtin_log_scope_entry
51+
// CHECK-NEXT: {{.*}} __builtin_log[x='3']
52+
// CHECK-NEXT: {{.*}} __builtin_log[='3']
53+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
54+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
55+
// CHECK-NEXT: {{.*}} __builtin_log_scope_entry
56+
// CHECK-NEXT: {{.*}} __builtin_log[x='5']
57+
// CHECK-NEXT: {{.*}} __builtin_log[='5']
58+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
59+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
60+
// CHECK-NEXT: {{.*}} __builtin_log[foo='["1", "3", "5"]']

‎test/PlaygroundTransform/function_parameters.swift

Lines changed: 50 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,50 @@
1+
// RUN: %empty-directory(%t)
2+
// RUN: cp %s %t/main.swift
3+
// RUN: %target-build-swift -whole-module-optimization -module-name PlaygroundSupport -emit-module-path %t/PlaygroundSupport.swiftmodule -parse-as-library -c -o %t/PlaygroundSupport.o %S/Inputs/SilentPCMacroRuntime.swift %S/Inputs/PlaygroundsRuntime.swift
4+
// RUN: %target-build-swift -Xfrontend -playground -Xfrontend -debugger-support -o %t/main -I=%t %t/PlaygroundSupport.o %t/main.swift
5+
// RUN: %target-codesign %t/main
6+
// RUN: %target-run %t/main | %FileCheck %s
7+
// RUN: %target-build-swift -Xfrontend -pc-macro -Xfrontend -playground -Xfrontend -debugger-support -o %t/main2 -I=%t %t/PlaygroundSupport.o %t/main.swift
8+
// RUN: %target-codesign %t/main2
9+
// RUN: %target-run %t/main2 | %FileCheck %s
10+
// REQUIRES: executable_test
11+
12+
import PlaygroundSupport
13+
14+
// Labeled, unlabeled, and multi-value parameters are logged.
15+
func f(x: Int, _ y: Float = 7.62, z: String...) -> Int {
16+
func g(w: (Int, Int)) -> Int {
17+
func h(v: Int) -> Int {
18+
return v + 1
19+
}
20+
return h(v: w.0) + h(v: w.1) + 1
21+
}
22+
return x + z.count + g(w: (1, 2))
23+
}
24+
let foo = f(x: 42, z: "hello", "world")
25+
26+
// Unnamed parameters do are not logged.
27+
func f(_: Int) -> Int {
28+
return 42
29+
}
30+
let bar = f(21)
31+
32+
// CHECK: {{.*}} __builtin_log_scope_entry
33+
// CHECK-NEXT: {{.*}} __builtin_log[x='42']
34+
// CHECK-NEXT: {{.*}} __builtin_log[y='7.62']
35+
// CHECK-NEXT: {{.*}} __builtin_log[z='["hello", "world"]']
36+
// CHECK-NEXT: {{.*}} __builtin_log_scope_entry
37+
// CHECK-NEXT: {{.*}} __builtin_log[w='(1, 2)']
38+
// CHECK-NEXT: {{.*}} __builtin_log_scope_entry
39+
// CHECK-NEXT: {{.*}} __builtin_log[v='1']
40+
// CHECK-NEXT: {{.*}} __builtin_log[='2']
41+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
42+
// CHECK-NEXT: {{.*}} __builtin_log_scope_entry
43+
// CHECK-NEXT: {{.*}} __builtin_log[v='2']
44+
// CHECK-NEXT: {{.*}} __builtin_log[='3']
45+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
46+
// CHECK-NEXT: {{.*}} __builtin_log[='6']
47+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
48+
// CHECK-NEXT: {{.*}} __builtin_log[='50']
49+
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
50+
// CHECK-NEXT: {{.*}} __builtin_log[foo='50']

‎test/PlaygroundTransform/generics.swift

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,18 +21,21 @@ for i in 0..<3 {
2121

2222
// CHECK: __builtin_log_scope_entry
2323
// CHECK-NEXT: __builtin_log_scope_entry
24+
// CHECK-NEXT: __builtin_log[t='0']
2425
// CHECK-NEXT: __builtin_log[='0']
2526
// CHECK-NEXT: __builtin_log_scope_exit
2627
// CHECK-NEXT: __builtin_log[='0']
2728
// CHECK-NEXT: __builtin_log_scope_exit
2829
// CHECK-NEXT: __builtin_log_scope_entry
2930
// CHECK-NEXT: __builtin_log_scope_entry
31+
// CHECK-NEXT: __builtin_log[t='1']
3032
// CHECK-NEXT: __builtin_log[='1']
3133
// CHECK-NEXT: __builtin_log_scope_exit
3234
// CHECK-NEXT: __builtin_log[='1']
3335
// CHECK-NEXT: __builtin_log_scope_exit
3436
// CHECK-NEXT: __builtin_log_scope_entry
3537
// CHECK-NEXT: __builtin_log_scope_entry
38+
// CHECK-NEXT: __builtin_log[t='2']
3639
// CHECK-NEXT: __builtin_log[='2']
3740
// CHECK-NEXT: __builtin_log_scope_exit
3841
// CHECK-NEXT: __builtin_log[='2']

‎test/PlaygroundTransform/implicit_return_func_binaryoperation_args.swift

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,8 @@ func add<I : SignedNumeric>(_ lhs: I, _ rhs: I) -> I {
1616
}
1717
add(3, 4)
1818
// CHECK: {{.*}} __builtin_log_scope_entry
19+
// CHECK-NEXT: {{.*}} __builtin_log[lhs='3']
20+
// CHECK-NEXT: {{.*}} __builtin_log[rhs='4']
1921
// CHECK-NEXT: {{.*}} __builtin_log[='7']
2022
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
2123
// CHECK-NEXT: {{.*}} __builtin_log[='7']

‎test/PlaygroundTransform/implicit_return_func_is.swift

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,10 +17,14 @@ func iss<T>(_ instance: Any, anInstanceOf type: T.Type) -> Bool {
1717
iss("hello", anInstanceOf: String.self)
1818
iss(57, anInstanceOf: String.self)
1919
// CHECK: {{.*}} __builtin_log_scope_entry
20+
// CHECK-NEXT: {{.*}} __builtin_log[instance='hello']
21+
// CHECK-NEXT: {{.*}} __builtin_log[type='String']
2022
// CHECK-NEXT: {{.*}} __builtin_log[='true']
2123
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
2224
// CHECK-NEXT: {{.*}} __builtin_log[='true']
2325
// CHECK: {{.*}} __builtin_log_scope_entry
26+
// CHECK-NEXT: {{.*}} __builtin_log[instance='57']
27+
// CHECK-NEXT: {{.*}} __builtin_log[type='String']
2428
// CHECK-NEXT: {{.*}} __builtin_log[='false']
2529
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
2630
// CHECK-NEXT: {{.*}} __builtin_log[='false']

‎test/PlaygroundTransform/implicit_return_subscript_chain.swift

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -33,15 +33,19 @@ s[13]
3333
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
3434

3535
// CHECK: {{.*}} __builtin_log_scope_entry
36+
// CHECK-NEXT: {{.*}} __builtin_log[newValue='Optional(33)']
37+
// CHECK-NEXT: {{.*}} __builtin_log[int='13']
3638
// CHECK-NEXT: {{.*}} __builtin_log[='Optional(Optional(33))']
3739
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
3840

3941
// CHECK: {{.*}} __builtin_log_scope_entry
42+
// CHECK-NEXT: {{.*}} __builtin_log[int='14']
4043
// CHECK-NEXT: {{.*}} __builtin_log[='Optional(14)']
4144
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
4245
// CHECK-NEXT: {{.*}} __builtin_log[='Optional(14)']
4346

4447
// CHECK: {{.*}} __builtin_log_scope_entry
48+
// CHECK-NEXT: {{.*}} __builtin_log[int='13']
4549
// CHECK-NEXT: {{.*}} __builtin_log[='Optional(33)']
4650
// CHECK-NEXT: {{.*}} __builtin_log_scope_exit
4751
// CHECK-NEXT: {{.*}} __builtin_log[='Optional(33)']

0 commit comments

Comments
 (0)