Skip to content

Commit bea4424

Browse files
committed
Standardize log levels
Verbose is now used to log requests and responses. Debug is now used to log internal operations while processing requests. Silly is now used to log raw data associated with requests. This should make it easier for us to control log levels appropriately in various environments. Issue #70 Use better logging levels
1 parent 56cd34e commit bea4424

File tree

1 file changed

+128
-52
lines changed

1 file changed

+128
-52
lines changed

src/classes/SftpSessionHandler.ts

Lines changed: 128 additions & 52 deletions
Original file line numberDiff line numberDiff line change
@@ -47,20 +47,22 @@ export class SftpSessionHandler {
4747
flags: number,
4848
attrs: Attributes,
4949
): void => {
50-
logger.verbose('SFTP file open request (SSH_FXP_OPEN)');
51-
logger.debug('Request:', {
52-
reqId,
53-
filename,
54-
flags,
55-
attrs,
56-
});
50+
logger.verbose(
51+
'Request: SFTP file open (SSH_FXP_OPEN)',
52+
{
53+
reqId,
54+
filename,
55+
flags,
56+
attrs,
57+
},
58+
);
5759
const handle = generateHandle();
5860
logger.debug(`Opening ${filename}: ${handle}`);
5961
this.permanentFileSystem.loadFile(filename)
6062
.then((file) => {
6163
logger.debug('Contents:', file);
6264
this.openFiles.set(handle, file);
63-
logger.debug('Response:', { reqId, handle });
65+
logger.verbose('Response: Handle', { reqId, handle });
6466
this.sftpConnection.handle(
6567
reqId,
6668
Buffer.from(handle),
@@ -69,7 +71,10 @@ export class SftpSessionHandler {
6971
.catch((reason: unknown) => {
7072
logger.warn('Failed to load file', { reqId, filename });
7173
logger.warn(reason);
72-
logger.debug('Response: Status (FAILURE)', { reqId }, SFTP_STATUS_CODE.FAILURE);
74+
logger.verbose('Response: Status (FAILURE)', {
75+
reqId,
76+
code: SFTP_STATUS_CODE.FAILURE,
77+
});
7378
this.sftpConnection.status(reqId, SFTP_STATUS_CODE.FAILURE);
7479
});
7580
};
@@ -86,23 +91,37 @@ export class SftpSessionHandler {
8691
offset: number,
8792
length: number,
8893
): void => {
89-
logger.verbose('SFTP read file request (SSH_FXP_READ)');
90-
logger.debug('Request:', {
91-
reqId,
92-
handle,
93-
offset,
94-
length,
95-
});
94+
logger.verbose(
95+
'Request: SFTP read file (SSH_FXP_READ)',
96+
{
97+
reqId,
98+
handle,
99+
offset,
100+
length,
101+
},
102+
);
96103
const file = this.openFiles.get(handle.toString());
97104
if (!file) {
98105
logger.info('There is no open file associated with this handle', { reqId, handle });
99-
logger.debug('Response: Status (FAILURE)', { reqId }, SFTP_STATUS_CODE.FAILURE);
106+
logger.verbose(
107+
'Response: Status (FAILURE)',
108+
{
109+
reqId,
110+
code: SFTP_STATUS_CODE.FAILURE,
111+
},
112+
);
100113
this.sftpConnection.status(reqId, SFTP_STATUS_CODE.FAILURE);
101114
return;
102115
}
103116

104117
if (offset >= file.size) {
105-
logger.debug('Response: Status (EOF)', { reqId }, SFTP_STATUS_CODE.EOF);
118+
logger.verbose(
119+
'Response: Status (EOF)',
120+
{
121+
reqId,
122+
code: SFTP_STATUS_CODE.EOF,
123+
},
124+
);
106125
this.sftpConnection.status(reqId, SFTP_STATUS_CODE.EOF);
107126
return;
108127
}
@@ -114,7 +133,8 @@ export class SftpSessionHandler {
114133
})
115134
.then(async (response) => {
116135
const data = await response.buffer();
117-
logger.debug('Response: Data', { reqId, data });
136+
logger.verbose('Response: Data', { reqId });
137+
logger.silly('Sent data...', { data });
118138
this.sftpConnection.data(
119139
reqId,
120140
data,
@@ -128,7 +148,13 @@ export class SftpSessionHandler {
128148
length,
129149
});
130150
logger.warn(reason);
131-
logger.debug('Response: Status (FAILURE)', { reqId }, SFTP_STATUS_CODE.FAILURE);
151+
logger.verbose(
152+
'Response: Status (FAILURE)',
153+
{
154+
reqId,
155+
code: SFTP_STATUS_CODE.FAILURE,
156+
},
157+
);
132158
this.sftpConnection.status(reqId, SFTP_STATUS_CODE.FAILURE);
133159
});
134160
};
@@ -141,7 +167,7 @@ export class SftpSessionHandler {
141167
*/
142168
// eslint-disable-next-line class-methods-use-this
143169
public writeHandler = (): void => {
144-
logger.verbose('SFTP write file request (SSH_FXP_WRITE)');
170+
logger.verbose('Request: SFTP write file (SSH_FXP_WRITE)');
145171
};
146172

147173
/**
@@ -154,8 +180,10 @@ export class SftpSessionHandler {
154180
reqId: number,
155181
itemPath: Buffer,
156182
): void => {
157-
logger.verbose('SFTP read open file statistics request (SSH_FXP_FSTAT)');
158-
logger.debug('Request:', { reqId, itemPath });
183+
logger.verbose(
184+
'Request: SFTP read open file statistics (SSH_FXP_FSTAT)',
185+
{ reqId, itemPath },
186+
);
159187
this.genericStatHandler(reqId, itemPath);
160188
};
161189

@@ -167,7 +195,7 @@ export class SftpSessionHandler {
167195
*/
168196
// eslint-disable-next-line class-methods-use-this
169197
public fsetStatHandler = (): void => {
170-
logger.verbose('SFTP write open file statistics request (SSH_FXP_FSETSTAT)');
198+
logger.verbose('Request: SFTP write open file statistics (SSH_FXP_FSETSTAT)');
171199
};
172200

173201
/**
@@ -177,10 +205,18 @@ export class SftpSessionHandler {
177205
* https://datatracker.ietf.org/doc/html/draft-ietf-secsh-filexfer-02#section-6.3
178206
*/
179207
public closeHandler = (reqId: number, handle: Buffer): void => {
180-
logger.verbose('SFTP close file request (SSH_FXP_CLOSE)');
181-
logger.debug('Request:', { reqId, handle });
208+
logger.verbose(
209+
'Request: SFTP close file (SSH_FXP_CLOSE)',
210+
{ reqId, handle },
211+
);
182212
this.openFiles.delete(handle.toString());
183-
logger.debug('Response: Status (OK)', { reqId }, SFTP_STATUS_CODE.OK);
213+
logger.verbose(
214+
'Response: Status (OK)',
215+
{
216+
reqId,
217+
code: SFTP_STATUS_CODE.OK,
218+
},
219+
);
184220
this.sftpConnection.status(reqId, SFTP_STATUS_CODE.OK);
185221
};
186222

@@ -191,15 +227,17 @@ export class SftpSessionHandler {
191227
* https://datatracker.ietf.org/doc/html/draft-ietf-secsh-filexfer-02#section-6.7
192228
*/
193229
public openDirHandler = (reqId: number, dirPath: string): void => {
194-
logger.verbose('SFTP open directory request (SSH_FXP_OPENDIR)');
195-
logger.debug('Request:', { reqId, dirPath });
230+
logger.verbose(
231+
'SFTP open directory request (SSH_FXP_OPENDIR)',
232+
{ reqId, dirPath },
233+
);
196234
const handle = generateHandle();
197235
logger.debug(`Opening ${dirPath}:`, handle);
198236
this.permanentFileSystem.loadDirectory(dirPath)
199237
.then((fileEntries) => {
200238
logger.debug('Contents:', fileEntries);
201239
this.openDirectories.set(handle, fileEntries);
202-
logger.debug('Response:', { reqId, handle });
240+
logger.verbose('Response: Handle', { reqId, handle });
203241
this.sftpConnection.handle(
204242
reqId,
205243
Buffer.from(handle),
@@ -208,7 +246,13 @@ export class SftpSessionHandler {
208246
.catch((reason: unknown) => {
209247
logger.warn('Failed to load path', { reqId, dirPath });
210248
logger.warn(reason);
211-
logger.debug('Response: Status (FAILURE)', { reqId }, SFTP_STATUS_CODE.FAILURE);
249+
logger.verbose(
250+
'Response: Status (FAILURE)',
251+
{
252+
reqId,
253+
code: SFTP_STATUS_CODE.FAILURE,
254+
},
255+
);
212256
this.sftpConnection.status(reqId, SFTP_STATUS_CODE.FAILURE);
213257
});
214258
};
@@ -220,15 +264,23 @@ export class SftpSessionHandler {
220264
* https://datatracker.ietf.org/doc/html/draft-ietf-secsh-filexfer-02#section-6.7
221265
*/
222266
public readDirHandler = (reqId: number, handle: Buffer): void => {
223-
logger.verbose('SFTP read directory request (SSH_FXP_READDIR)');
267+
logger.verbose(
268+
'Request: SFTP read directory (SSH_FXP_READDIR)',
269+
{ reqId, handle },
270+
);
224271
const names = this.openDirectories.get(handle.toString()) ?? [];
225-
logger.debug('Request:', { reqId, handle, names });
226272
if (names.length !== 0) {
227-
logger.debug('Response:', { reqId, names });
273+
logger.verbose('Response: Name', { reqId, names });
228274
this.openDirectories.set(handle.toString(), []);
229275
this.sftpConnection.name(reqId, names);
230276
} else {
231-
logger.debug('Response: Status (EOF)', { reqId }, SFTP_STATUS_CODE.EOF);
277+
logger.verbose(
278+
'Response: Status (EOF)',
279+
{
280+
reqId,
281+
code: SFTP_STATUS_CODE.EOF,
282+
},
283+
);
232284
this.openDirectories.delete(handle.toString());
233285
this.sftpConnection.status(reqId, SFTP_STATUS_CODE.EOF);
234286
}
@@ -244,8 +296,10 @@ export class SftpSessionHandler {
244296
reqId: number,
245297
itemPath: Buffer,
246298
): void => {
247-
logger.verbose('SFTP read file statistics without following symbolic links request (SSH_FXP_LSTAT)');
248-
logger.debug('Request:', { reqId, itemPath });
299+
logger.verbose(
300+
'Request: SFTP read file statistics without following symbolic links (SSH_FXP_LSTAT)',
301+
{ reqId, itemPath },
302+
);
249303
this.genericStatHandler(reqId, itemPath);
250304
};
251305

@@ -259,8 +313,10 @@ export class SftpSessionHandler {
259313
reqId: number,
260314
itemPath: Buffer,
261315
): void => {
262-
logger.verbose('SFTP read file statistics following symbolic links request (SSH_FXP_STAT)');
263-
logger.debug('Request:', { reqId, itemPath });
316+
logger.verbose(
317+
'Request: SFTP read file statistics following symbolic links (SSH_FXP_STAT)',
318+
{ reqId, itemPath },
319+
);
264320
this.genericStatHandler(reqId, itemPath);
265321
};
266322

@@ -272,7 +328,7 @@ export class SftpSessionHandler {
272328
*/
273329
// eslint-disable-next-line class-methods-use-this
274330
public removeHandler = (): void => {
275-
logger.verbose('SFTP remove file request (SSH_FXP_REMOVE)');
331+
logger.verbose('Request: SFTP remove file (SSH_FXP_REMOVE)');
276332
};
277333

278334
/**
@@ -283,7 +339,7 @@ export class SftpSessionHandler {
283339
*/
284340
// eslint-disable-next-line class-methods-use-this
285341
public rmDirHandler = (): void => {
286-
logger.verbose('SFTP remove directory request (SSH_FXP_RMDIR)');
342+
logger.verbose('Request: SFTP remove directory (SSH_FXP_RMDIR)');
287343
};
288344

289345
/**
@@ -293,8 +349,10 @@ export class SftpSessionHandler {
293349
* https://datatracker.ietf.org/doc/html/draft-ietf-secsh-filexfer-02#section-6.11
294350
*/
295351
public realPathHandler = (reqId: number, relativePath: string): void => {
296-
logger.verbose('SFTP canonicalize path request (SSH_FXP_REALPATH)');
297-
logger.debug('Request:', { reqId, relativePath });
352+
logger.verbose(
353+
'Request: SFTP canonicalize path (SSH_FXP_REALPATH)',
354+
{ reqId, relativePath },
355+
);
298356
const resolvedPath = path.resolve('/', relativePath);
299357
this.permanentFileSystem.getItemAttributes(resolvedPath)
300358
.then((attrs) => {
@@ -303,11 +361,20 @@ export class SftpSessionHandler {
303361
attrs,
304362
);
305363
const names = [fileEntry];
306-
logger.debug('Response:', { reqId, names });
364+
logger.verbose(
365+
'Response: Name',
366+
{ reqId, names },
367+
);
307368
this.sftpConnection.name(reqId, names);
308369
})
309370
.catch(() => {
310-
logger.debug('Response: Status (EOF)', { reqId }, SFTP_STATUS_CODE.NO_SUCH_FILE);
371+
logger.verbose(
372+
'Response: Status (EOF)',
373+
{
374+
reqId,
375+
code: SFTP_STATUS_CODE.NO_SUCH_FILE,
376+
},
377+
);
311378
this.sftpConnection.status(reqId, SFTP_STATUS_CODE.NO_SUCH_FILE);
312379
});
313380
};
@@ -320,7 +387,7 @@ export class SftpSessionHandler {
320387
*/
321388
// eslint-disable-next-line class-methods-use-this
322389
public readLinkHandler = (): void => {
323-
logger.verbose('SFTP read link request (SSH_FXP_READLINK)');
390+
logger.verbose('Request: SFTP read link (SSH_FXP_READLINK)');
324391
};
325392

326393
/**
@@ -331,7 +398,7 @@ export class SftpSessionHandler {
331398
*/
332399
// eslint-disable-next-line class-methods-use-this
333400
public setStatHandler = (): void => {
334-
logger.verbose('SFTP set file attributes request (SSH_FXP_SETSTAT)');
401+
logger.verbose('Request: SFTP set file attributes (SSH_FXP_SETSTAT)');
335402
};
336403

337404
/**
@@ -342,7 +409,7 @@ export class SftpSessionHandler {
342409
*/
343410
// eslint-disable-next-line class-methods-use-this
344411
public mkDirHandler = (): void => {
345-
logger.verbose('SFTP create directory request (SSH_FXP_MKDIR)');
412+
logger.verbose('Request: SFTP create directory (SSH_FXP_MKDIR)');
346413
};
347414

348415
/**
@@ -353,7 +420,7 @@ export class SftpSessionHandler {
353420
*/
354421
// eslint-disable-next-line class-methods-use-this
355422
public renameHandler = (): void => {
356-
logger.verbose('SFTP file rename request (SSH_FXP_RENAME)');
423+
logger.verbose('Request: SFTP file rename (SSH_FXP_RENAME)');
357424
};
358425

359426
/**
@@ -364,20 +431,29 @@ export class SftpSessionHandler {
364431
*/
365432
// eslint-disable-next-line class-methods-use-this
366433
public symLinkHandler = (): void => {
367-
logger.verbose('SFTP create symlink request (SSH_FXP_SYMLINK)');
434+
logger.verbose('Request: SFTP create symlink (SSH_FXP_SYMLINK)');
368435
};
369436

370437
private readonly genericStatHandler = (reqId: number, itemPath: Buffer): void => {
371438
this.permanentFileSystem.getItemAttributes(itemPath.toString())
372439
.then((attrs) => {
373-
logger.debug('Response:', { reqId, attrs });
440+
logger.verbose(
441+
'Response: Attrs',
442+
{ reqId, attrs },
443+
);
374444
this.sftpConnection.attrs(
375445
reqId,
376446
attrs,
377447
);
378448
})
379449
.catch(() => {
380-
logger.debug('Response: Status (NO_SUCH_FILE)', { reqId }, SFTP_STATUS_CODE.NO_SUCH_FILE);
450+
logger.verbose(
451+
'Response: Status (NO_SUCH_FILE)',
452+
{
453+
reqId,
454+
code: SFTP_STATUS_CODE.NO_SUCH_FILE,
455+
},
456+
);
381457
this.sftpConnection.status(reqId, SFTP_STATUS_CODE.NO_SUCH_FILE);
382458
});
383459
};

0 commit comments

Comments
 (0)