-
Notifications
You must be signed in to change notification settings - Fork 65
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
feat(PE-6695/PE-6696): remove resolver, add redis support for arns cache #200
Changes from 5 commits
037417e
3b09c9e
ecb7574
379e027
0041495
f1bd0cf
d114821
410cb5f
b8afa1c
b9e4fe6
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -16,34 +16,70 @@ | |
* along with this program. If not, see <http://www.gnu.org/licenses/>. | ||
*/ | ||
import winston from 'winston'; | ||
import { NameResolution, NameResolver } from '../types.js'; | ||
import { KVBufferStore, NameResolution, NameResolver } from '../types.js'; | ||
import * as metrics from '../metrics.js'; | ||
import { KvArnsStore } from '../store/kv-arns-store.js'; | ||
|
||
export class CompositeArNSResolver implements NameResolver { | ||
private log: winston.Logger; | ||
private resolvers: NameResolver[]; | ||
private cache: KVBufferStore; | ||
|
||
constructor({ | ||
log, | ||
resolvers, | ||
cache, | ||
}: { | ||
log: winston.Logger; | ||
resolvers: NameResolver[]; | ||
cache: KvArnsStore; | ||
}) { | ||
this.log = log.child({ class: 'CompositeArNSResolver' }); | ||
this.log = log.child({ class: this.constructor.name }); | ||
this.resolvers = resolvers; | ||
this.cache = cache; | ||
} | ||
|
||
async resolve(name: string): Promise<NameResolution> { | ||
this.log.info('Resolving name...', { name }); | ||
|
||
try { | ||
const cachedResolutionBuffer = await this.cache.get(name); | ||
if (cachedResolutionBuffer) { | ||
const cachedResolution: NameResolution = JSON.parse( | ||
cachedResolutionBuffer.toString(), | ||
); | ||
if ( | ||
cachedResolution !== undefined && | ||
cachedResolution.resolvedAt !== undefined && | ||
cachedResolution.ttl !== undefined && | ||
cachedResolution.resolvedAt + cachedResolution.ttl * 1000 > Date.now() | ||
) { | ||
metrics.arnsCacheHitCounter.inc(); | ||
this.log.info('Cache hit for arns name', { name }); | ||
return cachedResolution; | ||
} | ||
} | ||
metrics.arnsCacheMissCounter.inc(); | ||
this.log.info('Cache miss for arns name', { name }); | ||
|
||
for (const resolver of this.resolvers) { | ||
this.log.debug('Attempting to resolve name with resolver', { | ||
resolver, | ||
}); | ||
const resolution = await resolver.resolve(name); | ||
if (resolution.resolvedId !== undefined) { | ||
return resolution; | ||
try { | ||
this.log.info('Attempting to resolve name with resolver', { | ||
type: resolver.constructor.name, | ||
name, | ||
}); | ||
const resolution = await resolver.resolve(name); | ||
if (resolution.resolvedId !== undefined) { | ||
await this.cache.set(name, Buffer.from(JSON.stringify(resolution))); | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I was thinking about the need to What do you think? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. good call out, removed in f1bd0cf - when thinking about the implications of this, i also realized we aren't handling concurrent requests well. I'd like to propose adding a request cache in the arns middleware that protects against concurrent calls to // check if this instance is already in the process of resolving the requested name, and return that promise if so, otherwise set it in the cache
const getArnsResolutionPromise = async (): Promise<NameResolution> => {
if (arnsRequestCache.has(arnsSubdomain)) {
const arnsResolutionPromise =
arnsRequestCache.get<Promise<NameResolution>>(arnsSubdomain);
if (arnsResolutionPromise) {
return arnsResolutionPromise;
}
}
const arnsResolutionPromise = nameResolver.resolve(arnsSubdomain);
arnsRequestCache.set(arnsSubdomain, arnsResolutionPromise);
return arnsResolutionPromise;
};
const start = Date.now();
const { resolvedId, ttl, processId } =
await getArnsResolutionPromise().finally(() => {
// remove from cache after resolution
arnsRequestCache.del(arnsSubdomain);
});
metrics.arnsResolutionTime.observe(Date.now() - start);
if (resolvedId === undefined) {
sendNotFound(res);
return;
}
res.header(headerNames.arnsResolvedId, resolvedId);
res.header(headerNames.arnsTtlSeconds, ttl.toString());
res.header(headerNames.arnsProcessId, processId);
// TODO: add a header for arns cache status
res.header('Cache-Control', `public, max-age=${ttl}`);
dataHandler(req, res, next); After adding this change, I did some tests using Test: 100 concurrent requests for an arns nameBefore:Each arns request created independent promises to AO, resulting in a wide range of resolution times and some experiencing rate limiting/throttling having to fallback to TrustedArNSGateway resolvers. ❯ hey -n 100 -c 100 -t 60 -host 'gateways.example.com' http://localhost:4000
Summary:
Total: 65.3634 secs
Slowest: 65.3604 secs
Fastest: 17.1049 secs
Average: 31.1251 secs
Requests/sec: 1.5299
Total data: 172414200 bytes
Size/request: 1724142 bytes
Response time histogram:
17.105 [1] |■
21.930 [71] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
26.756 [3] |■■
31.582 [0] |
36.407 [0] |
41.233 [0] |
46.058 [0] |
50.884 [0] |
55.709 [0] |
60.535 [6] |■■■
65.360 [19] |■■■■■■■■■■■
Latency distribution:
10% in 19.6950 secs
25% in 20.5840 secs
50% in 21.3610 secs
75% in 59.9175 secs
90% in 63.3682 secs
95% in 64.5496 secs
99% in 65.3604 secs
Details (average, fastest, slowest):
DNS+dialup: 0.0074 secs, 17.1049 secs, 65.3604 secs
DNS-lookup: 0.0026 secs, 0.0016 secs, 0.0042 secs
req write: 0.0002 secs, 0.0000 secs, 0.0020 secs
resp wait: 27.6524 secs, 15.5326 secs, 65.3426 secs
resp read: 3.4650 secs, 0.0111 secs, 6.5513 secs
Status code distribution:
[200] 100 responses Logs - these are printed 100 times (one for each request) and several experience rate limits from AO infrastructure, forcing the core-1 | info: Attempting to resolve name with resolver {"class":"CompositeArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.052Z","type":"TrustedGatewayArNSResolver"}
core-1 | info: Resolving name... {"class":"TrustedGatewayArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.052Z"}
core-1 | warn: Unable to resolve name: fetch failed {"class":"OnDemandArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.054Z"}
core-1 | info: Attempting to resolve name with resolver {"class":"CompositeArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.054Z","type":"TrustedGatewayArNSResolver"}
core-1 | info: Resolving name... {"class":"TrustedGatewayArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.055Z"}
core-1 | warn: Unable to resolve name: fetch failed {"class":"OnDemandArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.056Z"}
core-1 | info: Attempting to resolve name with resolver {"class":"CompositeArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.056Z","type":"TrustedGatewayArNSResolver"}
core-1 | info: Resolving name... {"class":"TrustedGatewayArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.057Z"}
core-1 | warn: Unable to resolve name: fetch failed {"class":"OnDemandArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.060Z"}
core-1 | info: Attempting to resolve name with resolver {"class":"CompositeArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.060Z","type":"TrustedGatewayArNSResolver"}
core-1 | info: Resolving name... {"class":"TrustedGatewayArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.060Z"}
core-1 | warn: Unable to resolve name: fetch failed {"class":"OnDemandArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.064Z"}
core-1 | info: Attempting to resolve name with resolver {"class":"CompositeArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.065Z","type":"TrustedGatewayArNSResolver"}
core-1 | info: Resolving name... {"class":"TrustedGatewayArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.065Z"}
core-1 | warn: Unable to resolve name: fetch failed {"class":"OnDemandArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.069Z"}
core-1 | info: Attempting to resolve name with resolver {"class":"CompositeArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.069Z","type":"TrustedGatewayArNSResolver"}
core-1 | info: Resolving name... {"class":"TrustedGatewayArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.069Z"}
core-1 | warn: Unable to resolve name: fetch failed {"class":"OnDemandArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.074Z"}
core-1 | info: Attempting to resolve name with resolver {"class":"CompositeArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.074Z","type":"TrustedGatewayArNSResolver"}
core-1 | info: Resolving name... {"class":"TrustedGatewayArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.074Z"}
core-1 | warn: Unable to resolve name: fetch failed {"class":"OnDemandArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.078Z"}
core-1 | info: Attempting to resolve name with resolver {"class":"CompositeArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.078Z","type":"TrustedGatewayArNSResolver"}
core-1 | info: Resolving name... {"class":"TrustedGatewayArNSResolver","name":"joose","timestamp":"2024-09-10T14:19:59.078Z"} AfterAll 100 requests were satisfied with the single request to AO, and resolution times were approx. the same ❯ hey -n 100 -c 100 -t 60 -host 'gateways.example.com' http://localhost:4000
Summary:
Total: 44.0368 secs
Slowest: 44.0354 secs
Fastest: 43.6696 secs
Average: 43.8166 secs
Requests/sec: 2.2708
Total data: 172414200 bytes
Size/request: 1724142 bytes
Response time histogram:
43.670 [1] |■
43.706 [0] |
43.743 [8] |■■■■■■■■■■
43.779 [22] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■
43.816 [31] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
43.853 [10] |■■■■■■■■■■■■■
43.889 [17] |■■■■■■■■■■■■■■■■■■■■■■
43.926 [3] |■■■■
43.962 [4] |■■■■■
43.999 [3] |■■■■
44.035 [1] |■
Latency distribution:
10% in 43.7457 secs
25% in 43.7732 secs
50% in 43.8027 secs
75% in 43.8615 secs
90% in 43.9001 secs
95% in 43.9574 secs
99% in 44.0354 secs
Details (average, fastest, slowest):
DNS+dialup: 0.0091 secs, 43.6696 secs, 44.0354 secs
DNS-lookup: 0.0021 secs, 0.0015 secs, 0.0029 secs
req write: 0.0002 secs, 0.0000 secs, 0.0016 secs
resp wait: 42.9208 secs, 42.9030 secs, 42.9412 secs
resp read: 0.8865 secs, 0.7390 secs, 1.0992 secs
Status code distribution:
[200] 100 responses Logs - only printed once for all 100 requests, no falling back to gateway resolver necessary core-1 | info: Cache miss for arns name {"class":"CompositeArNSResolver","name":"gateways","timestamp":"2024-09-10T13:34:09.999Z"}
core-1 | info: Attempting to resolve name with resolver {"class":"CompositeArNSResolver","name":"gateways","timestamp":"2024-09-10T13:34:09.999Z","type":"OnDemandArNSResolver"}
core-1 | info: Resolving name... {"class":"OnDemandArNSResolver","name":"gateways","timestamp":"2024-09-10T13:34:10.000Z"} This should also help slamming AO on fresh or expired names and likely a pattern would could extend to other request paths. cc @djwhitt |
||
this.log.info('Resolved name', { name, resolution }); | ||
return resolution; | ||
} | ||
} catch (error: any) { | ||
this.log.error('Error resolving name with resolver', { | ||
resolver, | ||
message: error.message, | ||
stack: error.stack, | ||
}); | ||
} | ||
} | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Should we fall back to the cached resolution here, perhaps with some staleness threshold, if we have one? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. sure, can add that, we can use the TTL of the cache as the staleness threshold. that would mean if the cache has it, and we can't fetch anything new - return what the cache has until it expires. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. modified to return the cached resolution data on error - if we have it - here - b9e4fe6 |
||
this.log.warn('Unable to resolve name against all resolvers', { name }); | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
👋