From 561c0f81a0d62b84fa47a98226eeb85eda864ffd Mon Sep 17 00:00:00 2001 From: "Terence D. Honles" Date: Thu, 21 May 2020 21:25:00 -0700 Subject: [PATCH] perf(ngcc): allow immediately reporting a stale lock file (#37250) Currently, if an ngcc process is killed in a manner that it doesn't clean up its lock file (or is killed too quickly) the compiler reports that it is waiting on the PID of a process that doesn't exist, and that it will wait up to a maximum of N seconds. This PR updates the locking code to additionally check if the process exists, and if it does not it will immediately bail out, and print the location of the lock file so a user may clean it up. PR Close #37250 --- .../ngcc/src/locking/async_locker.ts | 66 ++++++++++++++++--- .../ngcc/test/locking/async_locker_spec.ts | 48 ++++++++++++++ 2 files changed, 104 insertions(+), 10 deletions(-) diff --git a/packages/compiler-cli/ngcc/src/locking/async_locker.ts b/packages/compiler-cli/ngcc/src/locking/async_locker.ts index 670033baf7..6124b0985b 100644 --- a/packages/compiler-cli/ngcc/src/locking/async_locker.ts +++ b/packages/compiler-cli/ngcc/src/locking/async_locker.ts @@ -56,22 +56,68 @@ export class AsyncLocker { pid = newPid; } if (attempts === 0) { - this.logger.info( + // Check to see if the process identified by the PID is still running. Because the + // process *should* clean up after itself, we only check for a stale lock file when the + // PID changes and only once. This may mean you have to wait if the process is killed + // after the first check and isn't given the chance to clean up after itself. + if (!this.isProcessRunning(pid)) { + // try to re-lock one last time in case there was a race condition checking the process. + try { + return this.lockFile.write(); + } catch (e2) { + if (e2.code !== 'EEXIST') { + throw e2; + } + } + + // finally check that the lock was held by the same process this whole time. + const finalPid = this.lockFile.read(); + if (finalPid === pid) { + throw new TimeoutError(this.lockFileMessage( + `Lock found, but no process with PID ${pid} seems to be running.`)); + } else { + // attempts is still 0, but adjust the PID so the message below is correct. + pid = finalPid; + } + } + + this.logger.info(this.lockFileMessage( `Another process, with id ${pid}, is currently running ngcc.\n` + - `Waiting up to ${this.retryDelay * this.retryAttempts / 1000}s for it to finish.\n` + - `(If you are sure no ngcc process is running then you should delete the lock-file at ${ - this.lockFile.path}.)`); + `Waiting up to ${this.retryDelay * this.retryAttempts / 1000}s for it to finish.`)); } // The file is still locked by another process so wait for a bit and retry await new Promise(resolve => setTimeout(resolve, this.retryDelay)); } } // If we fall out of the loop then we ran out of rety attempts - throw new TimeoutError( - `Timed out waiting ${ - this.retryAttempts * this.retryDelay / - 1000}s for another ngcc process, with id ${pid}, to complete.\n` + - `(If you are sure no ngcc process is running then you should delete the lock-file at ${ - this.lockFile.path}.)`); + throw new TimeoutError(this.lockFileMessage(`Timed out waiting ${ + this.retryAttempts * this.retryDelay / + 1000}s for another ngcc process, with id ${pid}, to complete.`)); + } + + protected isProcessRunning(pid: string): boolean { + // let the normal logic run if this is not called with a valid PID + if (isNaN(+pid)) { + this.logger.debug(`Cannot check if invalid PID "${pid}" is running, a number is expected.`); + return true; + } + + try { + process.kill(+pid, 0); + return true; + } catch (e) { + // If the process doesn't exist ESRCH will be thrown, if the error is not that, throw it. + if (e.code !== 'ESRCH') { + throw e; + } + + return false; + } + } + + private lockFileMessage(message: string): string { + return message + + `\n(If you are sure no ngcc process is running then you should delete the lock-file at ${ + this.lockFile.path}.)`; } } diff --git a/packages/compiler-cli/ngcc/test/locking/async_locker_spec.ts b/packages/compiler-cli/ngcc/test/locking/async_locker_spec.ts index 9c6487b193..97d8a9c4f3 100644 --- a/packages/compiler-cli/ngcc/test/locking/async_locker_spec.ts +++ b/packages/compiler-cli/ngcc/test/locking/async_locker_spec.ts @@ -71,6 +71,7 @@ runInEachFileSystem(() => { } return lockFileContents; }); + spyOn(process, 'kill').and.returnValue(); const promise = locker.lock(async () => log.push('fn()')); // The lock is now waiting on the lock-file becoming free, so no `fn()` in the log. @@ -80,6 +81,7 @@ runInEachFileSystem(() => { `(If you are sure no ngcc process is running then you should delete the lock-file at ${ lockFile.path}.)` ]]); + expect(process.kill).toHaveBeenCalledWith(188, 0); lockFileContents = null; // The lock-file has been removed, so we can create our own lock-file, call `fn()` and then @@ -88,6 +90,47 @@ runInEachFileSystem(() => { expect(log).toEqual(['write()', 'read() => 188', 'write()', 'fn()', 'remove()']); }); + it('should fail fast when waiting on a dead process', async () => { + const fs = getFileSystem(); + const log: string[] = []; + const lockFile = new MockLockFile(fs, log); + const logger = new MockLogger(); + const locker = new AsyncLocker(lockFile, logger, 100, 10); + + let lockFileContents: string|null = '188'; + spyOn(lockFile, 'write').and.callFake(() => { + log.push('write()'); + if (lockFileContents) { + throw {code: 'EEXIST'}; + } + }); + spyOn(lockFile, 'read').and.callFake(() => { + log.push('read() => ' + lockFileContents); + if (lockFileContents === null) { + throw {code: 'ENOENT'}; + } + return lockFileContents; + }); + spyOn(process, 'kill').and.callFake(() => { + throw {code: 'ESRCH'}; + }); + + const promise = locker.lock(async () => log.push('fn()')); + // The lock has already failed so no `fn()` in the log. + expect(log).toEqual(['write()', 'read() => 188', 'write()', 'read() => 188']); + expect(logger.logs.info).toEqual([]); + expect(process.kill).toHaveBeenCalledWith(188, 0); + // Check that a missing process errors out. + let error: Error; + await promise.catch(e => error = e); + expect(log).toEqual(['write()', 'read() => 188', 'write()', 'read() => 188']); + expect(error!.message) + .toEqual( + `Lock found, but no process with PID 188 seems to be running.\n` + + `(If you are sure no ngcc process is running then you should delete the lock-file at ${ + lockFile.path}.)`); + }); + it('should extend the retry timeout if the other process locking the file changes', async () => { const fs = getFileSystem(); const log: string[] = []; @@ -109,6 +152,7 @@ runInEachFileSystem(() => { } return lockFileContents; }); + spyOn(process, 'kill').and.returnValue(); const promise = locker.lock(async () => log.push('fn()')); // The lock is now waiting on the lock-file becoming free, so no `fn()` in the log. @@ -118,6 +162,7 @@ runInEachFileSystem(() => { `(If you are sure no ngcc process is running then you should delete the lock-file at ${ lockFile.path}.)` ]]); + expect(process.kill).toHaveBeenCalledWith(188, 0); lockFileContents = '444'; // The lock-file has been taken over by another process - wait for the next attempt @@ -131,6 +176,7 @@ runInEachFileSystem(() => { `(If you are sure no ngcc process is running then you should delete the lock-file at ${ lockFile.path}.)`] ]); + expect(process.kill).toHaveBeenCalledWith(444, 0); lockFileContents = null; // The lock-file has been removed, so we can create our own lock-file, call `fn()` and @@ -163,11 +209,13 @@ runInEachFileSystem(() => { } return lockFileContents; }); + spyOn(process, 'kill').and.returnValue(); const promise = locker.lock(async () => log.push('fn()')); // The lock is now waiting on the lock-file becoming free, so no `fn()` in the log. expect(log).toEqual(['write()', 'read() => 188']); + expect(process.kill).toHaveBeenCalledWith(188, 0); // Do not remove the lock-file and let the call to `lock()` timeout. let error: Error; await promise.catch(e => error = e);