diff --git a/src/db.ts b/src/db.ts index de2386e..9693a63 100644 --- a/src/db.ts +++ b/src/db.ts @@ -42,9 +42,7 @@ const pool = createPool( const executeQuery = (query: Query) => { console.log("executing query"); - const res = pool.acquire(); - - return res + return pool.acquire() .then(async (client: Client) => { console.log("aquired client from pool"); const result = await client.execute(query); diff --git a/src/forge-download.ts b/src/forge-download.ts index 204a55a..3528f07 100644 --- a/src/forge-download.ts +++ b/src/forge-download.ts @@ -1,7 +1,7 @@ import * as ForgeSDK from "forge-apis"; - -const fs = require("fs").promises; +import * as fs from "fs"; import * as config from "./config"; +import { logger } from './logger'; const ObjectsApi = new ForgeSDK.ObjectsApi(); const ItemsApi = new ForgeSDK.ItemsApi(); @@ -19,17 +19,20 @@ const ItemsApi = new ForgeSDK.ItemsApi(); exports.download = async (projectID: string, itemID: string, fileName: string, destination: string, credentials: ForgeSDK.AuthToken) => { const storageLocation = await getStorageLocation(projectID, itemID, credentials); - console.log("Downloading file " + fileName); + logger.info(`download: Downloading file "${fileName}" to ${destination}`); return ObjectsApi.getObject("wip.dm.prod", storageLocation, {}, config.authClient, credentials) .then((res: ForgeSDK.ApiResponse) => { - console.log("Downloaded file " + fileName + " to " + destination); - fs.writeFile(`${destination}/${fileName}`, res.body); + try { + fs.writeFileSync(`${destination}/${fileName}`, res.body); + logger.info(`download: Downloaded file ${fileName} to ${destination}`); + } catch (err) { + logger.error(`download: Error writing file "${fileName}"`, err); + } return itemID; }) .catch((err: ForgeSDK.ApiError) => { - console.log("error while processing " + storageLocation); - console.log(err); + logger.error(`download: Error downloading "${fileName}": ${err.statusCode}`, err); }); }; @@ -41,6 +44,6 @@ const getStorageLocation = (projectID: string, itemID: string, credentials: Forg storageID = storageID.substring(storageID.indexOf("/") + 1); return storageID; }).catch((err: ForgeSDK.ApiError) => { - console.log("unable to get storage location for " + itemID + ": " + err.statusCode); + logger.error(`download: Unable to get storage location for ${itemID}: ${err.statusCode}`, err); }); }; diff --git a/src/forge-upload.ts b/src/forge-upload.ts index 77f9771..eb972a1 100644 --- a/src/forge-upload.ts +++ b/src/forge-upload.ts @@ -1,5 +1,6 @@ import * as ForgeSDK from 'forge-apis'; import * as config from './config'; +import { logger } from './logger'; import * as fs from 'fs'; const jsonVersion: ForgeSDK.JsonApiVersionJsonapi = {version: "1.0"} @@ -138,8 +139,8 @@ function createItem(fileName: string, folderID: string, objectID: string, creden return true; }, (err: ForgeSDK.ApiError) => { - console.log("API ERROR CODE: ", err.statusCode, "\nMESSAGE: ", err.statusMessage, "\nBODY: ", err.statusBody); - return false; + logger.error(`upload: Error creating a new item: ${err.statusCode}`, err); + return false; } ); } @@ -171,12 +172,7 @@ function uploadFileObject(fileName: string, folderName: string, objectID: string {contentDisposition: fileName}, config.authClient, credentials).then( - (resp: ForgeSDK.ApiResponse) => { - if (resp.statusCode != 200) { - console.log("Upload File Error: ", resp.statusCode); - return false; - } - + (res: ForgeSDK.ApiResponse) => { return createItem(fileName, config.folderMap[folderName].fusionID, objectID, credentials); }, (err: ForgeSDK.ApiError) => { diff --git a/src/forge-webhooks.ts b/src/forge-webhooks.ts index c281e99..ec6006c 100644 --- a/src/forge-webhooks.ts +++ b/src/forge-webhooks.ts @@ -1,6 +1,7 @@ import * as axios from "axios"; import * as ForgeSDK from "forge-apis"; import * as config from "./config"; +import { logger } from "./logger"; /** * Kevin Pan | pan261@purdue.edu | Last Modified: 2/7/2022 @@ -22,7 +23,8 @@ const fileShareID = "urn:adsk.wipprod:fs.folder:co.T0n0mYQeS16K0lq1VuuYVQ"; * Function to manage hook lifecycle */ exports.setupHooks = (callbackUrl: string, credentials: ForgeSDK.AuthToken) => { - console.log("Checking hooks"); + logger.info('webhooks: Checking webhooks'); + axios.default({ method: "GET", url: "https://developer.api.autodesk.com/webhooks/v1/hooks", @@ -42,7 +44,7 @@ exports.setupHooks = (callbackUrl: string, credentials: ForgeSDK.AuthToken) => { } else { hookEvents.push(hook.event); if (hook.status === "inactive") { - console.log("reactivating " + hook.event + " hook"); + logger.info(`webhooks: Reactivating hook for ${hook.event}`); reactivateHook(hook.event, hook.hookId, credentials); } } @@ -62,7 +64,7 @@ exports.setupHooks = (callbackUrl: string, credentials: ForgeSDK.AuthToken) => { } }) .catch((err: axios.AxiosError) => { - console.log(err); + logger.error(`webhooks: Error getting webhooks: ${err.code}`, err.response); }); }; @@ -83,10 +85,10 @@ const createHook = (event: string, callbackUrl: string, credentials: ForgeSDK.Au }, }) .then((res: axios.AxiosResponse) => { - console.log("Sucessfully created hook for " + event); + logger.info(`webhooks: Successfully created hook for ${event}`, res.data); }) .catch((err: axios.AxiosError) => { - err.response && console.log("error creating hook for " + event + ": " + err.response.status); + err.response && logger.error(`webhooks: Error creating hook for ${event}: ${err.code}`, err.response); }); }; @@ -104,10 +106,10 @@ const reactivateHook = (event: string, hookID: string, credentials: ForgeSDK.Aut }, }) .then((res: axios.AxiosResponse) => { - console.log("successfully reactivated " + event + " hook"); + logger.info(`webhooks: Successfully reactivated ${event} hook`, res.data); }) .catch((err: axios.AxiosError) => { - err.response && console.log("error reactivating hook for " + event + ": " + err.response.status); + logger.error(`webhooks: Error reactivating hook for ${event}: ${err.code}`, err.response); }); }; @@ -120,17 +122,15 @@ const deleteHook = (event: string, hookID: string, credentials: ForgeSDK.AuthTok }, }) .then((res: axios.AxiosResponse) => { - console.log("deleted " + event + " hook with bad callback url"); + logger.info(`webhooks: Deleted ${event} hook with bad callback URL`, res.data); }) .catch((err: axios.AxiosError) => { - if (err.response) { - console.log("error deleting hook for " + event + ": " + err.response.status); - } + err.response && logger.error(`webhooks: Error deleteing hook for ${event}: ${err.code}`, err.response); }); }; exports.setupToken = (credentials: ForgeSDK.AuthToken) => { - console.log("Checking webhook token"); + logger.info('webhooks: Checking webhook token'); axios.default({ method: "POST", @@ -144,15 +144,15 @@ exports.setupToken = (credentials: ForgeSDK.AuthToken) => { }, }) .then((res: axios.AxiosResponse) => { - console.log(res.data.detail); + logger.info('webhooks: Added new webhook token', res.data) }) .catch((err: axios.AxiosError) => { if (err.response) { if (err.response.status == 400) { - console.log("Webhook token already exists, updating"); + logger.info('webhooks: Webhook token already exists, updating'); updateToken(credentials); } else { - console.log("Error creating a new webhook token"); + logger.error(`webhooks: Error creating webhook token: ${err.code}`, err.response); } } }); @@ -172,9 +172,9 @@ const updateToken = (credentials: ForgeSDK.AuthToken) => { }, }) .then((res: axios.AxiosResponse) => { - console.log("Successfully updated webhook token"); + logger.info('webhooks: Successfully updated webhook token', res.data); }) .catch((err: axios.AxiosError) => { - console.log("Error updating webhook token"); + logger.error(`webhooks: Error updating webhook token: ${err.code}`, err); }); }; diff --git a/src/localhook.ts b/src/localhook.ts index e9b7855..f9cd011 100644 --- a/src/localhook.ts +++ b/src/localhook.ts @@ -1,6 +1,7 @@ import * as chokidar from 'chokidar'; import { AuthToken } from 'forge-apis'; import * as uploader from './forge-upload'; +import { logger } from './logger'; const polltime: number = 100; @@ -54,8 +55,9 @@ function extractFolder(path: string): string[] { * Signal indexing complete, display tracked folders */ watcher.on('ready', () => { - console.log('\nIndexing complete\nPolling every ' + polltime + ' milliseconds\nWatching directories:'); - watcher.getWatched()['.'].forEach((element) => console.log(element + '/')); + let watched: string = ""; + watcher.getWatched()['.'].forEach((element) => watched += ` ${element}/\n`); + logger.info(`localhook: Indexing complete\n Polling every ${polltime} milliseconds\n Watching directories:\n${watched}`); }); /* Gavin Williams | will1742 | 01/19/22 @@ -65,16 +67,11 @@ watcher.on('ready', () => { watcher.on('add', (path: string) => { try { [folder, file] = extractFolder(path); - } catch (e) { - console.log("Invalid Path"); + } catch (err) { + logger.error(`localhook: Invalid path`, err); return; } - console.log(file + ' locally added to ' + folder); - console.log( - '\x1b[93mlocalhook.js::add:', - '\x1b[0mAttempting upload...' - ); - + logger.info(`localhook: ${file} locally added to ${folder}`); uploader.uploadFile(file, folder.toLowerCase(), credentials); }); @@ -85,11 +82,11 @@ watcher.on('add', (path: string) => { watcher.on('unlink', (path: string) => { try { [folder, file] = extractFolder(path); - } catch (e) { - console.log("Invalid Path"); + } catch (err) { + logger.error(`localhook: Invalid path`, err); return; } - console.log(file + ' has been removed from ' + folder); + logger.info(`localhook: ${file} has been removed from ${folder}`); }); /* Kevin Pan | pan261 | 01/30/22 @@ -99,15 +96,15 @@ watcher.on('unlink', (path: string) => { watcher.on('change', (path: string) => { try { [folder, file] = extractFolder(path); - } catch (e) { - console.log("Invalid Path"); + } catch (err) { + logger.error(`localhook: Invalid path`, err); return; } - console.log(file + ' has been modified in ' + folder) + logger.info(`localhook: ${file} has been modified in ${folder}`); }); // Error handling so errors don't crash the server watcher.on('error', (err: any) => { - console.log("Chokidar error:", err) + logger.error(`localhook: Chokidar error`, err); }) diff --git a/src/logger.ts b/src/logger.ts index 494eaac..89d74ef 100644 --- a/src/logger.ts +++ b/src/logger.ts @@ -1,19 +1,49 @@ -import winston = require('winston'); +import * as winston from 'winston'; + +const timezone = () => { + return new Date().toLocaleString('en-US', { + timeZone: 'America/New_York' + }); +} + +const consoleFormat = (info: winston.Logform.TransformableInfo) => { + return `${[info.timestamp]}: ${info.level}: ${info.message}`; +} + +const fileFormat = (info: winston.Logform.TransformableInfo) => { + let meta = info.metadata; + let timestamp = meta.timestamp + + if (Object.keys(meta).length === 1) { + return `${meta.timestamp}: ${info.level}: ${info.message}`; + } + + delete info.timestamp; + + return `${timestamp}: ${info.level}: ${info.message}\nData:` + JSON.stringify(info.metadata, null, '\t') + '\n'; +} export const logger = winston.createLogger({ level: 'info', - format: winston.format.combine( - winston.format.timestamp({format: 'MMM-DD-YYYY HH:mm:ss'}), - winston.format.align(), - winston.format.printf(info => `${info.level}: ${[info.timestamp]}: ${info.message}`), - ), transports: [ new winston.transports.Console({ - level: 'error' + level: 'info', + format: winston.format.combine( + winston.format.colorize({ all: true }), + winston.format.timestamp({format: timezone}), + winston.format.prettyPrint(), + winston.format.printf(info => consoleFormat(info)), + ) }), new winston.transports.File({ level: 'info', - filename: './logs/ffs.log' + filename: `${__dirname}/logs/ffs.log`, + format: winston.format.combine( + winston.format.timestamp({format: timezone}), + winston.format.metadata(), + winston.format.prettyPrint(), + winston.format.printf(info => fileFormat(info)), + ) }) ] }); \ No newline at end of file diff --git a/src/server.ts b/src/server.ts index d39e796..a52ecdc 100644 --- a/src/server.ts +++ b/src/server.ts @@ -8,7 +8,6 @@ import { logger } from "./logger"; import * as ForgeSDK from "forge-apis"; import { Request, Response, ErrorRequestHandler } from "express"; -import { resolve } from "path/posix"; const webhooks = require("./forge-webhooks"); const downloader = require("./forge-download"); @@ -41,7 +40,7 @@ const verifySignature = ( buf: Buffer, encoding: crypto.Encoding ) => { - console.log("Verifying webhook callback signature"); + logger.info("server: Verifying webhook callback signature"); const signature = req.header("x-adsk-signature"); if (!signature) { return; @@ -73,15 +72,15 @@ const getWebhookCallbackURL = () => { let url: string = ""; data.forEach((entry: any) => { if (entry.name === "command_line (http)") { - url = entry.public_url + "/hook" - console.log("Webhook callback url is:", url); + url = entry.public_url + "/hook"; + logger.info(`server: Webhook callback URL is: ${url}`); } }); return url; }) .catch((err: axios.AxiosError) => { - console.log("ngrok server error:", err.code, err.message); + logger.error('server: ngrok server error:', err.response); }); } @@ -100,17 +99,13 @@ const createServer = () => { const PORT = config.port || 3000; if (config.forgeClientId == null || config.forgeClientSecret == null) { - console.error("Missing FORGE_CLIENT_ID or FORGE_CLIENT_SECRET env. variables."); + logger.error("Missing FORGE_CLIENT_ID or FORGE_CLIENT_SECRET env. variables"); return; } // Endpoint to begin authentication process app.get("/auth", function (req: Request, res: Response) { - logger.log('info', '/auth endpoint called'); - console.log( - "\x1b[96mserver.js::createServer:", - "\x1b[0m/auth endpoint called" - ); + logger.info('server: /auth endpoint called'); res.redirect(config.authClient.generateAuthUrl("")); }); @@ -122,10 +117,7 @@ const createServer = () => { credentials = creds; refreshTime = creds.expires_in - 300; res.send("Generated token: " + credentials.access_token); - console.log( - "\x1b[92mserver.js::createServer:", - "\x1b[0m/callback reached, token generated" - ); + logger.info('server: /callback endpoint reached', creds); }) .then(async () => { // get webhook callback url from ngrok @@ -147,38 +139,20 @@ const createServer = () => { setTimeout(() => { credentials.access_token = ""; clearInterval(intervalID); - console.log( - "\x1b[93mserver.js::createServer:", - "\x1b[0mRefresh token expiring, need to authenticate again" - ); + logger.info('server: Refresh token expiring, need to authenticate again'); }, 13 * 24 * 3600 * 1000); // 13 days to ms }) .catch((err: ForgeSDK.ApiError) => { - console.error(err); + logger.error('server: Error getting token in /callback:', err); res.send(err); }); }); - // Endpoint for internal use, to get credentials from our auth server - app.get("/credentials", function (req: Request, res: Response) { - if (credentials.access_token !== "") { - console.log( - "\x1b[96mserver.js::createServer:", - "\x1b[0m/credentials endpoint called, credentials returned" - ); - res.send(credentials); - } else { - console.log( - "\x1b[93mserver.js::createServer:", - "\x1b[0m/credentials endpoint called, no credentials found" - ); - res.send("Need to authenticate at localhost:3000/auth"); - } - }); - app.post("/hook", async function (req: any, res: Response) { + logger.info('server: Webhook callback received'); + if (!req.signature_match) { - console.log("Request received from outside webhooks service"); + logger.warn('server: Request received from outside webhooks service', req); return res.status(403).send("Not called from webhooks service"); } @@ -186,13 +160,24 @@ const createServer = () => { let body: Request["body"] = req.body; + if (credentials && body.hook.event === "dm.version.added") { + logger.info(`server: "${body.payload.name}" has been added in ${config.folderIDtoLocal[body.payload.parentFolderUrn]}`, body); + } + + if (credentials && body.hook.event === "dm.version.modified") { + logger.info(`server: "${body.payload.name}" has been modified in ${config.folderIDtoLocal[body.payload.parentFolderUrn]}`, body); + } + + if (credentials && body.hook.event === "dm.version.deleted") { + logger.info(`server: "${body.payload.name}" has been deleted in ${config.folderIDtoLocal[body.payload.parentFolderUrn]}`, body); + } + if (credentials && body.hook.event === "dm.version.added") { const itemID = body.payload.lineageUrn; //TODO: check if extension is in the name const fileName = body.payload.name; const destination = __dirname + "/file_share" + config.folderIDtoLocal[body.payload.parentFolderUrn]; await downloader.download(config.projectID, itemID, fileName, destination, credentials); - // await deleter.delete(config.projectID, itemID, fileName, credentials); } }); @@ -215,7 +200,7 @@ const createServer = () => { app.use(errorHandler); const server = app.listen(PORT, () => { - console.log(`Server listening on port ${PORT}`); + logger.info(`Server listening on port ${PORT}`); }); return server; @@ -229,11 +214,7 @@ const refresh = () => { .refreshToken(credentials, config.scopes) .then(async (creds: ForgeSDK.AuthToken) => { credentials = creds; - console.log( - "\x1b[92mserver.js::refresh:", - "\x1b[0mnew token generated from refresh token:" - ); - console.log(credentials); + logger.info('server: Token refresed', creds); // check callback URL let webhookUrl = await getWebhookCallbackURL(); @@ -245,7 +226,7 @@ const refresh = () => { localhook.setCredentials(credentials); }) .catch((err: ForgeSDK.ApiError) => { - console.log(err); + logger.error('server: Error refreshing token:', err); }); };