Profiling framework: core performance-logging implementation (#3238)

* profiling instrumentation

* Support native testing with mock impl of `mod js`

* Add benchmarks

* Wrapper: support methods.

* `#[profile]`: work in any context

* feature-gate lineno info that breaks IDE

* Support async; more docs; add perf analysis

* docs & formatting
This commit is contained in:
Kaz Wesley 2022-02-10 09:24:29 -08:00 committed by GitHub
parent 63ecadc421
commit b0b035e73d
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 1419 additions and 126 deletions

20
Cargo.lock generated
View File

@ -954,6 +954,7 @@ dependencies = [
"enso-frp",
"enso-logger",
"enso-prelude",
"enso-profiler",
"enso-shapely",
"enso-text",
"enso-web",
@ -1056,6 +1057,25 @@ dependencies = [
"web-sys",
]
[[package]]
name = "enso-profiler"
version = "0.1.0"
dependencies = [
"enso-profiler-macros",
"futures 0.3.17",
"wasm-bindgen",
]
[[package]]
name = "enso-profiler-macros"
version = "0.1.0"
dependencies = [
"Inflector",
"proc-macro2 1.0.32",
"quote 1.0.10",
"syn",
]
[[package]]
name = "enso-shapely"
version = "0.2.0"

View File

@ -72,6 +72,8 @@ members = [
"lib/rust/parser/ast",
"lib/rust/parser/flexer",
"lib/rust/prelude",
"lib/rust/profiler",
"lib/rust/profiler/macros",
"lib/rust/parser/flexer-testing/definition",
"lib/rust/parser/flexer-testing/generation",
"lib/rust/parser/lexer/definition",

View File

@ -17,6 +17,7 @@ enso-debug-scene = { path = "view/debug_scene" }
enso-frp = { path = "../../lib/rust/frp" }
enso-logger = { path = "../../lib/rust/logger"}
enso-prelude = { path = "../../lib/rust/prelude"}
enso-profiler = { path = "../../lib/rust/profiler" }
enso-shapely = { path = "../../lib/rust/shapely/impl"}
enso-text = { path = "../../lib/rust/text" }
enso-web = { path = "../../lib/rust/web" }

View File

@ -510,9 +510,9 @@
"integrity": "sha512-77EbyPPpMz+FRFRuAFlWMtmgUWGe9UOG2Z25NqCwiIjRhOf5iKGuzSe5P2w1laq+FkRy4p+PCuVkJSGkzTEKVw=="
},
"node_modules/@firebase/firestore": {
"version": "2.4.0",
"resolved": "https://registry.npmjs.org/@firebase/firestore/-/firestore-2.4.0.tgz",
"integrity": "sha512-PQ6+lWNrvh74GvFTHT4gCutFipDmtu8D1tNNawKe+/SyL6XFgeuMYgZIpKQgkTSezVDogC7EGQTJBFnewF9pOg==",
"version": "2.4.1",
"resolved": "https://registry.npmjs.org/@firebase/firestore/-/firestore-2.4.1.tgz",
"integrity": "sha512-S51XnILdhNt0ZA6bPnbxpqKPI5LatbGY9RQjA2TmATrjSPE3aWndJsLIrutI6aS9K+YFwy5+HLDKVRFYQfmKAw==",
"dependencies": {
"@firebase/component": "0.5.6",
"@firebase/firestore-types": "2.4.0",
@ -521,7 +521,7 @@
"@firebase/webchannel-wrapper": "0.5.1",
"@grpc/grpc-js": "^1.3.2",
"@grpc/proto-loader": "^0.6.0",
"node-fetch": "2.6.1",
"node-fetch": "2.6.7",
"tslib": "^2.1.0"
},
"engines": {
@ -547,14 +547,14 @@
"integrity": "sha512-77EbyPPpMz+FRFRuAFlWMtmgUWGe9UOG2Z25NqCwiIjRhOf5iKGuzSe5P2w1laq+FkRy4p+PCuVkJSGkzTEKVw=="
},
"node_modules/@firebase/functions": {
"version": "0.6.15",
"resolved": "https://registry.npmjs.org/@firebase/functions/-/functions-0.6.15.tgz",
"integrity": "sha512-b7RpLwFXi0N+HgkfK8cmkarSOoBeSrc1jNdadkCacQt+vIePkKM3E9EJXF4roWSa8GwTruodpBsvH+lK9iCAKQ==",
"version": "0.6.16",
"resolved": "https://registry.npmjs.org/@firebase/functions/-/functions-0.6.16.tgz",
"integrity": "sha512-KDPjLKSjtR/zEH06YXXbdWTi8gzbKHGRzL/+ibZQA/1MLq0IilfM+1V1Fh8bADsMCUkxkqoc1yiA4SUbH5ajJA==",
"dependencies": {
"@firebase/component": "0.5.6",
"@firebase/functions-types": "0.4.0",
"@firebase/messaging-types": "0.5.0",
"node-fetch": "2.6.1",
"node-fetch": "2.6.7",
"tslib": "^2.1.0"
},
"peerDependencies": {
@ -701,14 +701,14 @@
"integrity": "sha512-77EbyPPpMz+FRFRuAFlWMtmgUWGe9UOG2Z25NqCwiIjRhOf5iKGuzSe5P2w1laq+FkRy4p+PCuVkJSGkzTEKVw=="
},
"node_modules/@firebase/storage": {
"version": "0.7.0",
"resolved": "https://registry.npmjs.org/@firebase/storage/-/storage-0.7.0.tgz",
"integrity": "sha512-ebDFKJbM5HOxVtZV+RhVEBVtlWHK+Z5L3kA5uDBA2jMYcn+8NV/crozJnEE+iRsGEco6dLK5JS+Er4qtKLpH5A==",
"version": "0.7.1",
"resolved": "https://registry.npmjs.org/@firebase/storage/-/storage-0.7.1.tgz",
"integrity": "sha512-T7uH6lAgNs/Zq8V3ElvR3ypTQSGWon/R7WRM2I5Td/d0PTsNIIHSAGB6q4Au8mQEOz3HDTfjNQ9LuQ07R6S2ug==",
"dependencies": {
"@firebase/component": "0.5.6",
"@firebase/storage-types": "0.5.0",
"@firebase/util": "1.3.0",
"node-fetch": "2.6.1",
"node-fetch": "2.6.7",
"tslib": "^2.1.0"
},
"peerDependencies": {
@ -749,9 +749,9 @@
"integrity": "sha512-dZMzN0uAjwJXWYYAcnxIwXqRTZw3o14hGe7O6uhwjD1ZQWPVYA5lASgnNskEBra0knVBsOXB4KXg+HnlKewN/A=="
},
"node_modules/@grpc/grpc-js": {
"version": "1.4.5",
"resolved": "https://registry.npmjs.org/@grpc/grpc-js/-/grpc-js-1.4.5.tgz",
"integrity": "sha512-A6cOzSu7dqXZ7rzvh/9JZf+Jg/MOpLEMP0IdT8pT8hrWJZ6TB4ydN/MRuqOtAugInJe/VQ9F8BPricUpYZSaZA==",
"version": "1.5.4",
"resolved": "https://registry.npmjs.org/@grpc/grpc-js/-/grpc-js-1.5.4.tgz",
"integrity": "sha512-+nJTOsqpFAXnfFrMZ7Too4XXZ/J9O+8jYvSoaunupoC7I7b9H4iex1BRsbTdOmiowfPGJrWit7jUPmbENSUSpw==",
"dependencies": {
"@grpc/proto-loader": "^0.6.4",
"@types/node": ">=12.12.47"
@ -761,15 +761,15 @@
}
},
"node_modules/@grpc/proto-loader": {
"version": "0.6.7",
"resolved": "https://registry.npmjs.org/@grpc/proto-loader/-/proto-loader-0.6.7.tgz",
"integrity": "sha512-QzTPIyJxU0u+r2qGe8VMl3j/W2ryhEvBv7hc42OjYfthSj370fUrb7na65rG6w3YLZS/fb8p89iTBobfWGDgdw==",
"version": "0.6.9",
"resolved": "https://registry.npmjs.org/@grpc/proto-loader/-/proto-loader-0.6.9.tgz",
"integrity": "sha512-UlcCS8VbsU9d3XTXGiEVFonN7hXk+oMXZtoHHG2oSA1/GcDP1q6OUgs20PzHDGizzyi8ufGSUDlk3O2NyY7leg==",
"dependencies": {
"@types/long": "^4.0.1",
"lodash.camelcase": "^4.3.0",
"long": "^4.0.0",
"protobufjs": "^6.10.0",
"yargs": "^16.1.1"
"yargs": "^16.2.0"
},
"bin": {
"proto-loader-gen-types": "build/bin/proto-loader-gen-types.js"
@ -2410,9 +2410,9 @@
"optional": true
},
"node_modules/@types/yargs": {
"version": "17.0.7",
"resolved": "https://registry.npmjs.org/@types/yargs/-/yargs-17.0.7.tgz",
"integrity": "sha512-OvLKmpKdea1aWtqHv9bxVVcMoT6syAeK+198dfETIFkAevYRGwqh4H+KFxfjUETZuUuE5sQCAFwdOdoHUdo8eg==",
"version": "17.0.8",
"resolved": "https://registry.npmjs.org/@types/yargs/-/yargs-17.0.8.tgz",
"integrity": "sha512-wDeUwiUmem9FzsyysEwRukaEdDNcwbROvQ9QGRKaLI6t+IltNzbn4/i4asmB10auvZGQCzSQ6t0GSczEThlUXw==",
"dependencies": {
"@types/yargs-parser": "*"
}
@ -2931,9 +2931,9 @@
}
},
"node_modules/app-builder-lib/node_modules/hosted-git-info": {
"version": "4.0.2",
"resolved": "https://registry.npmjs.org/hosted-git-info/-/hosted-git-info-4.0.2.tgz",
"integrity": "sha512-c9OGXbZ3guC/xOlCg1Ci/VgWlwsqDv1yMQL1CWqXDL0hDjXuNcq0zuR4xqPSuasI3kqFDhqSyTjREz5gzq0fXg==",
"version": "4.1.0",
"resolved": "https://registry.npmjs.org/hosted-git-info/-/hosted-git-info-4.1.0.tgz",
"integrity": "sha512-kyCuEOWjJqZuDbRHzL8V93NzQhwIB71oFWSyzVo+KPZI+pnQPPxucdkrOZvkLRnrf5URsQM+IJ09Dw29cRALIA==",
"dependencies": {
"lru-cache": "^6.0.0"
},
@ -3635,9 +3635,9 @@
}
},
"node_modules/boxen/node_modules/camelcase": {
"version": "6.2.1",
"resolved": "https://registry.npmjs.org/camelcase/-/camelcase-6.2.1.tgz",
"integrity": "sha512-tVI4q5jjFV5CavAU8DXfza/TJcZutVKo/5Foskmsqcm0MsL91moHvwiGNnqaa2o6PF/7yT5ikDRcVcl8Rj6LCA==",
"version": "6.3.0",
"resolved": "https://registry.npmjs.org/camelcase/-/camelcase-6.3.0.tgz",
"integrity": "sha512-Gmy6FhYlCY7uOElZUSbxo2UCDH8owEk996gkbrpsgGtrJLM3J7jGxl9Ic7Qwwj4ivOE5AWZWRMecDdF7hqGjFA==",
"engines": {
"node": ">=10"
},
@ -4825,9 +4825,9 @@
}
},
"node_modules/color": {
"version": "4.1.0",
"resolved": "https://registry.npmjs.org/color/-/color-4.1.0.tgz",
"integrity": "sha512-o2rkkxyLGgYoeUy1OodXpbPAQNmlNBrirQ8ODO8QutzDiDMNdezSOZLNnusQ6pUpCQJUsaJIo9DZJKqa2HgH7A==",
"version": "4.2.0",
"resolved": "https://registry.npmjs.org/color/-/color-4.2.0.tgz",
"integrity": "sha512-hHTcrbvEnGjC7WBMk6ibQWFVDgEFTVmjrz2Q5HlU6ltwxv0JJN2Z8I7uRbWeQLF04dikxs8zgyZkazRJvSMtyQ==",
"dependencies": {
"color-convert": "^2.0.1",
"color-string": "^1.9.0"
@ -6856,9 +6856,9 @@
}
},
"node_modules/electron-builder/node_modules/yargs": {
"version": "17.3.0",
"resolved": "https://registry.npmjs.org/yargs/-/yargs-17.3.0.tgz",
"integrity": "sha512-GQl1pWyDoGptFPJx9b9L6kmR33TGusZvXIZUT+BOz9f7X2L94oeAskFYLEg/FkhV06zZPBYLvLZRWeYId29lew==",
"version": "17.3.1",
"resolved": "https://registry.npmjs.org/yargs/-/yargs-17.3.1.tgz",
"integrity": "sha512-WUANQeVgjLbNsEmGk20f+nlHgOqzRFpiGWVaBrYGYIGANIIu3lWjoyi0fNlFmJkvfhCZ6BXINe7/W2O2bV4iaA==",
"dependencies": {
"cliui": "^7.0.2",
"escalade": "^3.1.1",
@ -7100,11 +7100,6 @@
"node": ">= 10.0.0"
}
},
"node_modules/electron/node_modules/@types/node": {
"version": "12.20.38",
"resolved": "https://registry.npmjs.org/@types/node/-/node-12.20.38.tgz",
"integrity": "sha512-NxmtBRGipjx1B225OeMdI+CQmLbYqvvmYbukDTJGDgzIDgPQ1EcjGmYxGhOk5hTBqeB558S6RgHSpq2iiqifAQ=="
},
"node_modules/elliptic": {
"version": "6.5.3",
"resolved": "https://registry.npmjs.org/elliptic/-/elliptic-6.5.3.tgz",
@ -7150,7 +7145,7 @@
"version": "0.1.13",
"resolved": "https://registry.npmjs.org/encoding/-/encoding-0.1.13.tgz",
"integrity": "sha512-ETBauow1T35Y/WZMkio9jiM0Z5xjHHmJ4XmjZOq1l/dXz3lr2sRn87nJy20RupqSh1F2m3HHPSp8ShIPQJrJ3A==",
"dev": true,
"devOptional": true,
"dependencies": {
"iconv-lite": "^0.6.2"
}
@ -8049,9 +8044,9 @@
}
},
"node_modules/firebase": {
"version": "8.10.0",
"resolved": "https://registry.npmjs.org/firebase/-/firebase-8.10.0.tgz",
"integrity": "sha512-GCABTbJdo88QgzX5OH/vsfKBWvTRbLUylGlYXtO7uYo1VErfGd2BWW9ATlJP5Gxx+ClDfyvVTvcs2rcNWn3uUA==",
"version": "8.10.1",
"resolved": "https://registry.npmjs.org/firebase/-/firebase-8.10.1.tgz",
"integrity": "sha512-84z/zqF8Y5IpUYN8nREZ/bxbGtF5WJDOBy4y0hAxRzGpB5+2tw9PQgtTnUzk6MQiVEf/WOniMUL3pCVXKsxALw==",
"dependencies": {
"@firebase/analytics": "0.6.18",
"@firebase/app": "0.6.30",
@ -8059,14 +8054,14 @@
"@firebase/app-types": "0.6.3",
"@firebase/auth": "0.16.8",
"@firebase/database": "0.11.0",
"@firebase/firestore": "2.4.0",
"@firebase/functions": "0.6.15",
"@firebase/firestore": "2.4.1",
"@firebase/functions": "0.6.16",
"@firebase/installations": "0.4.32",
"@firebase/messaging": "0.8.0",
"@firebase/performance": "0.4.18",
"@firebase/polyfill": "0.3.36",
"@firebase/remote-config": "0.1.43",
"@firebase/storage": "0.7.0",
"@firebase/storage": "0.7.1",
"@firebase/util": "1.3.0"
},
"engines": {
@ -12359,11 +12354,22 @@
"optional": true
},
"node_modules/node-fetch": {
"version": "2.6.1",
"resolved": "https://registry.npmjs.org/node-fetch/-/node-fetch-2.6.1.tgz",
"integrity": "sha512-V4aYg89jEoVRxRb2fJdAg8FHvI7cEyYdVAh94HH0UIK8oJxUfkjlDQN9RbMx+bEjP7+ggMiFRprSti032Oipxw==",
"version": "2.6.7",
"resolved": "https://registry.npmjs.org/node-fetch/-/node-fetch-2.6.7.tgz",
"integrity": "sha512-ZjMPFEfVx5j+y2yF35Kzx5sF7kDzxuDj6ziH4FFbOp87zKDZNx8yExJIb05OGF4Nlt9IHFIMBkRl41VdvcNdbQ==",
"dependencies": {
"whatwg-url": "^5.0.0"
},
"engines": {
"node": "4.x || >=6.0.0"
},
"peerDependencies": {
"encoding": "^0.1.0"
},
"peerDependenciesMeta": {
"encoding": {
"optional": true
}
}
},
"node_modules/node-fetch-npm": {
@ -12380,6 +12386,25 @@
"node": ">=4"
}
},
"node_modules/node-fetch/node_modules/tr46": {
"version": "0.0.3",
"resolved": "https://registry.npmjs.org/tr46/-/tr46-0.0.3.tgz",
"integrity": "sha1-gYT9NH2snNwYWZLzpmIuFLnZq2o="
},
"node_modules/node-fetch/node_modules/webidl-conversions": {
"version": "3.0.1",
"resolved": "https://registry.npmjs.org/webidl-conversions/-/webidl-conversions-3.0.1.tgz",
"integrity": "sha1-JFNCdeKnvGvnvIZhHMFq4KVlSHE="
},
"node_modules/node-fetch/node_modules/whatwg-url": {
"version": "5.0.0",
"resolved": "https://registry.npmjs.org/whatwg-url/-/whatwg-url-5.0.0.tgz",
"integrity": "sha1-lmRU6HZUYuN2RNNib2dCzotwll0=",
"dependencies": {
"tr46": "~0.0.3",
"webidl-conversions": "^3.0.0"
}
},
"node_modules/node-forge": {
"version": "0.10.0",
"resolved": "https://registry.npmjs.org/node-forge/-/node-forge-0.10.0.tgz",
@ -13678,11 +13703,11 @@
}
},
"node_modules/prebuild-install": {
"version": "7.0.0",
"resolved": "https://registry.npmjs.org/prebuild-install/-/prebuild-install-7.0.0.tgz",
"integrity": "sha512-IvSenf33K7JcgddNz2D5w521EgO+4aMMjFt73Uk9FRzQ7P+QZPKrp7qPsDydsSwjGt3T5xRNnM1bj1zMTD5fTA==",
"version": "7.0.1",
"resolved": "https://registry.npmjs.org/prebuild-install/-/prebuild-install-7.0.1.tgz",
"integrity": "sha512-QBSab31WqkyxpnMWQxubYAHR5S9B2+r81ucocew34Fkl98FhvKIF50jIJnNOBmAZfyNV7vE5T6gd3hTVWgY6tg==",
"dependencies": {
"detect-libc": "^1.0.3",
"detect-libc": "^2.0.0",
"expand-template": "^2.0.3",
"github-from-package": "0.0.0",
"minimist": "^1.2.3",
@ -13703,6 +13728,14 @@
"node": ">=10"
}
},
"node_modules/prebuild-install/node_modules/detect-libc": {
"version": "2.0.0",
"resolved": "https://registry.npmjs.org/detect-libc/-/detect-libc-2.0.0.tgz",
"integrity": "sha512-S55LzUl8HUav8l9E2PBTlC5PAJrHK7tkM+XXFGD+fbsbkTzhCpG6K05LxJcUOEWzMa4v6ptcMZ9s3fOdJDu0Zw==",
"engines": {
"node": ">=8"
}
},
"node_modules/prepend-http": {
"version": "2.0.0",
"resolved": "https://registry.npmjs.org/prepend-http/-/prepend-http-2.0.0.tgz",
@ -15030,9 +15063,9 @@
}
},
"node_modules/sharp/node_modules/node-addon-api": {
"version": "4.2.0",
"resolved": "https://registry.npmjs.org/node-addon-api/-/node-addon-api-4.2.0.tgz",
"integrity": "sha512-eazsqzwG2lskuzBqCGPi7Ac2UgOoMz8JVOXVhTvvPDYhthvNpefx8jWD8Np7Gv+2Sz0FlPWZk0nJV0z598Wn8Q=="
"version": "4.3.0",
"resolved": "https://registry.npmjs.org/node-addon-api/-/node-addon-api-4.3.0.tgz",
"integrity": "sha512-73sE9+3UaLYYFmDsFZnqCInzPyh3MqIwZO9cw58yIqAZhONrrabrYyYe3TuIqtIiOuTXVhsGau8hcrhhwSsDIQ=="
},
"node_modules/sharp/node_modules/semver": {
"version": "7.3.5",
@ -15136,9 +15169,9 @@
]
},
"node_modules/simple-get": {
"version": "4.0.0",
"resolved": "https://registry.npmjs.org/simple-get/-/simple-get-4.0.0.tgz",
"integrity": "sha512-ZalZGexYr3TA0SwySsr5HlgOOinS4Jsa8YB2GJ6lUNAazyAu4KG/VmzMTwAt2YVXzzVj8QmefmAonZIK2BSGcQ==",
"version": "4.0.1",
"resolved": "https://registry.npmjs.org/simple-get/-/simple-get-4.0.1.tgz",
"integrity": "sha512-brv7p5WgH0jmQJr1ZDDfKDOSeWWg+OVypG99A/5vYGPqJ6pxiaHLy8nxtFjBA7oMa01ebA9gfh1uMCFqOuXxvA==",
"funding": [
{
"type": "github",
@ -18737,9 +18770,9 @@
}
},
"node_modules/yargs-unparser/node_modules/camelcase": {
"version": "6.2.1",
"resolved": "https://registry.npmjs.org/camelcase/-/camelcase-6.2.1.tgz",
"integrity": "sha512-tVI4q5jjFV5CavAU8DXfza/TJcZutVKo/5Foskmsqcm0MsL91moHvwiGNnqaa2o6PF/7yT5ikDRcVcl8Rj6LCA==",
"version": "6.3.0",
"resolved": "https://registry.npmjs.org/camelcase/-/camelcase-6.3.0.tgz",
"integrity": "sha512-Gmy6FhYlCY7uOElZUSbxo2UCDH8owEk996gkbrpsgGtrJLM3J7jGxl9Ic7Qwwj4ivOE5AWZWRMecDdF7hqGjFA==",
"engines": {
"node": ">=10"
},
@ -19258,9 +19291,9 @@
}
},
"@firebase/firestore": {
"version": "2.4.0",
"resolved": "https://registry.npmjs.org/@firebase/firestore/-/firestore-2.4.0.tgz",
"integrity": "sha512-PQ6+lWNrvh74GvFTHT4gCutFipDmtu8D1tNNawKe+/SyL6XFgeuMYgZIpKQgkTSezVDogC7EGQTJBFnewF9pOg==",
"version": "2.4.1",
"resolved": "https://registry.npmjs.org/@firebase/firestore/-/firestore-2.4.1.tgz",
"integrity": "sha512-S51XnILdhNt0ZA6bPnbxpqKPI5LatbGY9RQjA2TmATrjSPE3aWndJsLIrutI6aS9K+YFwy5+HLDKVRFYQfmKAw==",
"requires": {
"@firebase/component": "0.5.6",
"@firebase/firestore-types": "2.4.0",
@ -19269,7 +19302,7 @@
"@firebase/webchannel-wrapper": "0.5.1",
"@grpc/grpc-js": "^1.3.2",
"@grpc/proto-loader": "^0.6.0",
"node-fetch": "2.6.1",
"node-fetch": "2.6.7",
"tslib": "^2.1.0"
},
"dependencies": {
@ -19287,14 +19320,14 @@
"requires": {}
},
"@firebase/functions": {
"version": "0.6.15",
"resolved": "https://registry.npmjs.org/@firebase/functions/-/functions-0.6.15.tgz",
"integrity": "sha512-b7RpLwFXi0N+HgkfK8cmkarSOoBeSrc1jNdadkCacQt+vIePkKM3E9EJXF4roWSa8GwTruodpBsvH+lK9iCAKQ==",
"version": "0.6.16",
"resolved": "https://registry.npmjs.org/@firebase/functions/-/functions-0.6.16.tgz",
"integrity": "sha512-KDPjLKSjtR/zEH06YXXbdWTi8gzbKHGRzL/+ibZQA/1MLq0IilfM+1V1Fh8bADsMCUkxkqoc1yiA4SUbH5ajJA==",
"requires": {
"@firebase/component": "0.5.6",
"@firebase/functions-types": "0.4.0",
"@firebase/messaging-types": "0.5.0",
"node-fetch": "2.6.1",
"node-fetch": "2.6.7",
"tslib": "^2.1.0"
},
"dependencies": {
@ -19427,14 +19460,14 @@
"integrity": "sha512-G96qnF3RYGbZsTRut7NBX0sxyczxt1uyCgXQuH/eAfUCngxjEGcZQnBdy6mvSdqdJh5mC31rWPO4v9/s7HwtzA=="
},
"@firebase/storage": {
"version": "0.7.0",
"resolved": "https://registry.npmjs.org/@firebase/storage/-/storage-0.7.0.tgz",
"integrity": "sha512-ebDFKJbM5HOxVtZV+RhVEBVtlWHK+Z5L3kA5uDBA2jMYcn+8NV/crozJnEE+iRsGEco6dLK5JS+Er4qtKLpH5A==",
"version": "0.7.1",
"resolved": "https://registry.npmjs.org/@firebase/storage/-/storage-0.7.1.tgz",
"integrity": "sha512-T7uH6lAgNs/Zq8V3ElvR3ypTQSGWon/R7WRM2I5Td/d0PTsNIIHSAGB6q4Au8mQEOz3HDTfjNQ9LuQ07R6S2ug==",
"requires": {
"@firebase/component": "0.5.6",
"@firebase/storage-types": "0.5.0",
"@firebase/util": "1.3.0",
"node-fetch": "2.6.1",
"node-fetch": "2.6.7",
"tslib": "^2.1.0"
},
"dependencies": {
@ -19472,24 +19505,24 @@
"integrity": "sha512-dZMzN0uAjwJXWYYAcnxIwXqRTZw3o14hGe7O6uhwjD1ZQWPVYA5lASgnNskEBra0knVBsOXB4KXg+HnlKewN/A=="
},
"@grpc/grpc-js": {
"version": "1.4.5",
"resolved": "https://registry.npmjs.org/@grpc/grpc-js/-/grpc-js-1.4.5.tgz",
"integrity": "sha512-A6cOzSu7dqXZ7rzvh/9JZf+Jg/MOpLEMP0IdT8pT8hrWJZ6TB4ydN/MRuqOtAugInJe/VQ9F8BPricUpYZSaZA==",
"version": "1.5.4",
"resolved": "https://registry.npmjs.org/@grpc/grpc-js/-/grpc-js-1.5.4.tgz",
"integrity": "sha512-+nJTOsqpFAXnfFrMZ7Too4XXZ/J9O+8jYvSoaunupoC7I7b9H4iex1BRsbTdOmiowfPGJrWit7jUPmbENSUSpw==",
"requires": {
"@grpc/proto-loader": "^0.6.4",
"@types/node": ">=12.12.47"
}
},
"@grpc/proto-loader": {
"version": "0.6.7",
"resolved": "https://registry.npmjs.org/@grpc/proto-loader/-/proto-loader-0.6.7.tgz",
"integrity": "sha512-QzTPIyJxU0u+r2qGe8VMl3j/W2ryhEvBv7hc42OjYfthSj370fUrb7na65rG6w3YLZS/fb8p89iTBobfWGDgdw==",
"version": "0.6.9",
"resolved": "https://registry.npmjs.org/@grpc/proto-loader/-/proto-loader-0.6.9.tgz",
"integrity": "sha512-UlcCS8VbsU9d3XTXGiEVFonN7hXk+oMXZtoHHG2oSA1/GcDP1q6OUgs20PzHDGizzyi8ufGSUDlk3O2NyY7leg==",
"requires": {
"@types/long": "^4.0.1",
"lodash.camelcase": "^4.3.0",
"long": "^4.0.0",
"protobufjs": "^6.10.0",
"yargs": "^16.1.1"
"yargs": "^16.2.0"
}
},
"@lerna/add": {
@ -20882,9 +20915,9 @@
"optional": true
},
"@types/yargs": {
"version": "17.0.7",
"resolved": "https://registry.npmjs.org/@types/yargs/-/yargs-17.0.7.tgz",
"integrity": "sha512-OvLKmpKdea1aWtqHv9bxVVcMoT6syAeK+198dfETIFkAevYRGwqh4H+KFxfjUETZuUuE5sQCAFwdOdoHUdo8eg==",
"version": "17.0.8",
"resolved": "https://registry.npmjs.org/@types/yargs/-/yargs-17.0.8.tgz",
"integrity": "sha512-wDeUwiUmem9FzsyysEwRukaEdDNcwbROvQ9QGRKaLI6t+IltNzbn4/i4asmB10auvZGQCzSQ6t0GSczEThlUXw==",
"requires": {
"@types/yargs-parser": "*"
}
@ -21326,9 +21359,9 @@
}
},
"hosted-git-info": {
"version": "4.0.2",
"resolved": "https://registry.npmjs.org/hosted-git-info/-/hosted-git-info-4.0.2.tgz",
"integrity": "sha512-c9OGXbZ3guC/xOlCg1Ci/VgWlwsqDv1yMQL1CWqXDL0hDjXuNcq0zuR4xqPSuasI3kqFDhqSyTjREz5gzq0fXg==",
"version": "4.1.0",
"resolved": "https://registry.npmjs.org/hosted-git-info/-/hosted-git-info-4.1.0.tgz",
"integrity": "sha512-kyCuEOWjJqZuDbRHzL8V93NzQhwIB71oFWSyzVo+KPZI+pnQPPxucdkrOZvkLRnrf5URsQM+IJ09Dw29cRALIA==",
"requires": {
"lru-cache": "^6.0.0"
}
@ -21885,9 +21918,9 @@
}
},
"camelcase": {
"version": "6.2.1",
"resolved": "https://registry.npmjs.org/camelcase/-/camelcase-6.2.1.tgz",
"integrity": "sha512-tVI4q5jjFV5CavAU8DXfza/TJcZutVKo/5Foskmsqcm0MsL91moHvwiGNnqaa2o6PF/7yT5ikDRcVcl8Rj6LCA=="
"version": "6.3.0",
"resolved": "https://registry.npmjs.org/camelcase/-/camelcase-6.3.0.tgz",
"integrity": "sha512-Gmy6FhYlCY7uOElZUSbxo2UCDH8owEk996gkbrpsgGtrJLM3J7jGxl9Ic7Qwwj4ivOE5AWZWRMecDdF7hqGjFA=="
},
"chalk": {
"version": "4.1.2",
@ -22816,9 +22849,9 @@
}
},
"color": {
"version": "4.1.0",
"resolved": "https://registry.npmjs.org/color/-/color-4.1.0.tgz",
"integrity": "sha512-o2rkkxyLGgYoeUy1OodXpbPAQNmlNBrirQ8ODO8QutzDiDMNdezSOZLNnusQ6pUpCQJUsaJIo9DZJKqa2HgH7A==",
"version": "4.2.0",
"resolved": "https://registry.npmjs.org/color/-/color-4.2.0.tgz",
"integrity": "sha512-hHTcrbvEnGjC7WBMk6ibQWFVDgEFTVmjrz2Q5HlU6ltwxv0JJN2Z8I7uRbWeQLF04dikxs8zgyZkazRJvSMtyQ==",
"requires": {
"color-convert": "^2.0.1",
"color-string": "^1.9.0"
@ -24328,13 +24361,6 @@
"@electron/get": "^1.0.1",
"@types/node": "^14.6.2",
"extract-zip": "^1.0.3"
},
"dependencies": {
"@types/node": {
"version": "12.20.38",
"resolved": "https://registry.npmjs.org/@types/node/-/node-12.20.38.tgz",
"integrity": "sha512-NxmtBRGipjx1B225OeMdI+CQmLbYqvvmYbukDTJGDgzIDgPQ1EcjGmYxGhOk5hTBqeB558S6RgHSpq2iiqifAQ=="
}
}
},
"electron-builder": {
@ -24475,9 +24501,9 @@
"integrity": "sha512-0pfFzegeDWJHJIAmTLRP2DwHjdF5s7jo9tuztdQxAhINCdvS+3nGINqPd00AphqJR/0LhANUS6/+7SCb98YOfA=="
},
"yargs": {
"version": "17.3.0",
"resolved": "https://registry.npmjs.org/yargs/-/yargs-17.3.0.tgz",
"integrity": "sha512-GQl1pWyDoGptFPJx9b9L6kmR33TGusZvXIZUT+BOz9f7X2L94oeAskFYLEg/FkhV06zZPBYLvLZRWeYId29lew==",
"version": "17.3.1",
"resolved": "https://registry.npmjs.org/yargs/-/yargs-17.3.1.tgz",
"integrity": "sha512-WUANQeVgjLbNsEmGk20f+nlHgOqzRFpiGWVaBrYGYIGANIIu3lWjoyi0fNlFmJkvfhCZ6BXINe7/W2O2bV4iaA==",
"requires": {
"cliui": "^7.0.2",
"escalade": "^3.1.1",
@ -24704,7 +24730,7 @@
"version": "0.1.13",
"resolved": "https://registry.npmjs.org/encoding/-/encoding-0.1.13.tgz",
"integrity": "sha512-ETBauow1T35Y/WZMkio9jiM0Z5xjHHmJ4XmjZOq1l/dXz3lr2sRn87nJy20RupqSh1F2m3HHPSp8ShIPQJrJ3A==",
"dev": true,
"devOptional": true,
"requires": {
"iconv-lite": "^0.6.2"
}
@ -25436,9 +25462,9 @@
}
},
"firebase": {
"version": "8.10.0",
"resolved": "https://registry.npmjs.org/firebase/-/firebase-8.10.0.tgz",
"integrity": "sha512-GCABTbJdo88QgzX5OH/vsfKBWvTRbLUylGlYXtO7uYo1VErfGd2BWW9ATlJP5Gxx+ClDfyvVTvcs2rcNWn3uUA==",
"version": "8.10.1",
"resolved": "https://registry.npmjs.org/firebase/-/firebase-8.10.1.tgz",
"integrity": "sha512-84z/zqF8Y5IpUYN8nREZ/bxbGtF5WJDOBy4y0hAxRzGpB5+2tw9PQgtTnUzk6MQiVEf/WOniMUL3pCVXKsxALw==",
"requires": {
"@firebase/analytics": "0.6.18",
"@firebase/app": "0.6.30",
@ -25446,14 +25472,14 @@
"@firebase/app-types": "0.6.3",
"@firebase/auth": "0.16.8",
"@firebase/database": "0.11.0",
"@firebase/firestore": "2.4.0",
"@firebase/functions": "0.6.15",
"@firebase/firestore": "2.4.1",
"@firebase/functions": "0.6.16",
"@firebase/installations": "0.4.32",
"@firebase/messaging": "0.8.0",
"@firebase/performance": "0.4.18",
"@firebase/polyfill": "0.3.36",
"@firebase/remote-config": "0.1.43",
"@firebase/storage": "0.7.0",
"@firebase/storage": "0.7.1",
"@firebase/util": "1.3.0"
}
},
@ -28772,9 +28798,33 @@
"optional": true
},
"node-fetch": {
"version": "2.6.1",
"resolved": "https://registry.npmjs.org/node-fetch/-/node-fetch-2.6.1.tgz",
"integrity": "sha512-V4aYg89jEoVRxRb2fJdAg8FHvI7cEyYdVAh94HH0UIK8oJxUfkjlDQN9RbMx+bEjP7+ggMiFRprSti032Oipxw=="
"version": "2.6.7",
"resolved": "https://registry.npmjs.org/node-fetch/-/node-fetch-2.6.7.tgz",
"integrity": "sha512-ZjMPFEfVx5j+y2yF35Kzx5sF7kDzxuDj6ziH4FFbOp87zKDZNx8yExJIb05OGF4Nlt9IHFIMBkRl41VdvcNdbQ==",
"requires": {
"whatwg-url": "^5.0.0"
},
"dependencies": {
"tr46": {
"version": "0.0.3",
"resolved": "https://registry.npmjs.org/tr46/-/tr46-0.0.3.tgz",
"integrity": "sha1-gYT9NH2snNwYWZLzpmIuFLnZq2o="
},
"webidl-conversions": {
"version": "3.0.1",
"resolved": "https://registry.npmjs.org/webidl-conversions/-/webidl-conversions-3.0.1.tgz",
"integrity": "sha1-JFNCdeKnvGvnvIZhHMFq4KVlSHE="
},
"whatwg-url": {
"version": "5.0.0",
"resolved": "https://registry.npmjs.org/whatwg-url/-/whatwg-url-5.0.0.tgz",
"integrity": "sha1-lmRU6HZUYuN2RNNib2dCzotwll0=",
"requires": {
"tr46": "~0.0.3",
"webidl-conversions": "^3.0.0"
}
}
}
},
"node-fetch-npm": {
"version": "2.0.4",
@ -29833,11 +29883,11 @@
"integrity": "sha1-AerA/jta9xoqbAL+q7jB/vfgDqs="
},
"prebuild-install": {
"version": "7.0.0",
"resolved": "https://registry.npmjs.org/prebuild-install/-/prebuild-install-7.0.0.tgz",
"integrity": "sha512-IvSenf33K7JcgddNz2D5w521EgO+4aMMjFt73Uk9FRzQ7P+QZPKrp7qPsDydsSwjGt3T5xRNnM1bj1zMTD5fTA==",
"version": "7.0.1",
"resolved": "https://registry.npmjs.org/prebuild-install/-/prebuild-install-7.0.1.tgz",
"integrity": "sha512-QBSab31WqkyxpnMWQxubYAHR5S9B2+r81ucocew34Fkl98FhvKIF50jIJnNOBmAZfyNV7vE5T6gd3hTVWgY6tg==",
"requires": {
"detect-libc": "^1.0.3",
"detect-libc": "^2.0.0",
"expand-template": "^2.0.3",
"github-from-package": "0.0.0",
"minimist": "^1.2.3",
@ -29850,6 +29900,13 @@
"simple-get": "^4.0.0",
"tar-fs": "^2.0.0",
"tunnel-agent": "^0.6.0"
},
"dependencies": {
"detect-libc": {
"version": "2.0.0",
"resolved": "https://registry.npmjs.org/detect-libc/-/detect-libc-2.0.0.tgz",
"integrity": "sha512-S55LzUl8HUav8l9E2PBTlC5PAJrHK7tkM+XXFGD+fbsbkTzhCpG6K05LxJcUOEWzMa4v6ptcMZ9s3fOdJDu0Zw=="
}
}
},
"prepend-http": {
@ -30934,9 +30991,9 @@
}
},
"node-addon-api": {
"version": "4.2.0",
"resolved": "https://registry.npmjs.org/node-addon-api/-/node-addon-api-4.2.0.tgz",
"integrity": "sha512-eazsqzwG2lskuzBqCGPi7Ac2UgOoMz8JVOXVhTvvPDYhthvNpefx8jWD8Np7Gv+2Sz0FlPWZk0nJV0z598Wn8Q=="
"version": "4.3.0",
"resolved": "https://registry.npmjs.org/node-addon-api/-/node-addon-api-4.3.0.tgz",
"integrity": "sha512-73sE9+3UaLYYFmDsFZnqCInzPyh3MqIwZO9cw58yIqAZhONrrabrYyYe3TuIqtIiOuTXVhsGau8hcrhhwSsDIQ=="
},
"semver": {
"version": "7.3.5",
@ -31009,9 +31066,9 @@
"integrity": "sha512-cSFtAPtRhljv69IK0hTVZQ+OfE9nePi/rtJmw5UjHeVyVroEqJXP1sFztKUy1qU+xvz3u/sfYJLa947b7nAN2Q=="
},
"simple-get": {
"version": "4.0.0",
"resolved": "https://registry.npmjs.org/simple-get/-/simple-get-4.0.0.tgz",
"integrity": "sha512-ZalZGexYr3TA0SwySsr5HlgOOinS4Jsa8YB2GJ6lUNAazyAu4KG/VmzMTwAt2YVXzzVj8QmefmAonZIK2BSGcQ==",
"version": "4.0.1",
"resolved": "https://registry.npmjs.org/simple-get/-/simple-get-4.0.1.tgz",
"integrity": "sha512-brv7p5WgH0jmQJr1ZDDfKDOSeWWg+OVypG99A/5vYGPqJ6pxiaHLy8nxtFjBA7oMa01ebA9gfh1uMCFqOuXxvA==",
"requires": {
"decompress-response": "^6.0.0",
"once": "^1.3.1",
@ -33908,9 +33965,9 @@
},
"dependencies": {
"camelcase": {
"version": "6.2.1",
"resolved": "https://registry.npmjs.org/camelcase/-/camelcase-6.2.1.tgz",
"integrity": "sha512-tVI4q5jjFV5CavAU8DXfza/TJcZutVKo/5Foskmsqcm0MsL91moHvwiGNnqaa2o6PF/7yT5ikDRcVcl8Rj6LCA=="
"version": "6.3.0",
"resolved": "https://registry.npmjs.org/camelcase/-/camelcase-6.3.0.tgz",
"integrity": "sha512-Gmy6FhYlCY7uOElZUSbxo2UCDH8owEk996gkbrpsgGtrJLM3J7jGxl9Ic7Qwwj4ivOE5AWZWRMecDdF7hqGjFA=="
},
"decamelize": {
"version": "4.0.0",

View File

@ -0,0 +1,12 @@
[package]
name = "enso-profiler"
version = "0.1.0"
edition = "2021"
authors = ["Enso Team <contact@enso.org>"]
[dependencies]
wasm-bindgen = { version = "=0.2.58", features = ["nightly"] }
enso-profiler-macros = { path = "macros" }
[dev-dependencies]
futures = "0.3"

View File

@ -0,0 +1,17 @@
[package]
name = "enso-profiler-macros"
version = "0.1.0"
edition = "2021"
authors = ["Enso Team <contact@enso.org>"]
[lib]
proc-macro = true
[dependencies]
proc-macro2 = "1.0"
quote = "1.0"
syn = { version = "1.0", features = [ "full", "visit-mut" ] }
Inflector = "0.11"
[features]
lineno = []

View File

@ -0,0 +1,411 @@
//! Proc macros supporting the implementation of the `enso_profiler` library.
//!
//! The profiler API uses procedural macros for two reasons:
//! - To define the hierarchy of profiler types ([`define_hierarchy!`]). Each profiler type (e.g.
//! [`Objective`](../enso_profiler/struct.Objective.html)) needs an implementation of
//! [`Parent`](../enso_profiler/trait.Parent.html) for each finer-grained profiler type;
//! implementing this without proc macros would be complex and repetitious.
//! - To implement the [`#[profile]`](macro@profile) attribute macro.
#![cfg_attr(feature = "lineno", feature(proc_macro_span))]
#![deny(unconditional_recursion)]
#![warn(missing_copy_implementations)]
#![warn(missing_debug_implementations)]
#![warn(missing_docs)]
#![warn(trivial_casts)]
#![warn(trivial_numeric_casts)]
#![warn(unsafe_code)]
#![warn(unused_import_braces)]
use inflector::Inflector;
use quote::ToTokens;
use std::env;
use std::mem;
use syn::parse::Parser;
use syn::punctuated;
use syn::visit_mut;
use syn::visit_mut::VisitMut;
// =========================
// === define_hierarchy! ===
// =========================
#[allow(non_snake_case)]
/// Define a profiler type.
fn define_profiler(
level: &syn::Ident,
ObjIdent: &syn::Ident,
enabled: bool,
) -> proc_macro::TokenStream {
let start = quote::format_ident!("start_{}", level);
let with_same_start = quote::format_ident!("{}_with_same_start", level);
let level_link = format!("[{}-level](index.html#{})", level, level);
let doc_obj = format!("Identifies a {} profiler.", level_link);
let doc_start = format!("Start a new {} profiler.", level_link);
let doc_with_same_start = format!(
"Create a new {} profiler, with the same start as an existing profiler.",
level_link,
);
let ts = if enabled {
quote::quote! {
// =================================
// === Profiler (e.g. Objective) ===
// =================================
#[doc = #doc_obj]
#[derive(Copy, Clone, Debug)]
pub struct #ObjIdent(pub ProfilerId);
// === Trait Implementations ===
impl Profiler for #ObjIdent {
type Started = ProfilerData;
fn finish(self, data: &Self::Started) {
data.finish(self.0);
}
}
// === Constructor macros ===
#[doc = #doc_start]
#[macro_export]
macro_rules! #start {
($parent: expr, $label: expr) => {{
use profiler::Parent;
let label = concat!($label, " (", file!(), ":", line!(), ")");
let profiler: profiler::Started<profiler::#ObjIdent> = $parent.new_child(label);
profiler
}}
}
#[doc = #doc_with_same_start]
#[macro_export]
macro_rules! #with_same_start {
($parent: expr, $label: expr) => {{
use profiler::Parent;
let label = concat!($label, " (", file!(), ":", line!(), ")");
let profiler: profiler::Started<profiler::#ObjIdent> =
$parent.new_child_same_start(label);
profiler
}}
}
}
} else {
quote::quote! {
// =================================
// === Profiler (e.g. Objective) ===
// =================================
#[doc = #doc_obj]
#[derive(Copy, Clone, Debug)]
pub struct #ObjIdent(pub ());
// === Trait Implementations ===
impl Profiler for #ObjIdent {
type Started = ();
fn finish(self, _: &Self::Started) {}
}
// === Constructor macros ===
#[doc = #doc_start]
#[macro_export]
macro_rules! #start {
($parent: expr, $label: expr) => {
profiler::Started { profiler: profiler::#ObjIdent(()), data: () }
}
}
#[macro_export]
#[doc = #doc_with_same_start]
macro_rules! #with_same_start {
($parent: expr, $label: expr) => {
profiler::Started { profiler: profiler::#ObjIdent(()), data: () }
}
}
}
};
ts.into()
}
/// Generates an implementation of the [`Parent`] trait relating the given parent and child, when
/// both are enabled.
#[allow(non_snake_case)]
fn enabled_impl_parent(
ParentIdent: &syn::Ident,
ChildIdent: &syn::Ident,
) -> proc_macro::TokenStream {
let ts = quote::quote! {
impl Parent<#ChildIdent> for #ParentIdent {
fn new_child(&self, label:Label) -> Started<#ChildIdent> {
let profiler = #ChildIdent(ProfilerId::new());
let parent = self.0;
let start = Some(Timestamp::now());
let data = ProfilerData { parent, start, label };
Started { profiler, data }
}
fn new_child_same_start(&self, label:Label) -> Started<#ChildIdent> {
let profiler = #ChildIdent(ProfilerId::new());
let parent = self.0;
let start = None;
let data = ProfilerData { parent, start, label };
Started { profiler, data }
}
}
};
ts.into()
}
/// Generates an implementation of the [`Parent`] trait relating the given parent and child, when
/// the child is disabled.
#[allow(non_snake_case)]
fn disabled_impl_parent(
ParentIdent: &syn::Ident,
ChildIdent: &syn::Ident,
) -> proc_macro::TokenStream {
let ts = quote::quote! {
impl Parent<#ChildIdent> for #ParentIdent {
fn new_child(&self, label: Label) -> Started<#ChildIdent> {
self.new_child_same_start(label)
}
fn new_child_same_start(&self, _label: Label) -> Started<#ChildIdent> {
let profiler = #ChildIdent(());
let data = ();
Started { profiler, data }
}
}
};
ts.into()
}
/// Return the numeric Profiling Level (counting from 0 = top-level only).
fn get_enabled_level(levels: &[impl AsRef<str>]) -> usize {
const PROFILING_LEVEL_ENV_VAR: &str = "ENSO_MAX_PROFILING_LEVEL";
let enabled = match env::var(PROFILING_LEVEL_ENV_VAR) {
Ok(level) => level,
// If the variable isn't set, we default to the minimum.
Err(_) => return 0,
};
for (i, name) in levels.iter().enumerate() {
if &enabled[..] == name.as_ref() {
return i;
}
}
panic!("{} set to unknown profiling level: {}", PROFILING_LEVEL_ENV_VAR, enabled);
}
/// Defines a hierarchy of profiler levels.
///
/// # Usage
///
/// ```ignore
/// enso_profiler_macros::define_hierarchy![Objective, Task, Detail, Debug];
/// ```
///
/// Profiler-levels must be specified from coarsest to finest.
///
/// Profiler-level names should be given in CamelCase.
#[proc_macro]
#[allow(non_snake_case)]
pub fn define_hierarchy(ts: proc_macro::TokenStream) -> proc_macro::TokenStream {
let parser = punctuated::Punctuated::<syn::Ident, syn::Token![,]>::parse_terminated;
let idents: Vec<_> = parser.parse(ts).unwrap().into_iter().collect();
let level_names: Vec<_> = idents.iter().map(|id| id.to_string().to_snake_case()).collect();
let enabled_level = get_enabled_level(&level_names);
let mut out = proc_macro::TokenStream::new();
for ((i, ObjIdent), level_name) in idents.iter().enumerate().zip(level_names.iter()) {
let snake_ident = syn::Ident::new(level_name, proc_macro2::Span::call_site());
out.extend(define_profiler(&snake_ident, ObjIdent, enabled_level >= i));
for (j, ChildIdent) in idents[i..].iter().enumerate() {
let parent_impl = match enabled_level >= i + j {
true => enabled_impl_parent(ObjIdent, ChildIdent),
false => disabled_impl_parent(ObjIdent, ChildIdent),
};
out.extend(parent_impl);
}
}
out
}
// ================
// === profile! ===
// ================
// [Documented in `profiler`](../enso_profiler/attr.profile.html).
#[allow(missing_docs)]
#[proc_macro_attribute]
pub fn profile(
args: proc_macro::TokenStream,
ts: proc_macro::TokenStream,
) -> proc_macro::TokenStream {
assert!(args.is_empty(), "#[profile] does not expect any arguments");
let mut func = syn::parse_macro_input!(ts as syn::ItemFn);
let body_default =
Box::new(syn::Block { brace_token: Default::default(), stmts: vec![] });
let mut new_body = body_default.clone();
let orig_body = mem::replace(&mut func.block, body_default);
let orig_sig = func.sig.clone();
// Emit instrumentation at the beginning of the new body; genericize the wrapper's signature.
instrument(&mut func.sig, &mut new_body);
// Instead of inserting the original body directly, wrap it in a closure that is not generic
// over `impl Parent`; this avoids the code-size cost of monomorphizing it.
wrap_body(&orig_sig, *orig_body, &mut new_body);
func.block = new_body;
func.into_token_stream().into()
}
// === instrument ===
/// Insert instrumentation into the body, and genericize the profiler input to `impl Parent`.
fn instrument(sig: &mut syn::Signature, body: &mut syn::Block) {
let profiler_label = make_label(&sig.ident);
// Parse profiler argument in signature.
let last_arg = match sig.inputs.last_mut() {
Some(syn::FnArg::Typed(pat_type)) => pat_type,
_ => panic!("Function annotated with #[profile] must have a profiler argument."),
};
let profiler = last_arg.pat.clone();
// Replace profiler type `T `in sig with `impl Parent<T>`.
let profiler_type_in = last_arg.ty.clone();
let profiler_generic_parent = quote::quote! { impl profiler::Parent<#profiler_type_in> };
last_arg.ty = Box::new(syn::Type::Verbatim(profiler_generic_parent));
// Emit instrumentation statements.
let start_profiler = quote::quote! {
let _profiler = #profiler.new_child(#profiler_label);
};
let get_profiler = quote::quote! {
let #profiler = _profiler.profiler;
};
body.stmts.push(syn::parse(start_profiler.into()).unwrap());
body.stmts.push(syn::parse(get_profiler.into()).unwrap());
}
#[cfg(not(feature = "lineno"))]
/// Decorate the input with file:line info determined by the proc_macro's call site.
fn make_label(ident: &syn::Ident) -> String {
format!("{} (?:?)", ident)
}
#[cfg(feature = "lineno")]
/// Decorate the input with file:line info determined by the proc_macro's call site.
fn make_label(ident: &syn::Ident) -> String {
let span = proc_macro::Span::call_site();
let file = span.source_file().path();
let path = file.as_path().to_string_lossy();
let line = span.start().line;
format!("{} ({}:{})", ident, path, line)
}
// === wrap_body ===
type ClosureInputs = punctuated::Punctuated<syn::Pat, syn::Token![,]>;
type CallArgs = punctuated::Punctuated<syn::Expr, syn::Token![,]>;
/// Transforms a function's body into a new body that:
/// - Defines a nested function whose body is the original body.
/// - Calls the inner function, forwarding all arguments, returning its result.
///
/// The output of this transformation is operationally equivalent to the input; it is only useful in
/// conjunction with additional transformations. In particular, if after further transformation the
/// outer function is more generic than the inner function for some parameters, this pattern avoids
/// the code-size cost of monomorphization for those parameters.
///
/// # Implementation
///
/// For the nested function, we generate a closure rather than the more common `fn` seen with this
/// pattern because we need to be able to forward a `self` argument, but have no way to determine
/// the type of `Self`, so we can't write a function signature. In a closure definition, we can
/// simply leave the type of that argument implicit.
///
/// # Limitations
///
/// Not currently supported:
/// - `unsafe` functions
/// - functions with destructuring bindings
/// - functions containing an `impl` for a `struct` or `trait`
fn wrap_body(sig: &syn::Signature, mut body: syn::Block, body_out: &mut syn::Block) {
// If there's a `self` parameter, we need to replace it with an ordinary binding in the wrapped
// block (here) and signature (below, building `closure_inputs`).
let placeholder_self = syn::Ident::new("__wrap_body__self", proc_macro2::Span::call_site());
let find = syn::Ident::new("self", proc_macro2::Span::call_site());
let replace = placeholder_self.clone();
ReplaceAll { find, replace }.visit_block_mut(&mut body);
let mut call_args = CallArgs::new();
let mut closure_inputs = ClosureInputs::new();
for input in &sig.inputs {
call_args.push(match input {
syn::FnArg::Receiver(r) => ident_to_expr(r.self_token.into()),
syn::FnArg::Typed(pat_type) => pat_to_expr(&pat_type.pat),
});
closure_inputs.push(match input {
syn::FnArg::Receiver(_) => ident_to_pat(placeholder_self.clone()),
syn::FnArg::Typed(pat_ty) => pat_ty.clone().into(),
});
}
let wrapped = match &sig.asyncness {
None => quote::quote! {
return (|#closure_inputs| #body)(#call_args);
},
Some(_) => quote::quote! {
return (|#closure_inputs| async { #body })(#call_args).await;
},
};
body_out.stmts.push(syn::parse(wrapped.into()).unwrap());
}
struct ReplaceAll {
find: proc_macro2::Ident,
replace: proc_macro2::Ident,
}
impl visit_mut::VisitMut for ReplaceAll {
fn visit_ident_mut(&mut self, i: &mut syn::Ident) {
if i == &self.find {
*i = self.replace.clone();
}
}
}
fn pat_to_expr(pat: &syn::Pat) -> syn::Expr {
match pat {
syn::Pat::Ident(syn::PatIdent { ident, .. }) => ident_to_expr(ident.to_owned()),
syn::Pat::Reference(syn::PatReference { pat, mutability, .. }) => {
let expr = Box::new(pat_to_expr(pat));
let mutability = mutability.to_owned();
let attrs = Default::default();
let and_token = Default::default();
let raw = Default::default();
syn::ExprReference { expr, mutability, attrs, and_token, raw }.into()
}
_ => unimplemented!("destructuring-bind in signature of fn wrapped by #[profile]"),
}
}
fn ident_to_expr(ident: syn::Ident) -> syn::Expr {
let path = ident.into();
let attrs = Default::default();
let qself = Default::default();
syn::ExprPath { path, qself, attrs }.into()
}
fn ident_to_pat(ident: syn::Ident) -> syn::Pat {
let attrs = Default::default();
let by_ref = None;
let mutability = None;
let subpat = None;
syn::PatIdent { attrs, by_ref, mutability, ident, subpat }.into()
}

View File

@ -0,0 +1,773 @@
//! Instrumentation for timing execution of code.
//!
//! Supports the
//! [Profiling](https://github.com/enso-org/design/blob/main/epics/profiling/implementation.md)
//! design.
//!
//! # Profiler hierarchy
//!
//! Every profiler has a parent, except the special profiler value [`APP_LIFETIME`]. Each of its
//! children is considered a *root profiler*.
//!
//! ## Parents of async tasks
//!
//! `async` tasks do not have an inherent parent-child relationship. To fit them into a hierarchical
//! data model, we must rely on convention: when a profiler is created, **its parent must be
//! chosen** such that the lifetime of the child is entirely bounded within the lifetime of the
//! parent. The appropriate parent for a profiler will not necessarily be its direct ancestor in
//! scope, nor necessarily the most recent profiler that has been started and not yet finished--
//! typically, it will be both of those things, but users must be aware of exceptional cases.
//! Exceptions will usually occur when a task is *spawned*, e.g. with `executor::global::spawn`.
//!
//! # Profiling levels
//!
//! Profiling has performance overhead; to support fine-grained measurement when it is needed, but
//! avoid its costs when it is not, measurements are classified into *profiling levels*.
//!
//! This API only allows creating a profiler of the same or finer-grained level than its parent.
//!
//! #### Objective
//! Measurements that correspond directly to aspects of the user experience. An *objective* can
//! contain other *objective*s, e.g. *GUI initialization* (which might be defined as: time from
//! opening the app until the app is ready to receive user input) contains *time until the loading
//! spinner finishes*.
//! #### Task
//! Coarse-grained tasks, such as app window initialization, GUI downloading, or WASM compilation. A
//! *task* can contain other *task*s e.g. GUI initialization contains GUI downloading.
//! #### Detail
//! All processes which can be removed in compile-time for the official stable release for users. We
//! might provide some users with special releases with enabled *detailed* profiling, however, it
//! should be possible to debug and understand most of user-provided logs with disabled *details*
//! view.
//! #### Debug
//! All processes which should be removed in compile-time by default even during app development. It
//! applies to every heavy-usage of the profiling framework, such as per-frame rendering profiling.
//!
//! ## Conditional compilation
//!
//! The level of profiling detail is set at compile time with an environment variable, e.g.
//! `ENSO_MAX_PROFILING_LEVEL=task`. When using the `run` script, this can be accomplished by
//! passing the argument `--profiling-level=task`.
//!
//! If the environment variable is not set, the level will default to the minimum supported,
//! *objective*.
//!
//! # Structured measurement
//!
//! This API can be used to make arbitrary measurements; in order to ensure measurements are easy to
//! interpret, the intervals selected for measurement should correspond as much as possible to the
//! units of organization of the code.
//!
//! To support such structured measurement, the **primary interface is a
//! [`#[profile]`](macro@profile) attribute macro**, which instruments a whole function.
//!
//! # Low-level: RAII interface
//!
//! When it is not feasible to measure at the function level (for example if moving the section of
//! interest into its own function would divide the code into unreasonably small functions), or a
//! measurement needs to be made with special properties (e.g. with its start time inherited from
//! its parent), a *RAII interface* supports **instrumenting a block of code**.
//!
//! The core of the interface is a set of [macros](index.html#macros) that create a new profiler,
//! and return a *RAII guard* object of a type like [`Started<Task>`]. The guard object will
//! automatically log the end of a measurement when it is dropped.
//!
//! In rare cases, it will be necessary to measure an interval that doesn't correspond to a block at
//! any level of the code. This can be achieved using the RAII interface by allowing the guard
//! object to escape the scope in which it is created to control its `drop()` time.
//!
//! ## Basic usage
//!
//! ```
//! # use enso_profiler as profiler;
//! fn using_low_level_api(input: u32, profiler: impl profiler::Parent<profiler::Task>) {
//! if input == 4 {
//! let _profiler = profiler::start_task!(profiler, "subtask_4");
//! // ...
//! } else {
//! let _profiler = profiler::start_task!(profiler, "subtask_other");
//! // ...
//! }
//! }
//! ```
//!
//! ## Measuring a block
//!
//! When a measurement is ended by implicitly dropping its profiler at the end of a block, the
//! profiler should be created as **the first line of the block**; it measures one full block, and
//! the line containing [`start_task!`] (or the like) acts as a title for the block.
//!
//! In this case, the binding used to control the scope of the measurement should have a **name
//! beginning with an underscore**, even if it is referenced (e.g. to create a child profiler). This
//! indicates that the binding is used to identify a scope, even if it is *also* used for its a
//! value.
//!
//! ## Accepting a parent argument
//!
//! A function using the low-level API may need to accept a profiler argument to use as the parent
//! for a new profiler. The function should be able to accept any type of profiler that is of a
//! suitable level to be a parent of the profiler it is creating. This is supported by accepting an
//! **argument that is generic over the [`Parent`] trait**.
//!
//! ## Advanced Example: creating a root profiler
//!
//! ```
//! # use enso_profiler as profiler;
//! fn root_objective_that_starts_at_time_origin() {
//! let _profiler = profiler::objective_with_same_start!(
//! profiler::APP_LIFETIME,
//! "root_objective_that_starts_at_time_origin"
//! );
//! // ...
//! }
//! ```
//!
//! ### Root profilers
//!
//! The profiler constructor macros require a parent. To create a *root profiler*, specify the
//! special value [`APP_LIFETIME`] as the parent.
//!
//! ### Inheriting a start time
//!
//! Sometimes, multiple measurements need to start at the same time. To support this, an alternate
//! set of constructors create profilers that inherit their start time from the specified parent,
//! e.g. [`objective_with_same_start!`] in the example above.
#![feature(test)]
#![deny(unconditional_recursion)]
#![warn(missing_copy_implementations)]
#![warn(missing_debug_implementations)]
#![warn(missing_docs)]
#![warn(trivial_casts)]
#![warn(trivial_numeric_casts)]
#![warn(unsafe_code)]
#![warn(unused_import_braces)]
extern crate test;
use std::cell;
use std::num;
use std::str;
// =============
// === Label ===
// =============
/// The label of a profiler; this includes the name given at its creation, along with file and
/// line-number information.
pub type Label = &'static str;
// =================
// === Timestamp ===
// =================
/// Time elapsed since the [time origin](https://www.w3.org/TR/hr-time-2/#sec-time-origin).
///
/// Stored in units of 100us, because that is maximum resolution of performance.now():
/// - [in the specification](https://www.w3.org/TR/hr-time-3), 100us is the limit
/// - in practice, as observed in debug consoles: Chromium 97 (100us) and Firefox 95 (1ms)
#[derive(Copy, Clone, PartialEq, Eq, PartialOrd, Ord, Debug)]
pub struct Timestamp(num::NonZeroU64);
/// Offset used to encode a timestamp, which may be 0, in a [`NonZeroU64`].
/// To maximize the supported range, this is the smallest positive integer.
const TS_OFFSET: u64 = 1;
impl Timestamp {
/// Return the current time, relative to the time origin.
pub fn now() -> Self {
Self::from_ms(js::performance::now())
}
/// Return the timestamp corresponding to an offset from the time origin, in ms.
#[allow(unsafe_code)]
pub fn from_ms(ms: f64) -> Self {
let ticks = (ms * 10.0).round() as u64;
// Safety: ticks + 1 will not be 0 unless a Timestamp wraps.
// It takes (2 ** 64) * 100us = 58_455_453 years for a Timestamp to wrap.
unsafe { Self(num::NonZeroU64::new_unchecked(ticks + TS_OFFSET)) }
}
/// Convert to an offset from the time origin, in ms.
pub fn into_ms(self) -> f64 {
(self.0.get() - TS_OFFSET) as f64 / 10.0
}
}
// === FFI ===
#[cfg(target_arch = "wasm32")]
/// Web APIs.
pub mod js {
/// [The `Performance` API](https://developer.mozilla.org/en-US/docs/Web/API/Performance)
pub mod performance {
use wasm_bindgen::prelude::*;
#[wasm_bindgen]
extern "C" {
/// The
/// [performance.now](https://developer.mozilla.org/en-US/docs/Web/API/Performance/now)
/// method returns a double-precision float, measured in milliseconds.
///
/// The returned value represents the time elapsed since the time origin, which is when
/// the page began to load.
#[wasm_bindgen(js_namespace = performance)]
pub fn now() -> f64;
}
}
}
#[cfg(not(target_arch = "wasm32"))]
/// Web APIs.
pub mod js {
/// [The `Performance` API](https://developer.mozilla.org/en-US/docs/Web/API/Performance)
pub mod performance {
/// The
/// [performance.now](https://developer.mozilla.org/en-US/docs/Web/API/Performance/now)
/// method returns a double-precision float, measured in milliseconds.
///
/// The returned value represents the time elapsed since the time origin, which is when
/// the page began to load.
// This mock implementation returns a dummy value.
pub fn now() -> f64 {
0.0
}
}
}
// ==================
// === ProfilerId ===
// ==================
/// Uniquely identifies a runtime measurement.
#[derive(Copy, Clone, Debug, PartialEq, Eq)]
pub struct ProfilerId(u32);
impl ProfilerId {
fn new() -> Self {
thread_local! {
pub static NEXT_ID: cell::Cell<u32> = cell::Cell::new(1);
}
ProfilerId(NEXT_ID.with(|next_id| {
let id = next_id.get();
next_id.set(id + 1);
id
}))
}
}
/// Pseudo-profiler serving as the root of the measurement hierarchy.
pub const APP_LIFETIME: Objective = Objective(ProfilerId(0));
// =======================
// === StartedProfiler ===
// =======================
/// The interface supported by profiler-data objects.
pub trait StartedProfiler {
/// Log a measurement, identified by `profiler`, with end-time set to now.
fn finish(&self, profiler: ProfilerId);
}
// === Implementation for disabled profilers ===
impl StartedProfiler for () {
fn finish(&self, _: ProfilerId) {}
}
// ====================
// === ProfilerData ===
// ====================
/// Data used by a started [`Measurement`] for an enabled profile level.
#[derive(Debug, Copy, Clone)]
pub struct ProfilerData {
/// Identifier of the parent [`Measurement`].
pub parent: ProfilerId,
/// Start time for this [`Measurement`], or None to indicate it is the same as `parent`.
pub start: Option<Timestamp>,
/// Identifies where in the code this [`Measurement`] originates.
pub label: Label,
}
// === Trait Implementations ===
impl StartedProfiler for ProfilerData {
fn finish(&self, profiler: ProfilerId) {
let parent = self.parent;
let start = self.start;
let label = self.label;
let end = Timestamp::now();
let measurement = Measurement { parent, profiler, start, end, label };
crate::MEASUREMENTS.with(move |log| log.push(measurement));
}
}
// ===================
// === Measurement ===
// ===================
/// Record of a profiled section, the parent it was reached by, and its entry and exit times.
#[derive(Debug, Copy, Clone)]
pub struct Measurement {
/// A unique identifier.
pub profiler: ProfilerId,
/// Identifies parent [`Measurement`] by its `profiler` field.
pub parent: ProfilerId,
/// Start time, or None to indicate it is the same as `parent`.
pub start: Option<Timestamp>,
/// The end time.
pub end: Timestamp,
/// Identifies where in the code this [`Measurement`] originates.
pub label: Label,
}
/// Internal
pub mod internal {
use crate::*;
use std::cell;
use std::mem;
// =======================
// === LocalVecBuilder ===
// =======================
/// Data structure supporting limited interior mutability, to build up a collection.
#[derive(Debug)]
pub struct LocalVecBuilder<T>(cell::UnsafeCell<Vec<T>>);
#[allow(unsafe_code)]
impl<T> LocalVecBuilder<T> {
#[allow(clippy::new_without_default)]
/// Create a new, empty vec builder.
pub fn new() -> Self {
Self(cell::UnsafeCell::new(vec![]))
}
/// Push an element.
pub fn push(&self, element: T) {
// Note [LocalVecBuilder Safety]
unsafe {
(&mut *self.0.get()).push(element);
}
}
/// Return (and consume) all elements pushed so far.
pub fn build(&self) -> Vec<T> {
// Note [LocalVecBuilder Safety]
unsafe { mem::take(&mut *self.0.get()) }
}
}
// Note [LocalVecBuilder Safety]
// =============================
// When obtaining a reference from the UnsafeCell, all accessors follow these rules:
// - There must be a scope that the reference doesn't escape.
// - There must be no other references obtained in the same scope.
// Consistently following these rules ensures the no-alias rule of mutable references is
// satisfied.
// ====================
// === MEASUREMENTS ===
// ====================
thread_local! {
/// Global log of [`Measurement`]s.
pub static MEASUREMENTS: LocalVecBuilder<Measurement> = LocalVecBuilder::new();
}
}
#[doc(inline)]
pub use internal::MEASUREMENTS;
/// Gather all measurements taken since the last time take_log() was called.
pub fn take_log() -> Vec<Measurement> {
MEASUREMENTS.with(|log| log.build())
}
// ================
// === Profiler ===
// ================
/// The interface supported by profilers of all profiling levels.
pub trait Profiler: Copy {
/// Metadata this profiler stores from when it is started until it is finished.
type Started: StartedProfiler;
/// Log a measurement, using `self` as identifier, the present time as end time, and metadata as
/// provided in `data`.
fn finish(self, data: &Self::Started);
}
// ==============
// === Parent ===
// ==============
/// Any object representing a profiler that is a valid parent for a profiler of type T.
pub trait Parent<T: Profiler> {
/// Start a new profiler, with `self` as its parent.
fn new_child(&self, label: Label) -> Started<T>;
/// Create a new profiler, with `self` as its parent, and the same start time as `self`.
fn new_child_same_start(&self, label: Label) -> Started<T>;
}
// ===============
// === Started ===
// ===============
/// A profiler that has a start time set, and will complete its measurement when dropped.
#[derive(Debug)]
pub struct Started<T: Profiler> {
/// The ID to log this measurement as.
pub profiler: T,
/// Metadata to associate with this measurement when it is logged.
pub data: T::Started,
}
// === Trait Implementations ===
impl<T: Profiler> Drop for Started<T> {
fn drop(&mut self) {
let profiler = self.profiler;
profiler.finish(&self.data);
}
}
impl<T, U> Parent<T> for Started<U>
where
U: Parent<T> + Profiler,
T: Profiler,
{
fn new_child(&self, label: Label) -> Started<T> {
self.profiler.new_child(label)
}
fn new_child_same_start(&self, label: Label) -> Started<T> {
self.profiler.new_child_same_start(label)
}
}
// ===================================
// === profiler_macros Invocations ===
// ===================================
/// Instruments a function.
///
/// For each call to the function, a measurement of the time interval corresponding to the
/// function's body is logged under the name of the function, with file:line information
/// attached.
///
/// # Usage
///
/// The last argument must be an instance of a profiler type. The type given determines the
/// profiling level at which measurement is enabled; the macro will modify the function's
/// signature so that it can be called with any profiler that could be a *parent* of the
/// profiler.
///
/// ```
/// # use enso_profiler as profiler;
/// # use enso_profiler::profile;
/// #[profile]
/// fn small_computation(input: i16, profiler: profiler::Detail) -> u32 {
/// todo!()
/// }
///
/// #[enso_profiler_macros::profile]
/// fn bigger_computation(profiler: profiler::Task) -> u32 {
/// // Our task-level profiler is not the same type as the detail-level profiler available
/// // inside `small_computation`; it will be converted implicitly.
/// small_computation(7, profiler)
/// }
/// ```
///
/// This will expand to the equivalent of:
///
/// ```
/// # use enso_profiler as profiler;
/// # use enso_profiler::profile;
/// fn small_computation(input: i16, profiler: impl profiler::Parent<profiler::Detail>) -> u32 {
/// let _profiler = profiler.new_child("small_computation (file.rs:43)");
/// let profiler = _profiler.profiler;
/// return (|input: i16, profiler: profiler::Detail| todo!())(input, profiler);
/// }
///
/// fn bigger_computation(profiler: impl profiler::Parent<profiler::Task>) -> u32 {
/// let _profiler = profiler.new_child("bigger_computation (file.rs:48)");
/// let profiler = _profiler.profiler;
/// return (|profiler: profiler::Task| {
/// // Our task-level profiler is not the same type as the detail-level profiler available
/// // inside `small_computation`; it will be converted implicitly.
/// small_computation(7, profiler)
/// })(profiler);
/// }
/// ```
///
/// # Limitations
///
/// Some syntactic constructs are not (currently) supported.
///
/// ## Unsafe functions
///
/// Unsafe functions cannot be wrapped (yet). Use the low-level API.
///
/// ## Destructuring binding in function signatures
///
/// This won't compile:
///
/// ```compile_fail
/// # use enso_profiler as profiler;
/// # use profiler::profile;
/// #[profile]
/// fn unsupported_binding((x, y): (u32, u32), profiler: profiler::Task) -> u32 {
/// x + y
/// }
/// ```
///
/// Instead, rewrite the function to take the destructuring out of the signature:
///
/// ```
/// # use enso_profiler as profiler;
/// # use profiler::profile;
/// #[profile]
/// fn supported_binding(xy: (u32, u32), profiler: profiler::Task) -> u32 {
/// let (x, y) = xy;
/// x + y
/// }
/// ```
///
/// ## Method definitions in nested items
///
/// Use of the `self` keyword to refer to anything except the receiver of the wrapped item is
/// not supported; this means you can't define methods *inside* a wrapped function, like this:
///
/// ```compile_fail
/// # use enso_profiler as profiler;
/// # use profiler::profile;
/// #[profile]
/// fn bad_nested_method_def(profiler: profiler::Task) {
/// // This is technically legal syntax, but #[profile] doesn't support it.
/// struct Foo;
/// impl Foo {
/// fn consume(self) {}
/// fn call_consume(self) {
/// self.consume()
/// }
/// }
/// // ...
/// }
/// ```
///
/// Instead, define the items outside the lexical scope of the profiled function:
///
/// ```
/// # use enso_profiler as profiler;
/// # use profiler::profile;
/// struct Foo;
/// impl Foo {
/// fn consume(self) {}
/// fn call_consume(self) {
/// self.consume()
/// }
/// }
///
/// #[profile]
/// fn no_nested_method_def(profiler: profiler::Task) {
/// // ...
/// }
/// ```
#[doc(inline)]
pub use enso_profiler_macros::profile;
enso_profiler_macros::define_hierarchy![Objective, Task, Detail, Debug];
// =============
// === Tests ===
// =============
#[cfg(test)]
mod tests {
use crate as profiler;
use profiler::profile;
#[test]
fn root() {
{
// In any other crate we would refer to the macro as `profiler::start_objective!`, but
// "macro-expanded `macro_export` macros from the current crate cannot be referred to
// by absolute paths" (<https://github.com/rust-lang/rust/issues/52234>).
let _profiler = start_objective!(profiler::APP_LIFETIME, "test");
}
let measurements = profiler::take_log();
assert_eq!(measurements.len(), 1);
assert_eq!(measurements[0].parent, profiler::APP_LIFETIME.0);
assert!(measurements[0].label.starts_with("test "));
assert!(measurements[0].end >= measurements[0].start.unwrap());
}
#[test]
fn with_same_start() {
{
let _profiler0 = start_objective!(profiler::APP_LIFETIME, "test0");
let _profiler1 = objective_with_same_start!(_profiler0, "test1");
}
let measurements = profiler::take_log();
assert_eq!(measurements.len(), 2);
// _profiler1 is with_same_start, indicated by None in the log
// Note: _profiler1 is _measurements[0] because position in the log is determined by end
// order, not start order.
assert_eq!(measurements[0].start, None);
// _profiler0 has a start time
assert!(measurements[1].start.is_some());
}
#[test]
fn profile() {
#[profile]
fn profiled(_profiler: profiler::Objective) {}
profiled(profiler::APP_LIFETIME);
let measurements = profiler::take_log();
assert_eq!(measurements.len(), 1);
}
#[test]
fn profile_async() {
#[profile]
async fn profiled(_profiler: profiler::Objective) -> u32 {
let block = async { 4 };
block.await
}
let future = profiled(profiler::APP_LIFETIME);
futures::executor::block_on(future);
let measurements = profiler::take_log();
assert_eq!(measurements.len(), 1);
}
}
// Performance analysis [KW]
//
// Performance impact: Except at low numbers of measurements, run time is dominated by growing the
// vector. I'm measuring about 1.6ns per logged measurement [Ryzen 5950X], when accumulating 10k
// measurements.
// I think the cost of the unavoidable performance.now() will be on the order of 1μs, in which case
// the overhead of #[profile] is within 0.1 % of an optimal implementation.
//
// Performance variability impact: There's no easy way to measure this, so I'm speaking
// theoretically here. The only operation expected to have a significantly variable cost is the
// Vec::push to grow the MEASUREMENTS log; it sometimes needs to reallocate. However even at its
// most expensive, it should be on the order of a 1μs (for reasonable numbers of measurements); so
// the variance introduced by this framework shouldn't disturb even very small measurements (I
// expect <1% added variability for a 1ms measurement).
#[cfg(test)]
mod bench {
use crate as profiler;
/// Perform a specified number of measurements, for benchmarking.
fn log_measurements(count: usize) {
for _ in 0..count {
let _profiler = start_objective!(profiler::APP_LIFETIME, "");
}
test::black_box(profiler::take_log());
}
#[bench]
fn log_measurements_1000(b: &mut test::Bencher) {
b.iter(|| log_measurements(1000));
}
#[bench]
fn log_measurements_10_000(b: &mut test::Bencher) {
b.iter(|| log_measurements(10_000));
}
/// For comparison with time taken by [`log_measurements`].
fn push_vec(count: usize, measurements: &mut Vec<profiler::Measurement>) {
let some_timestamp = profiler::Timestamp(std::num::NonZeroU64::new(1).unwrap());
for _ in 0..count {
measurements.push(profiler::Measurement {
parent: profiler::ProfilerId(0),
profiler: profiler::ProfilerId(0),
start: None,
end: some_timestamp,
label: "",
});
}
test::black_box(&measurements);
measurements.clear();
}
#[bench]
fn push_vec_1000(b: &mut test::Bencher) {
let mut measurements = vec![];
b.iter(|| push_vec(1000, &mut measurements));
}
#[bench]
fn push_vec_10_000(b: &mut test::Bencher) {
let mut measurements = vec![];
b.iter(|| push_vec(10_000, &mut measurements));
}
}
#[cfg(test)]
mod compile_tests {
use crate as profiler;
use profiler::profile;
/// Decorating a pub fn.
#[profile]
pub fn profiled_pub(_profiler: profiler::Objective) {}
#[profile]
async fn profiled_async(_profiler: profiler::Objective) {}
#[profile]
#[allow(unsafe_code)]
unsafe fn profiled_unsafe(_profiler: profiler::Objective) {}
#[test]
fn mut_binding() {
#[profile]
fn profiled(mut _x: u32, _profiler: profiler::Objective) {
_x = 4;
}
profiled(0, profiler::APP_LIFETIME);
let measurements = profiler::take_log();
assert_eq!(measurements.len(), 1);
}
// Unsupported:
// #[profile]
// fn profiled_destructuring((_x, _y): (u32, u32), _profiler: profiler::Objective) {}
#[allow(dead_code)]
struct Foo;
impl Foo {
#[profile]
fn profiled_method(&mut self, _arg: u32, _profiler: profiler::Objective) {
profiled_pub(_profiler)
}
}
}