Skip to content

Commit 4b2bdf5

Browse files
smashahsmashah
committed
🔊 added new logger to client and launch controllers #2272 
1 parent b00b99c commit 4b2bdf5

File tree

4 files changed

+69
-47
lines changed

4 files changed

+69
-47
lines changed

‎src/api/Client.ts‎

Lines changed: 27 additions & 37 deletions
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,6 @@ import { v4 as uuidv4 } from 'uuid';
1414
import { default as parseFunction} from 'parse-function'
1515
import * as fs from 'fs'
1616
import datauri from 'datauri'
17-
import pino from 'pino'
1817
import isUrl from 'is-url-superb'
1918
import { readJsonSync } from 'fs-extra'
2019
import treekill from 'tree-kill';
@@ -39,28 +38,11 @@ import { base64MimeType, getDUrl, isBase64, isDataURL } from '../utils/tools';
3938
import { Call } from './model/call';
4039
import { Button, Section } from './model/button';
4140
import { JsonObject } from 'type-fest';
41+
import { log } from '../utils/logging';
4242

43-
/** @ignore */
44-
const pkg = readJsonSync(path.join(__dirname,'../../package.json')),
45-
createLogger = (sessionId: string, sessionInfo: SessionInfo, config: ConfigObject) => {
46-
const p = path.join(path.resolve(process.cwd()),`/logs/${sessionId || 'session'}/${sessionInfo.START_TS}.log`)
47-
if(!fs.existsSync(p)) {
48-
fs.mkdirSync(path.join(path.resolve(process.cwd()),`/logs/${sessionId || 'session'}`), {
49-
recursive:true
50-
})
51-
}
52-
const logger = pino({
53-
redact: ['file', 'base64', 'image', 'webpBase64', 'base64', 'durl', 'thumbnail'],
54-
},pino.destination(p))
55-
56-
logger.child({
57-
"STAGE": "LAUNCH",
58-
sessionInfo,
59-
config
60-
}).info("")
6143

62-
return logger
63-
}
44+
/** @ignore */
45+
const pkg = readJsonSync(path.join(__dirname,'../../package.json'));
6446

