Better logging for hanging benchmarks

This commit is contained in:
Fedor Indutny 2023-03-13 16:41:47 -07:00 committed by GitHub
parent adf2957537
commit 51c2029b5c
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
9 changed files with 446 additions and 458 deletions

View file

@ -10,7 +10,6 @@ import {
ReceiptType,
} from '@signalapp/mock-server';
import type { App } from './fixtures';
import {
Bootstrap,
debug,
@ -23,13 +22,7 @@ import {
const CONVERSATION_SIZE = 500; // messages
const LAST_MESSAGE = 'start sending messages now';
void (async () => {
const bootstrap = new Bootstrap({
benchmark: true,
});
await bootstrap.init();
Bootstrap.benchmark(async (bootstrap: Bootstrap): Promise<void> => {
const { contacts, phone } = bootstrap;
const members = [...contacts].slice(0, GROUP_SIZE);
@ -45,145 +38,131 @@ void (async () => {
.pinGroup(group)
);
let app: App | undefined;
const app = await bootstrap.link();
try {
app = await bootstrap.link();
const { server, desktop } = bootstrap;
const [first] = members;
const { server, desktop } = bootstrap;
const [first] = members;
const messages = new Array<Buffer>();
debug('encrypting');
// Fill left pane
for (const contact of members.slice().reverse()) {
const messageTimestamp = bootstrap.getTimestamp();
const messages = new Array<Buffer>();
debug('encrypting');
// Fill left pane
for (const contact of members.slice().reverse()) {
const messageTimestamp = bootstrap.getTimestamp();
messages.push(
await contact.encryptText(
desktop,
`hello from: ${contact.profileName}`,
messages.push(
await contact.encryptText(desktop, `hello from: ${contact.profileName}`, {
timestamp: messageTimestamp,
sealed: true,
})
);
messages.push(
await phone.encryptSyncRead(desktop, {
timestamp: bootstrap.getTimestamp(),
messages: [
{
senderUUID: contact.device.uuid,
timestamp: messageTimestamp,
sealed: true,
}
)
);
messages.push(
await phone.encryptSyncRead(desktop, {
timestamp: bootstrap.getTimestamp(),
messages: [
{
senderUUID: contact.device.uuid,
timestamp: messageTimestamp,
},
],
})
);
}
},
],
})
);
}
// Fill group
for (let i = 0; i < CONVERSATION_SIZE; i += 1) {
const contact = members[i % members.length];
const messageTimestamp = bootstrap.getTimestamp();
// Fill group
for (let i = 0; i < CONVERSATION_SIZE; i += 1) {
const contact = members[i % members.length];
const messageTimestamp = bootstrap.getTimestamp();
const isLast = i === CONVERSATION_SIZE - 1;
const isLast = i === CONVERSATION_SIZE - 1;
messages.push(
await contact.encryptText(
desktop,
isLast ? LAST_MESSAGE : `#${i} from: ${contact.profileName}`,
messages.push(
await contact.encryptText(
desktop,
isLast ? LAST_MESSAGE : `#${i} from: ${contact.profileName}`,
{
timestamp: messageTimestamp,
sealed: true,
group,
}
)
);
messages.push(
await phone.encryptSyncRead(desktop, {
timestamp: bootstrap.getTimestamp(),
messages: [
{
senderUUID: contact.device.uuid,
timestamp: messageTimestamp,
sealed: true,
group,
}
)
);
messages.push(
await phone.encryptSyncRead(desktop, {
timestamp: bootstrap.getTimestamp(),
messages: [
{
senderUUID: contact.device.uuid,
timestamp: messageTimestamp,
},
],
})
);
}
debug('encrypted');
},
],
})
);
}
debug('encrypted');
await Promise.all(messages.map(message => server.send(desktop, message)));
await Promise.all(messages.map(message => server.send(desktop, message)));
const window = await app.getWindow();
const window = await app.getWindow();
debug('opening conversation');
{
const leftPane = window.locator('.left-pane-wrapper');
debug('opening conversation');
{
const leftPane = window.locator('.left-pane-wrapper');
const item = leftPane
.locator(
'.module-conversation-list__item--contact-or-conversation' +
`>> text=${LAST_MESSAGE}`
)
.first();
await item.click();
}
const item = leftPane
.locator(
'.module-conversation-list__item--contact-or-conversation' +
`>> text=${LAST_MESSAGE}`
)
.first();
await item.click();
}
const timeline = window.locator(
'.timeline-wrapper, .conversation .ConversationView'
const timeline = window.locator(
'.timeline-wrapper, .conversation .ConversationView'
);
const deltaList = new Array<number>();
for (let runId = 0; runId < RUN_COUNT + DISCARD_COUNT; runId += 1) {
debug('finding composition input and clicking it');
const composeArea = window.locator(
'.composition-area-wrapper, .conversation .ConversationView'
);
const deltaList = new Array<number>();
for (let runId = 0; runId < RUN_COUNT + DISCARD_COUNT; runId += 1) {
debug('finding composition input and clicking it');
const composeArea = window.locator(
'.composition-area-wrapper, .conversation .ConversationView'
);
const input = composeArea.locator('[data-testid=CompositionInput]');
const input = composeArea.locator('[data-testid=CompositionInput]');
debug('entering message text');
await input.type(`my message ${runId}`);
await input.press('Enter');
debug('entering message text');
await input.type(`my message ${runId}`);
await input.press('Enter');
debug('waiting for message on server side');
const { body, source, envelopeType } = await first.waitForMessage();
assert.strictEqual(body, `my message ${runId}`);
assert.strictEqual(source, desktop);
assert.strictEqual(envelopeType, EnvelopeType.SenderKey);
debug('waiting for message on server side');
const { body, source, envelopeType } = await first.waitForMessage();
assert.strictEqual(body, `my message ${runId}`);
assert.strictEqual(source, desktop);
assert.strictEqual(envelopeType, EnvelopeType.SenderKey);
debug('waiting for timing from the app');
const { timestamp, delta } = await app.waitForMessageSend();
debug('waiting for timing from the app');
const { timestamp, delta } = await app.waitForMessageSend();
debug('sending delivery receipts');
const delivery = await first.encryptReceipt(desktop, {
timestamp: timestamp + 1,
messageTimestamps: [timestamp],
type: ReceiptType.Delivery,
});
debug('sending delivery receipts');
const delivery = await first.encryptReceipt(desktop, {
timestamp: timestamp + 1,
messageTimestamps: [timestamp],
type: ReceiptType.Delivery,
});
await server.send(desktop, delivery);
await server.send(desktop, delivery);
debug('waiting for message state change');
const message = timeline.locator(`[data-testid="${timestamp}"]`);
await message.waitFor();
debug('waiting for message state change');
const message = timeline.locator(`[data-testid="${timestamp}"]`);
await message.waitFor();
if (runId >= DISCARD_COUNT) {
deltaList.push(delta);
console.log('run=%d info=%j', runId - DISCARD_COUNT, { delta });
} else {
console.log('discarded=%d info=%j', runId, { delta });
}
if (runId >= DISCARD_COUNT) {
deltaList.push(delta);
console.log('run=%d info=%j', runId - DISCARD_COUNT, { delta });
} else {
console.log('discarded=%d info=%j', runId, { delta });
}
console.log('stats info=%j', { delta: stats(deltaList, [99, 99.8]) });
} catch (error) {
await bootstrap.saveLogs(app);
throw error;
} finally {
await app?.close();
await bootstrap.teardown();
}
})();
console.log('stats info=%j', { delta: stats(deltaList, [99, 99.8]) });
});