Skip to content

Commit

Permalink
clamp down on unnecessary logs
Browse files Browse the repository at this point in the history
  • Loading branch information
shadrach-tayo committed Oct 16, 2024
1 parent 8a58fc3 commit 87f0ab4
Show file tree
Hide file tree
Showing 9 changed files with 24 additions and 57 deletions.
30 changes: 3 additions & 27 deletions desci-repo/src/controllers/nodes/documents.ts
Original file line number Diff line number Diff line change
Expand Up @@ -67,16 +67,12 @@ export const createNodeDocument = async function (req: Request, res: Response) {

export const getLatestNodeManifest = async function (req: Request, res: Response) {
const logger = parentLogger.child({ module: 'getLatestNodeManifest', params: req.params });
logger.trace('getLatestNodeManifest');
const { uuid } = req.params;
const { documentId } = req.query;

const getDocument = async (documentId: DocumentId) => {
const automergeUrl = getAutomergeUrl(documentId);
const handle = backendRepo.find<ResearchObjectDocument>(automergeUrl as AutomergeUrl);
logger.trace({ uuid, automergeUrl }, 'Document Handle retrieved');

logger.trace({ uuid, automergeUrl }, 'Get DOCUMENT');
const document = await handle.doc();
logger.trace({ uuid, automergeUrl }, 'DOCUMENT Retrieved');
return document;
Expand All @@ -86,10 +82,8 @@ export const getLatestNodeManifest = async function (req: Request, res: Response
// todo: add support for documentId params and skip querying node
// fast track call if documentId is available
if (documentId) {
logger.trace({ documentId }, 'Fast track using documentId');
const document = await getDocument(documentId as DocumentId);
if (document) res.status(200).send({ ok: true, document });
logger.trace({ document: !!document }, 'Fast tracked call using documentId');
return;
}

Expand All @@ -110,27 +104,13 @@ export const getLatestNodeManifest = async function (req: Request, res: Response
return;
}

logger.info(
{ manifestDocumentId: node.manifestDocumentId, url: getAutomergeUrl(node.manifestDocumentId) },
'Node manifestDocumentId',
);

// const automergeUrl = getAutomergeUrl(node.manifestDocumentId as DocumentId);
// const handle = backendRepo.find<ResearchObjectDocument>(automergeUrl as AutomergeUrl);
// logger.trace({ uuid, automergeUrl }, 'Document Handle retrieved');

// logger.trace({ uuid, automergeUrl }, 'Get DOCUMENT');
// const document = await handle.doc();
// logger.trace({ uuid, automergeUrl }, 'DOCUMENT Retrieved');

if (!node.manifestDocumentId) {
res.status(404).send({ ok: false, message: `node: ${uuid} has no documentId: ${node.manifestDocumentId}` });
return;
}

const document = await getDocument(node.manifestDocumentId as DocumentId);

logger.info({ manifest: document?.manifest }, '[getLatestNodeManifest::END]');
res.status(200).send({ ok: true, document });
} catch (err) {
logger.error({ err }, 'Error');
Expand Down Expand Up @@ -158,7 +138,6 @@ export const dispatchDocumentChange = async function (req: RequestWithNode, res:

const dispatchChange = getDocumentUpdater(documentId);

logger.info({ actions }, 'Actions');
for (const action of actions) {
document = await dispatchChange(action);
}
Expand All @@ -169,7 +148,6 @@ export const dispatchDocumentChange = async function (req: RequestWithNode, res:
}

res.status(200).send({ ok: true, document });
logger.trace('END');
} catch (err) {
logger.error({ err }, 'Error [dispatchDocumentChange]');
res.status(500).send({ ok: false, message: JSON.stringify(err) });
Expand All @@ -178,7 +156,7 @@ export const dispatchDocumentChange = async function (req: RequestWithNode, res:

export const dispatchDocumentActions = async function (req: RequestWithNode, res: Response) {
const logger = parentLogger.child({ module: 'dispatchDocumentActions' });
logger.info({ body: req.body }, 'START [dispatchDocumentActions]');
// logger.info({ body: req.body }, 'START [dispatchDocumentActions]');
try {
if (!(req.body.uuid && req.body.documentId && req.body.actions)) {
logger.error({ body: req.body }, 'Invalid data');
Expand All @@ -190,20 +168,19 @@ export const dispatchDocumentActions = async function (req: RequestWithNode, res
const documentId = req.body.documentId as DocumentId;

if (!(actions && actions.length > 0)) {
logger.error({ actions }, 'No actions to dispatch');
logger.error({ body: req.body }, 'No actions to dispatch');
res.status(400).send({ ok: false, message: 'No actions to dispatch' });
return;
}

const validatedActions = await actionsSchema.parseAsync(actions);
logger.info({ validatedActions }, 'Actions validated');
logger.trace({ validatedActions }, 'Actions validated');

let document: Doc<ResearchObjectDocument> | undefined;

const dispatchChange = getDocumentUpdater(documentId);

for (const action of actions) {
logger.info({ action }, '[AUTOMERGE]::[dispatch Update]');
document = await dispatchChange(action);
}

Expand All @@ -213,7 +190,6 @@ export const dispatchDocumentActions = async function (req: RequestWithNode, res
return;
}

logger.info('END [dispatchDocumentActions]', { document });
res.status(200).send({ ok: true, document });
} catch (err) {
logger.error(err, 'Error [dispatchDocumentChange]');
Expand Down
12 changes: 6 additions & 6 deletions desci-repo/src/lib/PostgresStorageAdapter.ts
Original file line number Diff line number Diff line change
Expand Up @@ -21,7 +21,7 @@ export class PostgresStorageAdapter extends StorageAdapter {

try {
const result = await query(`SELECT * FROM "${this.tableName}" WHERE key = $1`, [key]);
logger.info({ value: result?.length, key }, '[LOAD DOCUMENT]::');
logger.trace({ value: result?.length, key }, '[LOAD DOCUMENT]::');

const response = result?.[0];
// MUST RETURN UNDEFINED!
Expand All @@ -38,7 +38,7 @@ export class PostgresStorageAdapter extends StorageAdapter {
this.cache[key] = binary;

try {
logger.info({ action: 'Save', key }, 'PostgresStorageAdaptser::Save');
logger.trace({ action: 'Save', key }, 'PostgresStorageAdaptser::Save');

await query(
`INSERT INTO "${this.tableName}" (key, value) VALUES ($1, $2) ON CONFLICT(key) DO UPDATE SET value = $2 RETURNING key`,
Expand All @@ -55,7 +55,7 @@ export class PostgresStorageAdapter extends StorageAdapter {
delete this.cache[key];

try {
logger.info({ action: 'Remove', key }, 'PostgresStorageAdapter::Remove');
logger.trace({ action: 'Remove', key }, 'PostgresStorageAdapter::Remove');
await query(`DELETE FROM "${this.tableName}" WHERE key = $1 RETURNING key`, [key]);
} catch (e) {
logger.error({ e, key }, 'PostgresStorageAdapter::Remove ==> Error deleting document');
Expand All @@ -81,7 +81,7 @@ export class PostgresStorageAdapter extends StorageAdapter {
const key = getKey(keyPrefix);
this.cachedKeys(keyPrefix).forEach((key) => delete this.cache[key]);
try {
logger.info({ key, keyPrefix }, 'DELETE DOCUMENT RANGE');
logger.trace({ key, keyPrefix }, 'DELETE DOCUMENT RANGE');
const result = await query(`DELETE FROM "${this.tableName}" WHERE key LIKE $1 RETURNING key`, [`${key}%`]);
console.log({ result, key }, 'DELETED MANY RANGE');
} catch (e) {
Expand All @@ -95,9 +95,9 @@ export class PostgresStorageAdapter extends StorageAdapter {
}

private async loadRangeKeys(keyPrefix: string[]): Promise<string[]> {
logger.info({ keyPrefix }, 'LoadRange Keys');
logger.trace({ keyPrefix }, 'LoadRange Keys');
const response = await query(`SELECT key FROM "${this.tableName}" WHERE key LIKE $1`, [`${keyPrefix}%`]);
logger.info({ keyPrefix, response: response?.length }, '[LOADED RANGE Keys]');
logger.trace({ keyPrefix, response: response?.length }, '[LOADED RANGE Keys]');

return response ? response.map((row) => row.key) : [];
}
Expand Down
2 changes: 1 addition & 1 deletion desci-repo/src/middleware/ensureApiKey.ts
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,7 @@ const REPO_SERVICE_API_KEY = process.env.REPO_SERVICE_SECRET_KEY;

export const ensureApiKey = async (req: Request, res: Response, next: NextFunction) => {
const apiKey = req.headers['x-api-key'];
logger.info({ module: 'EnsureApiKey', apiKeyLength: apiKey?.length, hostname: req.hostname }, 'VERIFY API KEY from');
logger.trace({ module: 'EnsureApiKey', apiKeyLength: apiKey?.length, hostname: req.hostname }, 'VERIFY API KEY from');
if (!apiKey || apiKey !== REPO_SERVICE_API_KEY) {
res.sendStatus(401);
return;
Expand Down
7 changes: 2 additions & 5 deletions desci-repo/src/middleware/guard.ts
Original file line number Diff line number Diff line change
Expand Up @@ -30,19 +30,16 @@ export interface RequestWithNode extends RequestWithUser {
}

export const ensureNodeAccess = async (req: RequestWithUser, res: Response, next: NextFunction) => {
logger.info('START EnsureNodeAccess');
const token = await extractAuthToken(req);

if (!token) {
logger.trace('Token not found');
res.status(401).send({ ok: false, message: 'Unauthorized' });
return;
}

const user = await extractUserFromToken(token);

if (!(user && user.id > 0)) {
logger.trace('User not found');
res.status(401).send({ ok: false, message: 'Unauthorized' });
return;
}
Expand All @@ -59,9 +56,9 @@ export const ensureNodeAccess = async (req: RequestWithUser, res: Response, next
const rows = await query('SELECT * FROM "Node" WHERE uuid = $1 AND ownerId = $2', [uuid, user.id]);
const node = rows?.[0];

logger.info({ email: hideEmail(user.email), uuid, node }, '[EnsureNodeAccess]:: => ');
logger.trace({ email: hideEmail(user.email), uuid, node }, '[EnsureNodeAccess]:: => ');
if (!node) {
logger.info({ uuid, user }, `Node not found ${req.params}`);
logger.trace({ uuid, user }, `Node not found ${req.params}`);
res.status(401).send({ message: 'Unauthorized' });
return;
}
Expand Down
2 changes: 1 addition & 1 deletion desci-repo/src/middleware/permissions.ts
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@ export const extractAuthToken = async (request: ExpressRequest | Request) => {
if (authHeader) {
token = authHeader.split(' ')[1];
}
logger.info({ module: 'Permissions::extractAuthToken', authHeaderLength: authHeader?.length || 0 }, 'Request');
logger.trace({ module: 'Permissions::extractAuthToken', authHeaderLength: authHeader?.length || 0 }, 'Request');

// If auth token wasn't found in the header, try retrieve from cookies
if (!token && request['cookies']) {
Expand Down
4 changes: 1 addition & 3 deletions desci-repo/src/repo.ts
Original file line number Diff line number Diff line change
Expand Up @@ -29,10 +29,8 @@ const config: RepoConfig = {
sharePolicy: async (peerId, documentId) => {
try {
if (!documentId) {
logger.warn({ peerId }, 'SharePolicy: Document ID NOT found');
logger.trace({ peerId }, 'SharePolicy: Document ID NOT found');
return false;
} else {
logger.trace({ peerId, documentId }, 'SharePolicy: Document found');
}
// peer format: `peer-[user#id]:[unique string combination]
if (peerId.toString().length < 8) {
Expand Down
10 changes: 5 additions & 5 deletions desci-repo/src/services/manifestRepo.ts
Original file line number Diff line number Diff line change
Expand Up @@ -50,8 +50,8 @@ export const getDocumentUpdater = (documentId: DocumentId) => {
}

const heads = getHeads(latestDocument);
logger.info({ heads }, `Document Heads`);
logger.info({ action }, `DocumentUpdater::Dispatched`);
// logger.info({ heads, action }, `Document Heads`);
logger.trace({ action, heads }, `DocumentUpdater::Dispatched`);

switch (action.type) {
case 'Add Components':
Expand Down Expand Up @@ -355,13 +355,13 @@ export const getDocumentUpdater = (documentId: DocumentId) => {
assertNever(action);
}

logger.trace({ documentId }, 'get updated doc');
// logger.trace({ documentId }, 'get updated doc');
latestDocument = await handle.doc();
logger.trace({ action }, 'retrieved updated doc');
// logger.trace({ action }, 'retrieved updated doc');

if (latestDocument) {
const updatedHeads = getHeads(latestDocument);
logger.info({ action, heads: updatedHeads }, `DocumentUpdater::Exit`);
logger.trace({ action, heads: updatedHeads }, `DocumentUpdater::Exit`);
}
return latestDocument;
};
Expand Down
4 changes: 2 additions & 2 deletions desci-repo/src/services/nodes.ts
Original file line number Diff line number Diff line change
Expand Up @@ -4,13 +4,13 @@ import { logger } from '../logger.js';

export const verifyNodeDocumentAccess = async (userId: number, documentId: DocumentId) => {
try {
logger.info({ userId, documentId }, 'START [verifyNodeDocumentAccess]::Node');
logger.trace({ userId, documentId }, 'START [verifyNodeDocumentAccess]::Node');
const rows = await query('SELECT * FROM "Node" WHERE "manifestDocumentId" = $1 AND "ownerId" = $2', [
documentId,
userId,
]);
const node = rows?.[0];
logger.info(
logger.trace(
{ uuid: node.uuid, userId, ownerId: node.ownerId, documentId: node.manifestDocumentId },
'[verifyNodeDocumentAccess]::Node',
);
Expand Down
10 changes: 3 additions & 7 deletions desci-repo/src/services/user.ts
Original file line number Diff line number Diff line change
Expand Up @@ -8,21 +8,17 @@ export const hideEmail = (email: string) => {
const logger = parentLogger.child({ module: 'UserService' });

export async function getUserByOrcId(orcid: string): Promise<any | null> {
logger.trace({ fn: 'getUserByOrcId' }, 'user::getUserByOrcId');
logger.info({ fn: 'getUserByOrcId' }, 'user::getUserByOrcId');
logger.trace({ orcid }, 'user::getUserByOrcId');
// const user = await prisma.user.findFirst({ where: { orcid } });
const rows = await query('SELECT * FROM "User" WHERE orcid = $1', [orcid]);
const user = rows?.[0];
logger.info({ fn: 'getUserByOrcId' }, 'user::getUserByOrcId');
return user;
}

export async function getUserByEmail(email: string): Promise<any | null> {
logger.trace({ fn: 'getUserByEmail' }, `user::getUserByEmail ${hideEmail(email)}`);
logger.info({ email }, 'user::getUserByemail');

logger.trace({ email: ` ${hideEmail(email)}` }, `user::getUserByEmail`);
const rows = await query('SELECT * FROM "User" WHERE lower(email) = $1', [email.toLowerCase()]);
logger.info({ rowLength: rows?.length }, 'getUserByEmail query');
logger.trace({ rowLength: rows?.length }, 'getUserByEmail query');

const user = rows?.[0];

Expand Down

0 comments on commit 87f0ab4

Please sign in to comment.