-
Notifications
You must be signed in to change notification settings - Fork 108
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Add a new "explain" logger #863
base: main
Are you sure you want to change the base?
Conversation
This is building up to writing an "explain" logger.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Looks great! Some pretty minor comments.
@@ -197,6 +198,9 @@ export const getOptions = (): Result<Options> => { | |||
if (str === 'quiet-ci') { | |||
return {ok: true, value: new QuietCiLogger(packageRoot)}; | |||
} | |||
if (str === 'explain') { | |||
return {ok: true, value: new ExplainLogger(packageRoot)}; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
WDYT about dynamic importing the explain logger here? It should be a rare import.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
+1!
README.md
Outdated
@@ -554,7 +554,7 @@ the given regular expression. | |||
|
|||
In watch mode, a service will be restarted whenever one of its input files or | |||
dependencies change, except for dependencies with | |||
[`cascade`](#execution-cascade) set to `false`. | |||
[`cascade`](#execution-cascade) set to `false`. Unlike standard scripts, `wireit` assumes that a service doesn't depend on any files unless you tell it otherwise by defining a `files` array. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Is this definitely true? I can't remember if it's intentional or not, do you think it's the right behavior?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Looked into it some more, and this seems like an oversight. It's better for services to have explicit "files", and the correct thing to do if that's not there is to restart on each new run. Updated.
if (script.files === undefined) { | ||
return {name: 'no files field'}; | ||
} | ||
// A standard script. Fully tracked if we know both its inputs and |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Should this comment be just above (above if (script.files === undefined) {
) ?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Ah, yes!
@@ -267,4 +294,186 @@ export class Fingerprint { | |||
equal(other: Fingerprint): boolean { | |||
return this.string === other.string; | |||
} | |||
|
|||
difference(previous: Fingerprint): FingerprintDifference | undefined { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Nit, would other
be a better name than previous
(more general -- previous
implies a certain relationship between the two fingerprints)?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
previous is the intended relationship here, and in both cases where it's currently called the other fingerprint is the called the previous fingerprint
this relationship is also represented in the FingerprintDifference
data structure (though I just noticed that I was created a lot of these values backwards, erp!)
by being specific we can give clearer messages when we log
>; | ||
type FieldsExcludingPlatform = Exclude<FingerprintFields, 'platform'>; | ||
if (this.data.platform !== previous.data.platform) { | ||
return { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There could be multiple fields that are different. WDYT about collecting all fields that differ and returning an array, instead of returning just the first one?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This is true across basically all of the "why" logging we do in this PR, and my thinking was that giving only the first cause of an action strikes the right balance of clarity and performance.
Maybe it would be better though to collect together things of like kind? Like, all of the environment changes into one change record, all of the config changes into one change record, etc.
Added a TODO
@@ -10,6 +10,10 @@ Versioning](https://semver.org/spec/v2.0.0.html). | |||
|
|||
## [Unreleased] | |||
|
|||
### Added | |||
|
|||
- Added a new logger for debugging your Wireit configs. Set `WIREIT_LOGGER=explain` to see detailed information about why each script is run, as well as the normal `simple` logs, without any stdout or stderr of scripts. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
It seems like a little more information is also added to the default logger in this PR (and I think simple logger, since it delegates to default sometimes?). Mention that too in a separate line?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Done
src/test/service.test.ts
Outdated
await wireit.waitForLog(/\[service\] Watching for file changes/); | ||
await new Promise((resolve) => setTimeout(resolve, 50)); | ||
assert.equal(service.numInvocations, 2); | ||
assert.equal(service.numInvocations, 3); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why did the numInvocations change? 🤔
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Good call! Investigated more, and I think it's because of a bug in wireit, that this test was testing, and that this change fixes. The relevant change is that I made services care about whether their dependencies are fully tracked when deciding whether they need to restart. If a dependency ran, and it's not cascade: false, and it's not fully tracked, then the service must restart, because the service's boot up might depend on an untracked output of the dependency.
In more detail:
[standard]
wasn't cacheable (i.e. wasn't fully tracked) as originally written because it didn't have an output
field. As a result, when we write 3
to standard's input file again, it needs to run again, and because of that [service]
needs to restart, because [service]
might consume some output of [standard]
th was emitted differently this time.
However this test is trying to test cases where [service]
doesn't need to restart, i.e. when after a failure of [standard]
we can revert it back to its previous version. That requires that [standard]
have an output
field, and then its final run is just a restore from cache.
src/logging/explain-logger.ts
Outdated
} | ||
} | ||
#logRunning(event: ScriptRunning) { | ||
const pipeRightTreeChar = '\u251c'; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
WDYT about just putting the character directly inline instead of having this variable? (That way we can see more easily whether it's the right one in the source)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Ah, yes, of course, that's much better
src/logging/explain-logger.ts
Outdated
console.log( | ||
`${downRightTreeChar} It can't be skipped because ${notFreshExplanation}.`, | ||
); | ||
// ? |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
What's this comment?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Ah, I was futzing about with making changes to trigger re-builds and looking at the output lol
@@ -74,6 +74,7 @@ async function retryWithGcUntilCallbackDoesNotThrow( | |||
cb: () => void, | |||
): Promise<void> { | |||
for (const wait of [0, 10, 100, 500, 1000]) { | |||
collectGarbage(); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
1 GC not enough?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Surprisingly, it often isn't. When doing memory leak tests in Lit we found that memory is often not freed unless you call gc twice in a row.
🤷
This test behaves the same with and without this change.
A somewhat different design, but intended to address the use case brought up in #806 and that we've frequently needed ourselves.