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.tsswift-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