Skip to content

Commit

Permalink
Include cache save/restore times in Job Summary (#389)
Browse files Browse the repository at this point in the history
Fixes #370
  • Loading branch information
bigdaz authored Sep 13, 2024
1 parent d156388 commit e5c1381
Show file tree
Hide file tree
Showing 5 changed files with 48 additions and 16 deletions.
28 changes: 25 additions & 3 deletions sources/src/caching/cache-reporting.ts
Original file line number Diff line number Diff line change
Expand Up @@ -110,10 +110,12 @@ export class CacheEntryListener {
requestedRestoreKeys: string[] | undefined
restoredKey: string | undefined
restoredSize: number | undefined
restoredTime: number | undefined
notRestored: string | undefined

savedKey: string | undefined
savedSize: number | undefined
savedTime: number | undefined
notSaved: string | undefined

constructor(entryName: string) {
Expand All @@ -130,9 +132,10 @@ export class CacheEntryListener {
return this
}

markRestored(key: string, size: number | undefined): CacheEntryListener {
markRestored(key: string, size: number | undefined, time: number): CacheEntryListener {
this.restoredKey = key
this.restoredSize = size
this.restoredTime = time
return this
}

Expand All @@ -141,9 +144,10 @@ export class CacheEntryListener {
return this
}

markSaved(key: string, size: number | undefined): CacheEntryListener {
markSaved(key: string, size: number | undefined, time: number): CacheEntryListener {
this.savedKey = key
this.savedSize = size
this.savedTime = time
return this
}

Expand Down Expand Up @@ -182,14 +186,16 @@ ${renderEntryTable(entries)}
function renderEntryTable(entries: CacheEntryListener[]): string {
return `
<table>
<tr><td></td><th>Count</th><th>Total Size (Mb)</th></tr>
<tr><td></td><th>Count</th><th>Total Size (Mb)</th><th>Total Time (ms)</tr>
<tr><td>Entries Restored</td>
<td>${getCount(entries, e => e.restoredSize)}</td>
<td>${getSize(entries, e => e.restoredSize)}</td>
<td>${getTime(entries, e => e.restoredTime)}</td>
</tr>
<tr><td>Entries Saved</td>
<td>${getCount(entries, e => e.savedSize)}</td>
<td>${getSize(entries, e => e.savedSize)}</td>
<td>${getTime(entries, e => e.savedTime)}</td>
</tr>
</table>
`
Expand All @@ -202,9 +208,11 @@ function renderEntryDetails(listener: CacheListener): string {
Requested Key : ${entry.requestedKey ?? ''}
Restored Key : ${entry.restoredKey ?? ''}
Size: ${formatSize(entry.restoredSize)}
Time: ${formatTime(entry.restoredTime)}
${getRestoredMessage(entry, listener.cacheWriteOnly)}
Saved Key : ${entry.savedKey ?? ''}
Size: ${formatSize(entry.savedSize)}
Time: ${formatTime(entry.savedTime)}
${getSavedMessage(entry, listener.cacheReadOnly)}
`
)
Expand Down Expand Up @@ -264,9 +272,23 @@ function getSize(
return Math.round(bytes / (1024 * 1024))
}

function getTime(
cacheEntries: CacheEntryListener[],
predicate: (value: CacheEntryListener) => number | undefined
): number {
return cacheEntries.map(e => predicate(e) ?? 0).reduce((p, v) => p + v, 0)
}

function formatSize(bytes: number | undefined): string {
if (bytes === undefined || bytes === 0) {
return ''
}
return `${Math.round(bytes / (1024 * 1024))} MB (${bytes} B)`
}

function formatTime(ms: number | undefined): string {
if (ms === undefined || ms === 0) {
return ''
}
return `${ms} ms`
}
6 changes: 4 additions & 2 deletions sources/src/caching/cache-utils.ts
Original file line number Diff line number Diff line change
Expand Up @@ -38,13 +38,14 @@ export async function restoreCache(
): Promise<cache.CacheEntry | undefined> {
listener.markRequested(cacheKey, cacheRestoreKeys)
try {
const startTime = Date.now()
// Only override the read timeout if the SEGMENT_DOWNLOAD_TIMEOUT_MINS env var has NOT been set
const cacheRestoreOptions = process.env[SEGMENT_DOWNLOAD_TIMEOUT_VAR]
? {}
: {segmentTimeoutInMs: SEGMENT_DOWNLOAD_TIMEOUT_DEFAULT}
const restoredEntry = await cache.restoreCache(cachePath, cacheKey, cacheRestoreKeys, cacheRestoreOptions)
if (restoredEntry !== undefined) {
listener.markRestored(restoredEntry.key, restoredEntry.size)
listener.markRestored(restoredEntry.key, restoredEntry.size, Date.now() - startTime)
}
return restoredEntry
} catch (error) {
Expand All @@ -56,8 +57,9 @@ export async function restoreCache(

export async function saveCache(cachePath: string[], cacheKey: string, listener: CacheEntryListener): Promise<void> {
try {
const startTime = Date.now()
const savedEntry = await cache.saveCache(cachePath, cacheKey)
listener.markSaved(savedEntry.key, savedEntry.size)
listener.markSaved(savedEntry.key, savedEntry.size, Date.now() - startTime)
} catch (error) {
if (error instanceof cache.ReserveCacheError) {
listener.markAlreadyExists(cacheKey)
Expand Down
4 changes: 2 additions & 2 deletions sources/src/caching/gradle-home-extry-extractor.ts
Original file line number Diff line number Diff line change
Expand Up @@ -134,7 +134,7 @@ abstract class AbstractEntryExtractor {
): Promise<ExtractedCacheEntry> {
const restoredEntry = await restoreCache([pattern], cacheKey, [], listener)
if (restoredEntry) {
core.info(`Restored ${artifactType} with key ${cacheKey} to ${pattern}`)
core.info(`Restored ${artifactType} with key ${cacheKey} to ${pattern} in ${listener.restoredTime}ms`)
return new ExtractedCacheEntry(artifactType, pattern, cacheKey)
} else {
core.info(`Did not restore ${artifactType} with key ${cacheKey} to ${pattern}`)
Expand Down Expand Up @@ -232,8 +232,8 @@ abstract class AbstractEntryExtractor {
cacheDebug(`No change to previously restored ${artifactType}. Not saving.`)
entryListener.markNotSaved('contents unchanged')
} else {
core.info(`Caching ${artifactType} with path '${pattern}' and cache key: ${cacheKey}`)
await saveCache([pattern], cacheKey, entryListener)
core.info(`Saved ${artifactType} with key ${cacheKey} from ${pattern} in ${entryListener.savedTime}ms`)
}

for (const file of matchingFiles) {
Expand Down
11 changes: 8 additions & 3 deletions sources/src/caching/gradle-user-home-cache.ts
Original file line number Diff line number Diff line change
Expand Up @@ -60,15 +60,18 @@ export class GradleUserHomeCache {
restoreKeys:[${cacheKey.restoreKeys}]`
)

const cacheResult = await restoreCache(this.getCachePath(), cacheKey.key, cacheKey.restoreKeys, entryListener)
const cachePath = this.getCachePath()
const cacheResult = await restoreCache(cachePath, cacheKey.key, cacheKey.restoreKeys, entryListener)
if (!cacheResult) {
core.info(`${this.cacheDescription} cache not found. Will initialize empty.`)
return
}

core.saveState(RESTORED_CACHE_KEY_KEY, cacheResult.key)

core.info(`Restored ${this.cacheDescription} from cache key: ${cacheResult.key}`)
core.info(
`Restored ${this.cacheDescription} with key ${cacheResult.key} to ${cachePath.join()} in ${entryListener.restoredTime}ms`
)

try {
await this.afterRestore(listener)
Expand Down Expand Up @@ -120,9 +123,11 @@ export class GradleUserHomeCache {
return
}

core.info(`Caching ${this.cacheDescription} with cache key: ${cacheKey}`)
const cachePath = this.getCachePath()
await saveCache(cachePath, cacheKey, gradleHomeEntryListener)
core.info(
`Saved ${this.cacheDescription} with key ${cacheKey} from ${cachePath.join()} in ${gradleHomeEntryListener.savedTime}ms`
)

return
}
Expand Down
15 changes: 9 additions & 6 deletions sources/test/jest/cache-reporting.test.ts
Original file line number Diff line number Diff line change
@@ -1,11 +1,12 @@
import exp from 'constants'
import {CacheEntryListener, CacheListener} from '../../src/caching/cache-reporting'

describe('caching report', () => {
describe('reports not fully restored', () => {
it('with one requested entry report', async () => {
const report = new CacheListener()
report.entry('foo').markRequested('1', ['2'])
report.entry('bar').markRequested('3').markRestored('4', 500)
report.entry('bar').markRequested('3').markRestored('4', 500, 1000)
expect(report.fullyRestored).toBe(false)
})
})
Expand All @@ -22,13 +23,13 @@ describe('caching report', () => {
})
it('with restored entry report', async () => {
const report = new CacheListener()
report.entry('bar').markRequested('3').markRestored('4', 300)
report.entry('bar').markRequested('3').markRestored('4', 300, 1000)
expect(report.fullyRestored).toBe(true)
})
it('with multiple restored entry reportss', async () => {
const report = new CacheListener()
report.entry('foo').markRestored('4', 3300)
report.entry('bar').markRequested('3').markRestored('4', 333)
report.entry('foo').markRestored('4', 3300, 111)
report.entry('bar').markRequested('3').markRestored('4', 333, 1000)
expect(report.fullyRestored).toBe(true)
})
})
Expand Down Expand Up @@ -64,7 +65,7 @@ describe('caching report', () => {
const report = new CacheListener()
const entryReport = report.entry('foo')
entryReport.markRequested('1', ['2', '3'])
entryReport.markSaved('4', 100)
entryReport.markSaved('4', 100, 1000)

const stringRep = report.stringify()
const reportClone: CacheListener = CacheListener.rehydrate(stringRep)
Expand All @@ -73,6 +74,8 @@ describe('caching report', () => {
expect(entryClone.requestedKey).toBe('1')
expect(entryClone.requestedRestoreKeys).toEqual(['2', '3'])
expect(entryClone.savedKey).toBe('4')
expect(entryClone.savedSize).toBe(100)
expect(entryClone.savedTime).toBe(1000)
})
it('with live entry report', async () => {
const report = new CacheListener()
Expand All @@ -85,7 +88,7 @@ describe('caching report', () => {

// Check type and call method on rehydrated entry report
expect(entryClone).toBeInstanceOf(CacheEntryListener)
entryClone.markSaved('4', 100)
entryClone.markSaved('4', 100, 1000)

expect(entryClone.requestedKey).toBe('1')
expect(entryClone.requestedRestoreKeys).toEqual(['2', '3'])
Expand Down

0 comments on commit e5c1381

Please sign in to comment.