swift-garage-61180
05/09/2023, 1:37 PMancient-diamond-80011
05/09/2023, 1:37 PMswift-garage-61180
05/09/2023, 1:37 PMancient-diamond-80011
05/09/2023, 1:39 PMts
async action(params: CommandParams<{}, {}>): Promise<CommandResult> {
const { garden } = params
const store = garden.globalConfigStore
// not awaiting here
const configPromise = store.set("clientAuthTokens", "throw.example.com", {
token: "",
refreshToken: "",
validity: new Date(),
})
throw new Error("oops")
}
and then adding some sleep()
to the set()
method on the configstore, and then manually removing the lock directory with rmdir
while the command is sleeping, because then in the finally
block of cli.ts
we call delete
for the activeProcessesancient-diamond-80011
05/09/2023, 1:41 PMENOENT
and ECOMPROMISED
combo with just the sleeps and throws and sets/deletesancient-diamond-80011
05/09/2023, 1:41 PMancient-diamond-80011
05/09/2023, 1:49 PM/Users/walther/git/garden/node_modules/yoga-layout-prebuilt/yoga-layout/build/Release/nbind.js:53
throw ex;
^
swift-garage-61180
05/09/2023, 2:00 PMswift-garage-61180
05/09/2023, 2:01 PMancient-diamond-80011
05/09/2023, 2:03 PMancient-diamond-80011
05/09/2023, 2:04 PMglobalConfigStore
somewhere
- somewhere, somehow we get a race condition
- something tries to update a lock that has already been deleted, or delete a lock that has already been deleted
- very likely this is happening in the finally
block of cli.ts
swift-garage-61180
05/09/2023, 2:05 PMswift-garage-61180
05/09/2023, 2:06 PMswift-garage-61180
05/09/2023, 2:06 PMancient-diamond-80011
05/09/2023, 2:07 PMisOverThreshold
conditions in the proper-lockfile
library in the updateLock
method, possibly from e.g. heavy synchronous code overloading the eventloop and getting time skew on the setTimeout
calls, leading to a difference in the expected time vs real timeancient-diamond-80011
05/09/2023, 2:08 PMENOENT
as part of the error messagesancient-diamond-80011
05/09/2023, 2:09 PMancient-diamond-80011
05/09/2023, 2:09 PMancient-diamond-80011
05/09/2023, 2:11 PMancient-diamond-80011
05/09/2023, 2:26 PMonExit
handler in the lockfile library, but it's also probably not related - considering we arrive at this error without external signals such as Ctrl-C or similarancient-diamond-80011
05/09/2023, 2:27 PMonExit
handler will not be called in case of a thrown exception, only on signals (but i could be wrong here)ancient-diamond-80011
05/09/2023, 2:28 PMonExit
handler any thrown errors are caught and not bubbled up, so we wouldn't see any errors from there)alert-helicopter-61082
05/09/2023, 2:30 PMonExit
handler (if we can) at the end of a CLI execution.alert-helicopter-61082
05/09/2023, 2:30 PMcold-jordan-68753
05/09/2023, 2:44 PMonCompromised
callback that we can potentially use instead of or in addition to the try/catch.alert-helicopter-61082
05/09/2023, 2:49 PMalert-helicopter-61082
05/09/2023, 2:51 PMalert-helicopter-61082
05/09/2023, 2:51 PMawait import(...)
for it, which should be fine for our use case I thinkancient-diamond-80011
05/09/2023, 2:53 PMswift-garage-61180
05/09/2023, 3:16 PMswift-garage-61180
05/09/2023, 3:16 PMancient-diamond-80011
05/09/2023, 3:17 PMswift-garage-61180
05/09/2023, 3:17 PMswift-garage-61180
05/10/2023, 8:16 AMancient-diamond-80011
05/10/2023, 8:16 AMancient-diamond-80011
05/10/2023, 8:17 AMswift-garage-61180
05/10/2023, 8:36 AMswift-garage-61180
05/10/2023, 8:48 AMswift-garage-61180
05/10/2023, 8:49 AMswift-garage-61180
05/10/2023, 8:49 AMswift-garage-61180
05/10/2023, 8:49 AMalert-helicopter-61082
05/10/2023, 9:32 AMalert-helicopter-61082
05/10/2023, 9:33 AMalert-helicopter-61082
05/10/2023, 9:33 AMswift-garage-61180
05/10/2023, 10:42 AMswift-garage-61180
05/10/2023, 10:43 AMswift-garage-61180
05/10/2023, 10:44 AMancient-diamond-80011
05/10/2023, 10:45 AMswift-garage-61180
05/10/2023, 10:46 AMprocess.on("uncaughtException", (...) => ...)
. I have a feeling this is fundamentally because of the async nature of the setTimeout
that's happening deep in the library.swift-garage-61180
05/10/2023, 10:47 AMancient-diamond-80011
05/10/2023, 10:47 AMswift-garage-61180
05/10/2023, 10:50 AMswift-garage-61180
05/10/2023, 11:21 AMswift-garage-61180
05/10/2023, 11:22 AMcold-jordan-68753
05/10/2023, 11:23 AMancient-diamond-80011
05/10/2023, 11:26 AMsetLockAsCompromised
function (and need to do so)
- that throw happens within the broader context of a setTimeout
call on line 109, so it is happening in an "outside" async context, not caught by surrounding try-catches
- however! if we monkeypatch the setTimeout
call to have internal try-catches as well, it still doesn't help
- of note: we are also within a callback function definition on the options.fs.stat(
call (line 114)
- it is also possible the execution of this stat call and the callback after it is handled in a separate async context in graceful-fs
and also ends up outside what we can catchancient-diamond-80011
05/10/2023, 11:30 AMif (asyncError)
before the callback completesswift-garage-61180
05/10/2023, 11:32 AMswift-garage-61180
05/10/2023, 11:32 AMcold-jordan-68753
05/10/2023, 11:38 AMancient-diamond-80011
05/10/2023, 11:42 AMcold-jordan-68753
05/10/2023, 11:45 AMancient-diamond-80011
05/10/2023, 11:45 AMfs.stat
callback handler (where it calls apply
and so on) seems to be happening in a separate async context, and we need to bring that back in to our main contextalert-helicopter-61082
05/10/2023, 11:59 AMalert-helicopter-61082
05/10/2023, 12:00 PMalert-helicopter-61082
05/10/2023, 12:01 PMtypescript
private async lock() {
const path = this.getConfigPath()
await ensureFile(path)
return new Promise<() => Promise<void>>((resolve, reject) => {
lock(path, { retries: 5, stale: 5000, onCompromised: reject }).then(resolve).catch(reject)
})
}
swift-garage-61180
05/10/2023, 12:13 PMancient-diamond-80011
05/10/2023, 12:14 PMcold-jordan-68753
05/10/2023, 12:14 PMalert-helicopter-61082
05/10/2023, 12:14 PMancient-diamond-80011
05/10/2023, 12:14 PMalert-helicopter-61082
05/10/2023, 12:15 PMalert-helicopter-61082
05/10/2023, 12:16 PMalert-helicopter-61082
05/10/2023, 12:19 PMalert-helicopter-61082
05/10/2023, 12:27 PMalert-helicopter-61082
05/10/2023, 12:27 PMancient-diamond-80011
05/10/2023, 12:46 PMancient-diamond-80011
05/10/2023, 12:47 PMonCompromised
handler that catches the error, does some better logging for our users, and then throws the stop-the-worldancient-diamond-80011
05/10/2023, 12:48 PMalert-helicopter-61082
05/10/2023, 12:48 PMancient-diamond-80011
05/10/2023, 12:49 PMancient-diamond-80011
05/10/2023, 12:49 PMancient-diamond-80011
05/10/2023, 12:49 PMalert-helicopter-61082
05/10/2023, 12:49 PMalert-helicopter-61082
05/10/2023, 12:50 PMancient-diamond-80011
05/10/2023, 12:50 PMupdateLock
method which is defined as a setTimeout
loop running in the backgroundancient-diamond-80011
05/10/2023, 12:50 PMwriteFile
execution will happily continue in the "other thread" (not exact terminology, but)alert-helicopter-61082
05/10/2023, 12:50 PMalert-helicopter-61082
05/10/2023, 12:51 PMcold-jordan-68753
05/10/2023, 12:52 PMcold-jordan-68753
05/10/2023, 12:53 PMalert-helicopter-61082
05/10/2023, 12:54 PMalert-helicopter-61082
05/10/2023, 12:55 PMalert-helicopter-61082
05/10/2023, 12:56 PMcold-jordan-68753
05/10/2023, 1:01 PMancient-diamond-80011
05/10/2023, 1:03 PMalert-helicopter-61082
05/10/2023, 1:04 PMalert-helicopter-61082
05/10/2023, 1:05 PMalert-helicopter-61082
05/10/2023, 1:06 PMalert-helicopter-61082
05/10/2023, 1:06 PMalert-helicopter-61082
05/10/2023, 1:07 PMancient-diamond-80011
05/10/2023, 1:08 PMalert-helicopter-61082
05/10/2023, 1:09 PM