diff --git a/packages/cache/RELEASES.md b/packages/cache/RELEASES.md index bc18cea2..f61e7a41 100644 --- a/packages/cache/RELEASES.md +++ b/packages/cache/RELEASES.md @@ -12,5 +12,6 @@ ### 1.0.0 - Downloads Azure-hosted caches using the Azure SDK for speed and reliability +- Displays download progress - Includes changes that break compatibility with earlier versions, including: - `retry`, `retryTypedResponse`, and `retryHttpClientResponse` moved from `cacheHttpClient` to `requestUtils` \ No newline at end of file diff --git a/packages/cache/__tests__/downloadUtils.test.ts b/packages/cache/__tests__/downloadUtils.test.ts new file mode 100644 index 00000000..c5179d33 --- /dev/null +++ b/packages/cache/__tests__/downloadUtils.test.ts @@ -0,0 +1,159 @@ +import * as core from '@actions/core' +import {DownloadProgress} from '../src/internal/downloadUtils' + +test('download progress tracked correctly', () => { + const progress = new DownloadProgress(1000) + + expect(progress.contentLength).toBe(1000) + expect(progress.receivedBytes).toBe(0) + expect(progress.segmentIndex).toBe(0) + expect(progress.segmentOffset).toBe(0) + expect(progress.segmentSize).toBe(0) + expect(progress.displayedComplete).toBe(false) + expect(progress.timeoutHandle).toBeUndefined() + expect(progress.getTransferredBytes()).toBe(0) + expect(progress.isDone()).toBe(false) + + progress.nextSegment(500) + + expect(progress.contentLength).toBe(1000) + expect(progress.receivedBytes).toBe(0) + expect(progress.segmentIndex).toBe(1) + expect(progress.segmentOffset).toBe(0) + expect(progress.segmentSize).toBe(500) + expect(progress.displayedComplete).toBe(false) + expect(progress.timeoutHandle).toBeUndefined() + expect(progress.getTransferredBytes()).toBe(0) + expect(progress.isDone()).toBe(false) + + progress.setReceivedBytes(250) + + expect(progress.contentLength).toBe(1000) + expect(progress.receivedBytes).toBe(250) + expect(progress.segmentIndex).toBe(1) + expect(progress.segmentOffset).toBe(0) + expect(progress.segmentSize).toBe(500) + expect(progress.displayedComplete).toBe(false) + expect(progress.timeoutHandle).toBeUndefined() + expect(progress.getTransferredBytes()).toBe(250) + expect(progress.isDone()).toBe(false) + + progress.setReceivedBytes(500) + + expect(progress.contentLength).toBe(1000) + expect(progress.receivedBytes).toBe(500) + expect(progress.segmentIndex).toBe(1) + expect(progress.segmentOffset).toBe(0) + expect(progress.segmentSize).toBe(500) + expect(progress.displayedComplete).toBe(false) + expect(progress.timeoutHandle).toBeUndefined() + expect(progress.getTransferredBytes()).toBe(500) + expect(progress.isDone()).toBe(false) + + progress.nextSegment(500) + + expect(progress.contentLength).toBe(1000) + expect(progress.receivedBytes).toBe(0) + expect(progress.segmentIndex).toBe(2) + expect(progress.segmentOffset).toBe(500) + expect(progress.segmentSize).toBe(500) + expect(progress.displayedComplete).toBe(false) + expect(progress.timeoutHandle).toBeUndefined() + expect(progress.getTransferredBytes()).toBe(500) + expect(progress.isDone()).toBe(false) + + progress.setReceivedBytes(250) + + expect(progress.contentLength).toBe(1000) + expect(progress.receivedBytes).toBe(250) + expect(progress.segmentIndex).toBe(2) + expect(progress.segmentOffset).toBe(500) + expect(progress.segmentSize).toBe(500) + expect(progress.displayedComplete).toBe(false) + expect(progress.timeoutHandle).toBeUndefined() + expect(progress.getTransferredBytes()).toBe(750) + expect(progress.isDone()).toBe(false) + + progress.setReceivedBytes(500) + + expect(progress.contentLength).toBe(1000) + expect(progress.receivedBytes).toBe(500) + expect(progress.segmentIndex).toBe(2) + expect(progress.segmentOffset).toBe(500) + expect(progress.segmentSize).toBe(500) + expect(progress.displayedComplete).toBe(false) + expect(progress.timeoutHandle).toBeUndefined() + expect(progress.getTransferredBytes()).toBe(1000) + expect(progress.isDone()).toBe(true) +}) + +test('display timer works correctly', () => { + const progress = new DownloadProgress(1000) + + const infoMock = jest.spyOn(core, 'info') + infoMock.mockImplementation(() => {}) + + const check = (): void => { + expect(infoMock).toHaveBeenLastCalledWith( + expect.stringContaining('Received 500 of 1000') + ) + } + + // Validate no further updates are displayed after stopping the timer. + const test2 = (): void => { + check() + expect(progress.timeoutHandle).toBeUndefined() + } + + // Validate the progress is displayed, stop the timer, and call test2. + const test1 = (): void => { + check() + + progress.stopDisplayTimer() + progress.setReceivedBytes(1000) + + setTimeout(() => test2(), 100) + } + + // Start the timer, update the received bytes, and call test1. + const start = (): void => { + progress.startDisplayTimer(10) + expect(progress.timeoutHandle).toBeDefined() + + progress.setReceivedBytes(500) + + setTimeout(() => test1(), 100) + } + + start() +}) + +test('display does not print completed line twice', () => { + const progress = new DownloadProgress(1000) + + const infoMock = jest.spyOn(core, 'info') + infoMock.mockImplementation(() => {}) + + progress.display() + + expect(progress.displayedComplete).toBe(false) + expect(infoMock).toHaveBeenCalledTimes(1) + + progress.nextSegment(1000) + progress.setReceivedBytes(500) + progress.display() + + expect(progress.displayedComplete).toBe(false) + expect(infoMock).toHaveBeenCalledTimes(2) + + progress.setReceivedBytes(1000) + progress.display() + + expect(progress.displayedComplete).toBe(true) + expect(infoMock).toHaveBeenCalledTimes(3) + + progress.display() + + expect(progress.displayedComplete).toBe(true) + expect(infoMock).toHaveBeenCalledTimes(3) +}) diff --git a/packages/cache/package-lock.json b/packages/cache/package-lock.json index 774a5e5a..234b64cb 100644 --- a/packages/cache/package-lock.json +++ b/packages/cache/package-lock.json @@ -1,6 +1,6 @@ { "name": "@actions/cache", - "version": "0.3.0", + "version": "1.0.0", "lockfileVersion": 1, "requires": true, "dependencies": { @@ -129,6 +129,45 @@ "tslib": "^1.9.3" } }, + "@azure/ms-rest-js": { + "version": "2.0.7", + "resolved": "https://registry.npmjs.org/@azure/ms-rest-js/-/ms-rest-js-2.0.7.tgz", + "integrity": "sha512-rQpNxDhyOIyS4E+4sUCBMvjrtbNwB32wH06cC2SFoQM4TR29bIKaTlIC1tMe0K07w9c5tNk/2uUHs6/ld/Z3+A==", + "requires": { + "@types/node-fetch": "^2.3.7", + "@types/tunnel": "0.0.1", + "abort-controller": "^3.0.0", + "form-data": "^2.5.0", + "node-fetch": "^2.6.0", + "tough-cookie": "^3.0.1", + "tslib": "^1.10.0", + "tunnel": "0.0.6", + "uuid": "^3.3.2", + "xml2js": "^0.4.19" + }, + "dependencies": { + "form-data": { + "version": "2.5.1", + "resolved": "https://registry.npmjs.org/form-data/-/form-data-2.5.1.tgz", + "integrity": "sha512-m21N3WOmEEURgk6B9GLOE4RuWOFf28Lhh9qGYeNlGq4VDXUlJy2th2slBNU8Gp8EzloYZOibZJ7t5ecIrFSjVA==", + "requires": { + "asynckit": "^0.4.0", + "combined-stream": "^1.0.6", + "mime-types": "^2.1.12" + } + }, + "tough-cookie": { + "version": "3.0.1", + "resolved": "https://registry.npmjs.org/tough-cookie/-/tough-cookie-3.0.1.tgz", + "integrity": "sha512-yQyJ0u4pZsv9D4clxO69OEjLWYw+jbgspjTue4lTQZLfV0c5l1VmK2y1JK8E9ahdpltPOaAThPcp5nKPUgSnsg==", + "requires": { + "ip-regex": "^2.1.0", + "psl": "^1.1.28", + "punycode": "^2.1.1" + } + } + } + }, "@azure/storage-blob": { "version": "12.1.2", "resolved": "https://registry.npmjs.org/@azure/storage-blob/-/storage-blob-12.1.2.tgz", @@ -177,6 +216,28 @@ "form-data": "^3.0.0" } }, + "@types/prop-types": { + "version": "15.7.3", + "resolved": "https://registry.npmjs.org/@types/prop-types/-/prop-types-15.7.3.tgz", + "integrity": "sha512-KfRL3PuHmqQLOG+2tGpRO26Ctg+Cq1E01D2DMriKEATHgWLfeNDmq9e29Q9WIky0dQ3NPkd1mzYH8Lm936Z9qw==" + }, + "@types/react": { + "version": "16.9.38", + "resolved": "https://registry.npmjs.org/@types/react/-/react-16.9.38.tgz", + "integrity": "sha512-pHAeZbjjNRa/hxyNuLrvbxhhnKyKNiLC6I5fRF2Zr/t/S6zS41MiyzH4+c+1I9vVfvuRt1VS2Lodjr4ZWnxrdA==", + "requires": { + "@types/prop-types": "*", + "csstype": "^2.2.0" + } + }, + "@types/react-native": { + "version": "0.62.13", + "resolved": "https://registry.npmjs.org/@types/react-native/-/react-native-0.62.13.tgz", + "integrity": "sha512-hs4/tSABhcJx+J8pZhVoXHrOQD89WFmbs8QiDLNSA9zNrD46pityAuBWuwk1aMjPk9I3vC5ewkJroVRHgRIfdg==", + "requires": { + "@types/react": "*" + } + }, "@types/semver": { "version": "6.2.1", "resolved": "https://registry.npmjs.org/@types/semver/-/semver-6.2.1.tgz", @@ -197,6 +258,14 @@ "integrity": "sha512-XDwyIlt/47l2kWLTzw/mtrpLdB+GPSskR2n/PIcPn+VYhVO77rGhRncIR5GPU0KRzXuqkDO+J5qqrG0Y8P6jzQ==", "dev": true }, + "abort-controller": { + "version": "3.0.0", + "resolved": "https://registry.npmjs.org/abort-controller/-/abort-controller-3.0.0.tgz", + "integrity": "sha512-h8lQ8tacZYnR3vNQTgibj+tODHI5/+l06Au2Pcriv/Gmet0eaj4TwWH41sO9wnHDiQsEj19q0drzdWdeAHtweg==", + "requires": { + "event-target-shim": "^5.0.0" + } + }, "asynckit": { "version": "0.4.0", "resolved": "https://registry.npmjs.org/asynckit/-/asynckit-0.4.0.tgz", @@ -229,11 +298,21 @@ "resolved": "https://registry.npmjs.org/concat-map/-/concat-map-0.0.1.tgz", "integrity": "sha1-2Klr13/Wjfd5OnMDajug1UBdR3s=" }, + "csstype": { + "version": "2.6.10", + "resolved": "https://registry.npmjs.org/csstype/-/csstype-2.6.10.tgz", + "integrity": "sha512-D34BqZU4cIlMCY93rZHbrq9pjTAQJ3U8S8rfBqjwHxkGPThWFjzZDQpgMJY0QViLxth6ZKYiwFBo14RdN44U/w==" + }, "delayed-stream": { "version": "1.0.0", "resolved": "https://registry.npmjs.org/delayed-stream/-/delayed-stream-1.0.0.tgz", "integrity": "sha1-3zrhmayt+31ECqrgsp4icrJOxhk=" }, + "event-target-shim": { + "version": "5.0.1", + "resolved": "https://registry.npmjs.org/event-target-shim/-/event-target-shim-5.0.1.tgz", + "integrity": "sha512-i/2XbnSz/uxRCU6+NdVJgKWDTM427+MqYbkQzD321DuCQJUqOuJKIA0IM2+W2xtYHdKOmZ4dR6fExsd4SXL+WQ==" + }, "events": { "version": "3.1.0", "resolved": "https://registry.npmjs.org/events/-/events-3.1.0.tgz", @@ -249,6 +328,11 @@ "mime-types": "^2.1.12" } }, + "ip-regex": { + "version": "2.1.0", + "resolved": "https://registry.npmjs.org/ip-regex/-/ip-regex-2.1.0.tgz", + "integrity": "sha1-+ni/XS5pE8kRzp+BnuUUa7bYROk=" + }, "mime-db": { "version": "1.44.0", "resolved": "https://registry.npmjs.org/mime-db/-/mime-db-1.44.0.tgz", diff --git a/packages/cache/package.json b/packages/cache/package.json index 3299349b..4768d8e9 100644 --- a/packages/cache/package.json +++ b/packages/cache/package.json @@ -42,6 +42,7 @@ "@actions/glob": "^0.1.0", "@actions/http-client": "^1.0.8", "@actions/io": "^1.0.1", + "@azure/ms-rest-js": "^2.0.7", "@azure/storage-blob": "^12.1.2", "semver": "^6.1.0", "uuid": "^3.3.3" diff --git a/packages/cache/src/internal/downloadUtils.ts b/packages/cache/src/internal/downloadUtils.ts index 839b1fa3..6286322f 100644 --- a/packages/cache/src/internal/downloadUtils.ts +++ b/packages/cache/src/internal/downloadUtils.ts @@ -2,6 +2,7 @@ import * as core from '@actions/core' import {HttpClient} from '@actions/http-client' import {IHttpClientResponse} from '@actions/http-client/interfaces' import {BlockBlobClient} from '@azure/storage-blob' +import {TransferProgressEvent} from '@azure/ms-rest-js' import * as buffer from 'buffer' import * as fs from 'fs' import * as stream from 'stream' @@ -26,6 +27,139 @@ async function pipeResponseToStream( await pipeline(response.message, output) } +/** + * Class for tracking the download state and displaying stats. + */ +export class DownloadProgress { + contentLength: number + segmentIndex: number + segmentSize: number + segmentOffset: number + receivedBytes: number + startTime: number + displayedComplete: boolean + timeoutHandle?: ReturnType + + constructor(contentLength: number) { + this.contentLength = contentLength + this.segmentIndex = 0 + this.segmentSize = 0 + this.segmentOffset = 0 + this.receivedBytes = 0 + this.displayedComplete = false + this.startTime = Date.now() + } + + /** + * Progress to the next segment. Only call this method when the previous segment + * is complete. + * + * @param segmentSize the length of the next segment + */ + nextSegment(segmentSize: number): void { + this.segmentOffset = this.segmentOffset + this.segmentSize + this.segmentIndex = this.segmentIndex + 1 + this.segmentSize = segmentSize + this.receivedBytes = 0 + + core.debug( + `Downloading segment at offset ${this.segmentOffset} with length ${this.segmentSize}...` + ) + } + + /** + * Sets the number of bytes received for the current segment. + * + * @param receivedBytes the number of bytes received + */ + setReceivedBytes(receivedBytes: number): void { + this.receivedBytes = receivedBytes + } + + /** + * Returns the total number of bytes transferred. + */ + getTransferredBytes(): number { + return this.segmentOffset + this.receivedBytes + } + + /** + * Returns true if the download is complete. + */ + isDone(): boolean { + return this.getTransferredBytes() === this.contentLength + } + + /** + * Prints the current download stats. Once the download completes, this will print one + * last line and then stop. + */ + display(): void { + if (this.displayedComplete) { + return + } + + const transferredBytes = this.segmentOffset + this.receivedBytes + const percentage = (100 * (transferredBytes / this.contentLength)).toFixed( + 1 + ) + const elapsedTime = Date.now() - this.startTime + const downloadSpeed = ( + transferredBytes / + (1024 * 1024) / + (elapsedTime / 1000) + ).toFixed(1) + + core.info( + `Received ${transferredBytes} of ${this.contentLength} (${percentage}%), ${downloadSpeed} MBs/sec` + ) + + if (this.isDone()) { + this.displayedComplete = true + } + } + + /** + * Callback used to update the progress. + * + * @param progress the progress event + */ + onProgressCallback(progress: TransferProgressEvent): void { + this.setReceivedBytes(progress.loadedBytes) + } + + /** + * Starts the timer that displays the stats. + * + * @param delayInMs the delay between each write + */ + startDisplayTimer(delayInMs: number = 1000): void { + const displayCallback = (): void => { + this.display() + + if (!this.isDone()) { + this.timeoutHandle = setTimeout(displayCallback, delayInMs) + } + } + + this.timeoutHandle = setTimeout(displayCallback, delayInMs) + } + + /** + * Stops the timer that displays the stats. As this typically indicates the download + * is complete, this will display one last line, unless the last line has already + * been written. + */ + stopDisplayTimer(): void { + if (this.timeoutHandle) { + clearTimeout(this.timeoutHandle) + this.timeoutHandle = undefined + } + + this.display() + } +} + /** * Download the cache using the Actions toolkit http-client * @@ -107,27 +241,36 @@ export async function downloadCacheStorageSDK( // If the file exceeds the buffer maximum length (~1 GB on 32-bit systems and ~2 GB // on 64-bit systems), split the download into multiple segments const maxSegmentSize = buffer.constants.MAX_LENGTH - let offset = 0 + const downloadProgress = new DownloadProgress(contentLength) const fd = fs.openSync(archivePath, 'w') try { - while (offset < contentLength) { - const segmentSize = Math.min(maxSegmentSize, contentLength - offset) - core.debug( - `Downloading segment at offset ${offset} with length ${segmentSize}...` + downloadProgress.startDisplayTimer() + + while (!downloadProgress.isDone()) { + const segmentSize = Math.min( + maxSegmentSize, + contentLength - downloadProgress.segmentOffset ) - const result = await client.downloadToBuffer(offset, segmentSize, { - concurrency: options.downloadConcurrency - }) + downloadProgress.nextSegment(segmentSize) + + const result = await client.downloadToBuffer( + downloadProgress.segmentOffset, + segmentSize, + { + concurrency: options.downloadConcurrency, + onProgress: downloadProgress.onProgressCallback.bind( + downloadProgress + ) + } + ) fs.writeFileSync(fd, result) - - core.debug(`Finished segment at offset ${offset}`) - offset += segmentSize } } finally { + downloadProgress.stopDisplayTimer() fs.closeSync(fd) } } diff --git a/packages/cache/tsconfig.json b/packages/cache/tsconfig.json index a8b812a6..2cddd408 100644 --- a/packages/cache/tsconfig.json +++ b/packages/cache/tsconfig.json @@ -3,7 +3,8 @@ "compilerOptions": { "baseUrl": "./", "outDir": "./lib", - "rootDir": "./src" + "rootDir": "./src", + "lib": ["es6", "dom"] }, "include": [ "./src"