6547
export enum namespace {
6648
Chat = 'Chat',
@@ -289,7 +271,6 @@ export class Client {
289271
private _page: Page;
290272
private _currentlyBeingKilled = false;
291273
private _refreshing = false
292-
private _l: any;
293274
private _prio: number = Number.MAX_SAFE_INTEGER;
294275
private _pageListeners : {
295276
event: keyof PageEventObject,
@@ -337,10 +318,9 @@ export class Client {
337318
await this.registerAllSimpleListenersOnEv();
338319
}
339320
this._sessionInfo.PHONE_VERSION = (await this.getMe())?.phone?.wa_version
340-
this.logger().child({
321+
log.info('LOADED',{
341322
PHONE_VERSION: this._sessionInfo.PHONE_VERSION
342-
}).info()
343-
323+
})
344324
if(this._createConfig?.autoEmoji === undefined || this._createConfig?.autoEmoji) {
345325
const ident = typeof this._createConfig?.autoEmoji === "string" ? this._createConfig?.autoEmoji : ":"
346326
this.onMessage(async message => {
@@ -356,6 +336,7 @@ export class Client {
356336
if(this._createConfig?.deleteSessionDataOnLogout) deleteSessionData(this._createConfig)
357337
if(this._createConfig?.killClientOnLogout) {
358338
console.log("Session logged out. Killing client")
339+
log.warn("Session logged out. Killing client")
359340
this.kill();
360341
}
361342
})
@@ -378,6 +359,7 @@ export class Client {
378359
this._page.on('close',()=>{
379360
if(!this._refreshing) {
380361
console.log("Browser page has closed. Killing client")
362+
log.warn("Browser page has closed. Killing client")
381363
this.kill();
382364
if(this._createConfig?.killProcessOnBrowserClose) process.exit();
383365
}
@@ -407,8 +389,7 @@ export class Client {
407389
* Grab the logger for this session/process
408390
*/
409391
public logger() : any {
410-
if(!this._l) this._l = createLogger(this.getSessionId(), this.getSessionInfo(), this.getConfig());
411-
return this._l;
392+
return log;
412393
}
413394

414395
/**
@@ -520,7 +501,8 @@ export class Client {
520501

521502

522503
private async pup(pageFunction:EvaluateFn<any>, ...args) {
523-
const {safeMode, callTimeout, idChecking, logFile} = this._createConfig;
504+
const {safeMode, callTimeout, idChecking, logFile, logging} = this._createConfig;
505+
let _t : number;
524506
if(safeMode) {
525507
if(!this._page || this._page.isClosed()) throw new CustomError(ERROR_NAME.PAGE_CLOSED, 'page closed');
526508
const state = await this.forceUpdateConnectionState();
@@ -537,15 +519,19 @@ export class Client {
537519
}
538520
})
539521
}
540-
if(logFile) {
522+
if(logging) {
541523
const wapis = (pageFunction?.toString()?.match(/WAPI\.(\w*)\(/g) || [])?.map(s=>s.replace(/WAPI|\.|\(/g,''));
542-
this.logger().child({
543-
_method: wapis?.length === 1 ? wapis[0] : wapis,
544-
...args[0]
545-
}).info()
524+
_t = Date.now()
525+
log.info(`Request ${_t}`,{
526+
_method: wapis?.length === 1 ? wapis[0] : wapis,
527+
...args[0]
528+
})
546529
}
547530
if(callTimeout) return await Promise.race([this._page.evaluate(pageFunction, ...args),new Promise((resolve, reject) => setTimeout(reject, this._createConfig?.callTimeout, new PageEvaluationTimeout()))])
548531
const res = await this._page.evaluate(pageFunction, ...args);
532+
if(_t && logging) {
533+
log.info(`Response ${_t}: ${Date.now() - _t}ms`, {res})
534+
}
549535
if(this._createConfig.onError && typeof res == "string" && (res.startsWith("Error") || res.startsWith("ERROR"))) {
550536
const e = this._createConfig.onError;
551537
/**
@@ -617,7 +603,6 @@ export class Client {
617603
return window[funcName] ? WAPI[`${funcName}`](obj => window[funcName](obj)) : false
618604
},{funcName});
619605
if(this._listeners[funcName] && !this._refreshing) {
620-
// console.log('listener already set');
621606
return true
622607
}
623608
this._listeners[funcName] = fn;
@@ -654,6 +639,7 @@ export class Client {
654639
this.registerPageEventListener('framenavigated', async frame => {
655640
if(frame.url().includes('post_logout=1')) {
656641
console.log("LOGGED OUT")
642+
log.warn("LOGGED OUT")
657643
await fn(true);
658644
}
659645
}, priority)
@@ -1126,7 +1112,8 @@ public async onLiveLocation(chatId: ChatId, fn: (liveLocationChangedEvent: LiveL
11261112
public async kill() : Promise<boolean> {
11271113
if(this._currentlyBeingKilled) return;
11281114
this._currentlyBeingKilled = true;
1129-
console.log('Shutting Down');
1115+
console.log('Killing client. Shutting Down');
1116+
log.info('Killing client. Shutting Down')
11301117
const browser = await this?._page?.browser()
11311118
const pid = browser?.process() ? browser?.process()?.pid : null;
11321119
try{
@@ -1722,6 +1709,7 @@ public async onLiveLocation(chatId: ChatId, fn: (liveLocationChangedEvent: LiveL
17221709
) as Promise<MessageId>;
17231710
} else {
17241711
console.log('something is wrong with this giphy link');
1712+
log.error('something is wrong with this giphy link', giphyMediaUrl);
17251713
return;
17261714
}
17271715
}
@@ -2830,7 +2818,6 @@ public async getStatus(contactId: ContactId) : Promise<{
28302818
*/
28312819
public async setGroupIcon(groupId: GroupChatId, image: DataURL) :Promise<boolean> {
28322820
const mimeInfo = base64MimeType(image);
2833-
console.log("setGroupIcon -> mimeInfo", mimeInfo)
28342821
if(!mimeInfo || mimeInfo.includes("image")){
28352822
let imgData;
28362823
if(this._createConfig.stickerServerEndpoint) {
@@ -3193,7 +3180,6 @@ public async getStatus(contactId: ContactId) : Promise<{
31933180
}
31943181

31953182
private async prepareWebp(image: DataURL, stickerMetadata?: StickerMetadata) {
3196-
// console.log("prepareWebp", image.slice(0,25))
31973183
if(isDataURL(image) && !image.includes("image")) {
31983184
console.error("Not an image. Please use convertMp4BufferToWebpDataUrl to process video stickers");
31993185
return false
@@ -3279,6 +3265,7 @@ public async getStatus(contactId: ContactId) : Promise<{
32793265
} catch (error) {
32803266
const msg = 'Stickers have to be less than 1MB. Please lower the fps or shorten the duration using the processOptions parameter: https://open-wa.github.io/wa-automate-nodejs/classes/client.html#sendmp4assticker'
32813267
console.log(msg)
3268+
log.warn(msg)
32823269
throw new CustomError(ERROR_NAME.STICKER_TOO_LARGE,msg);
32833270
}
32843271
}
@@ -3805,6 +3792,7 @@ public async getStatus(contactId: ContactId) : Promise<{
38053792
return this._registeredWebhooks[id];
38063793
}
38073794
console.log('Invalid listener(s)', events);
3795+
log.warn('Invalid listener(s)', events);
38083796
return false;
38093797
}
38103798

@@ -3829,12 +3817,14 @@ public async getStatus(contactId: ContactId) : Promise<{
38293817
if(!this._registeredEvListeners) this._registeredEvListeners={};
38303818
if(this._registeredEvListeners[simpleListener]) {
38313819
console.log('Listener already registered');
3820+
log.warn('Listener already registered');
38323821
return false;
38333822
}
38343823
this._registeredEvListeners[simpleListener] = await this[simpleListener](data=>ev.emit(this.getEventSignature(simpleListener),this.prepEventData(data,simpleListener)));
38353824
return true;
38363825
}
38373826
console.log('Invalid lisetner', simpleListener);
3827+
log.warn('Invalid lisetner', simpleListener);
38383828
return false;
38393829
}
38403830

‎src/controllers/auth.ts‎

Lines changed: 12 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@ import { Page } from 'puppeteer';
77
import { processSend } from '../utils/tools';
88
import { injectApi, kill } from './browser';
99
import axios from 'axios';
10+
import { log } from '../utils/logging';
1011
const timeout = ms => new Promise(resolve => setTimeout(resolve, ms, 'timeout'));
1112

1213
/**
@@ -30,6 +31,7 @@ export const needsToScan = (waPage: Page) : Observable<unknown> => {
3031
resolve(false)
3132
} catch (error) {
3233
console.log("needsToScan -> error", error)
34+
log.error("needsToScan -> error", error)
3335
}
3436
}))
3537
};
@@ -86,6 +88,7 @@ export async function smartQr(waPage: Page, config?: ConfigObject, spinner ?: Sp
8688
const evalResult = await waPage.evaluate("window.Store && window.Store.State")
8789
if (evalResult === false) {
8890
console.log('Seems as though you have been TOS_BLOCKed, unable to refresh QR Code. Please see https://github.com/open-wa/wa-automate-nodejs#best-practice for information on how to prevent this from happeing. You will most likely not get a QR Code');
91+
log.warn('Seems as though you have been TOS_BLOCKed, unable to refresh QR Code. Please see https://github.com/open-wa/wa-automate-nodejs#best-practice for information on how to prevent this from happeing. You will most likely not get a QR Code');
8992
if (config.throwErrorOnTosBlock) throw new Error('TOSBLOCK');
9093
}
9194

@@ -95,7 +98,10 @@ export async function smartQr(waPage: Page, config?: ConfigObject, spinner ?: Sp
9598
const grabAndEmit = async (qrData) => {
9699
if(qrData) {
97100
if(!config.qrLogSkip) qrcode.generate(qrData,{small: true});
98-
else console.log(`New QR Code generated. Not printing in console because qrLogSkip is set to true`)
101+
else {
102+
console.log(`New QR Code generated. Not printing in console because qrLogSkip is set to true`)
103+
log.info(`New QR Code generated. Not printing in console because qrLogSkip is set to true`)
104+
}
99105
}
100106
try {
101107
const qrPng = await waPage.evaluate(`window.getQrPng()`);
@@ -117,6 +123,7 @@ export async function smartQr(waPage: Page, config?: ConfigObject, spinner ?: Sp
117123
const qrUrl = `${host}${data}`
118124
qrEv.emit(qrUrl, `qrUrl`);
119125
console.log(`Scan the qr code at ${qrUrl}`)
126+
log.info(`Scan the qr code at ${qrUrl}`)
120127
}
121128
hash = data;
122129
}).catch(e=>{
@@ -128,7 +135,9 @@ export async function smartQr(waPage: Page, config?: ConfigObject, spinner ?: Sp
128135
}
129136
} catch (error) {
130137
//@ts-ignore
131-
console.log(await waPage.evaluate("window.launchres"))
138+
const lr = await waPage.evaluate("window.launchres")
139+
console.log(lr)
140+
log.info('smartQr -> error', {lr})
132141
spinner.info(`Something went wrong while retreiving new the QR code but it should not affect the session launch procedure: ${error.message}`)
133142
}
134143
}
@@ -164,6 +173,7 @@ export async function smartQr(waPage: Page, config?: ConfigObject, spinner ?: Sp
164173
//if an error occurs during the qr launcher then take a screenshot.
165174
await screenshot(waPage);
166175
console.log("qr -> e", e);
176+
log.error("qr -> e", e);
167177
})
168178
const firstQr = await waPage.evaluate(`document.querySelector("canvas[aria-label='Scan me!']")?document.querySelector("canvas[aria-label='Scan me!']").parentElement.getAttribute("data-ref"):false`);
169179
await grabAndEmit(firstQr);

‎src/controllers/browser.ts‎

Lines changed: 10 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@ import { FileNotFoundError, getTextFile } from 'pico-s3';
1010
// eslint-disable-next-line @typescript-eslint/no-var-requires
1111
const puppeteer = require('puppeteer-extra')
1212
import treekill from 'tree-kill';
13+
import { log } from '../utils/logging';
1314

1415
let browser;
1516

@@ -195,7 +196,9 @@ const getSessionDataFromFile = (sessionId: string, config: ConfigObject, spinner
195196
export const deleteSessionData = (config: ConfigObject) : boolean => {
196197
const sessionjsonpath = getSessionDataFilePath(config?.sessionId || 'session', config)
197198
if(typeof sessionjsonpath == 'string' && fs.existsSync(sessionjsonpath)) {
198-
console.log("logout detected, deleting session data")
199+
const l = `logout detected, deleting session data file: ${sessionjsonpath}`
200+
console.log(l)
201+
log.info(l)
199202
fs.unlinkSync(sessionjsonpath);
200203
}
201204
return true;
@@ -309,12 +312,15 @@ async function initBrowser(sessionId?: string, config:any={}) {
309312
try {
310313
// const tunnel = await devtools.createTunnel(browser);
311314
const tunnel = config.devtools == 'local' ? devtools.getLocalDevToolsUrl(browser) : (await devtools.createTunnel(browser)).url;
312-
console.log('\ndevtools URL: ', typeof config.devtools == 'object' ? {
315+
const l = `\ndevtools URL: ${ typeof config.devtools == 'object' ? {
313316
...config.devtools,
314317
tunnel
315-
} : tunnel);
318+
} : tunnel}`
319+
console.log(l);
320+
log.info(l);
316321
} catch (error) {
317-
console.log("TCL: initBrowser -> error", error)
322+
console.error("initBrowser -> error", error)
323+
log.error("initBrowser -> error", error)
318324
}
319325
}
320326
return browser;

‎src/controllers/initializer.ts‎

Lines changed: 20 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,7 @@ import { readJsonSync } from 'fs-extra'
1818
import { upload } from 'pico-s3';
1919
import { injectInitPatch } from './init_patch'
2020
import { earlyInjectionCheck, getLicense, getPatch, getAndInjectLivePatch, getAndInjectLicense } from './patch_manager';
21-
import { setupLogging } from '../utils/logging';
21+
import { log, setupLogging } from '../utils/logging';
2222

2323
export const pkg = readJsonSync(path.join(__dirname,'../../package.json')),
2424
configWithCases = readJsonSync(path.join(__dirname,'../../bin/config-schema.json')),
@@ -70,13 +70,16 @@ export async function create(config: ConfigObject = {}): Promise<Client> {
7070
notifier.notify();
7171
if(notifier?.update && config?.keepUpdated && notifier?.update.latest !== pkg.version) {
7272
console.log('UPDATING @OPEN-WA')
73+
log.info('UPDATING @OPEN-WA')
7374
const crossSpawn = await import('cross-spawn')
7475

7576
const result = crossSpawn.sync('npm', ['i', '@open-wa/wa-automate'], { stdio: 'inherit' });
7677
if(!result.stderr) {
7778
console.log('UPDATED SUCCESSFULLY')
79+
log.info('UPDATED SUCCESSFULLY')
7880
}
7981
console.log('RESTARTING PROCESS')
82+
log.info('RESTARTING PROCESS')
8083
process.on("exit", function () {
8184
crossSpawn.spawn(process.argv.shift(), process.argv, {
8285
cwd: process.cwd(),
@@ -118,6 +121,7 @@ export async function create(config: ConfigObject = {}): Promise<Client> {
118121
const {popup} = await import('./popup')
119122
const popupaddr = await popup(config);
120123
console.log(`You can also authenticate the session at: ${popupaddr}`)
124+
log.info(`You can also authenticate the session at: ${popupaddr}`)
121125
}
122126
if (!sessionId) sessionId = 'session';
123127
const spinner = new Spin(sessionId, 'STARTUP', config?.disableSpins);
@@ -176,7 +180,10 @@ export async function create(config: ConfigObject = {}): Promise<Client> {
176180
START_TS
177181
};
178182
if(config?.logDebugInfoAsObject || config?.disableSpins) spinner.succeed(`Debug info: ${JSON.stringify(debugInfo, null, 2)}`);
179-
else console.table(debugInfo);
183+
else {
184+
console.table(debugInfo);
185+
log.info('Debug info:', debugInfo);
186+
}
180187
// eslint-disable-next-line @typescript-eslint/no-unused-vars
181188
spinner.succeed('Use this easy pre-filled link to report an issue: ' + `https://github.com/open-wa/wa-automate-nodejs/issues/new?template=bug_report.yaml&debug_info=${encodeURI(JSON.stringify((({ OS, PAGE_UA, ...o }) => o)(debugInfo) ,null,2))}&environment=${`-%20OS:%20${encodeURI(debugInfo.OS)}%0A-%20Node:%20${encodeURI(process.versions.node)}%0A-%20npm:%20%0A`}`);
182189

@@ -321,8 +328,17 @@ export async function create(config: ConfigObject = {}): Promise<Client> {
321328
spinner?.fail(`Something went wrong while uploading new session data to cloud storage bucket. Continuing...`)
322329
}
323330
}
324-
if (config?.logConsole) waPage.on('console', msg => console.log(msg));
325-
if (config?.logConsoleErrors) waPage.on('error', error => console.log(error));
331+
/**
332+
* Set page-level logging
333+
*/
334+
waPage.on('console', msg => {
335+
if (config?.logConsole) console.log(msg)
336+
log.info('Page Console:', {msg})
337+
});
338+
waPage.on('error', error => {
339+
if (config?.logConsoleErrors) console.error(error)
340+
log.error('Page Console:', {error})
341+
});
326342
if (config?.restartOnCrash) waPage.on('error', async error => {
327343
console.error('Page Crashed! Restarting...', error);
328344
await kill(waPage);

0 commit comments

Comments
 (0)