diff --git a/lib/DBSQLLogger.ts b/lib/DBSQLLogger.ts index 3d298b9b..9b369773 100644 --- a/lib/DBSQLLogger.ts +++ b/lib/DBSQLLogger.ts @@ -1,6 +1,45 @@ +import fs from 'fs'; +import path from 'path'; import winston, { Logger } from 'winston'; import IDBSQLLogger, { LoggerOptions, LogLevel } from './contracts/IDBSQLLogger'; +const DEFAULT_LOG_FILE_NAME = 'databricks-sql-nodejs.log'; + +// An existing directory resolves to a default file inside it. Anything else is +// returned as the path winston will open (which drops a trailing separator). +function resolveLogFilePath(filepath: string): string { + try { + if (fs.statSync(filepath).isDirectory()) { + return path.join(filepath, DEFAULT_LOG_FILE_NAME); + } + } catch { + // doesn't exist or isn't accessible: treat it as a file path + } + return path.join(path.dirname(filepath), path.basename(filepath)); +} + +// winston's File transport swallows errors opening its stream (EISDIR, EACCES, +// ENOTDIR, ...), after which the logger stalls for all transports once its +// buffer fills. Check up front that the file can be opened for appending. +// Note: this probe is intentionally not side-effect free. It creates missing +// parent directories and an empty log file (as winston itself would when the +// transport opens), so the check exercises the exact same open path. +// Limitations: this is a one-time, synchronous check (statSync/mkdirSync/ +// openSync) run each time a DBSQLLogger is constructed with a `filepath`. +// Failures that start later (file/dir deleted, permissions changed, disk +// full, a Windows file lock) are not detected here and can still stall the +// logger. Follow-up (separate change): attach a runtime `error` handler to the +// File transport that removes it and falls back to console-only logging. +function checkLogFileWritable(filename: string): Error | undefined { + try { + fs.mkdirSync(path.dirname(filename), { recursive: true }); + fs.closeSync(fs.openSync(filename, 'a')); + return undefined; + } catch (error) { + return error instanceof Error ? error : new Error(String(error)); + } +} + export default class DBSQLLogger implements IDBSQLLogger { logger: Logger; @@ -21,8 +60,23 @@ export default class DBSQLLogger implements IDBSQLLogger { transports: [this.transports.console], }); if (filepath) { - this.transports.file = new winston.transports.File({ filename: filepath, handleExceptions: true, level }); - this.logger.add(this.transports.file); + const filename = resolveLogFilePath(filepath); + const error = checkLogFileWritable(filename); + if (error) { + // Logged at `error` so the console transport's level filter can never + // drop it (e.g. when the logger is configured with `level: error`). + // Trade-off: consumers filtering on the winston `level` field (e.g. + // error-level alerting) WILL see this as an error; the "[warn] ... + // non-fatal" wording only helps human readers tell this config + // fallback apart from a driver failure. + this.logger.log({ + level: LogLevel.error, + message: `[warn] Cannot write to log file ${filename}, logging to console only (non-fatal, driver continues normally): ${error.message}`, + }); + } else { + this.transports.file = new winston.transports.File({ filename, handleExceptions: true, level }); + this.logger.add(this.transports.file); + } } } diff --git a/lib/contracts/IDBSQLLogger.ts b/lib/contracts/IDBSQLLogger.ts index cbf73b6b..80f61469 100644 --- a/lib/contracts/IDBSQLLogger.ts +++ b/lib/contracts/IDBSQLLogger.ts @@ -1,4 +1,10 @@ export interface LoggerOptions { + /** + * Optional: a log file to write to, in addition to the console. If it names an + * existing directory, logs go to `databricks-sql-nodejs.log` inside it. If the + * file can't be opened for writing, the logger reports it on the console (at + * `error` level, so it is shown regardless of `level`) and logs to the console only. + */ filepath?: string; level?: LogLevel; } diff --git a/tests/unit/DBSQLLogger.test.ts b/tests/unit/DBSQLLogger.test.ts index 05cb60b6..788e606c 100644 --- a/tests/unit/DBSQLLogger.test.ts +++ b/tests/unit/DBSQLLogger.test.ts @@ -12,10 +12,27 @@ // See the License for the specific language governing permissions and // limitations under the License. +import fs from 'fs'; +import os from 'os'; +import path from 'path'; import { expect } from 'chai'; +import sinon from 'sinon'; +import winston from 'winston'; import DBSQLLogger from '../../lib/DBSQLLogger'; import { LogLevel } from '../../lib/contracts/IDBSQLLogger'; +async function waitForFileContent(file: string, text: string, timeoutMs = 2000): Promise { + const deadline = Date.now() + timeoutMs; + const read = () => (fs.existsSync(file) ? fs.readFileSync(file, 'utf8') : ''); + while (!read().includes(text) && Date.now() < deadline) { + // eslint-disable-next-line no-await-in-loop + await new Promise((resolve) => { + setTimeout(resolve, 20); + }); + } + return read(); +} + describe('DBSQLLogger level subscription', () => { it('getLevel reflects the configured level', () => { const logger = new DBSQLLogger({ level: LogLevel.warn }); @@ -60,3 +77,132 @@ describe('DBSQLLogger level subscription', () => { expect(logger.getLevel()).to.equal(LogLevel.debug); }); }); + +describe('DBSQLLogger file transport path resolution', () => { + let tmpDir: string; + let logger: DBSQLLogger | undefined; + let fileSettled: Promise | undefined; + + // The File transport opens its stream asynchronously; teardown waits for that + // before closing the logger and deleting the directory. + function createLogger(filepath: string, level?: LogLevel): DBSQLLogger { + const instance = new DBSQLLogger({ filepath, level }); + const file = instance.transports.file; + fileSettled = file + ? new Promise((resolve) => { + file.once('open', () => resolve()); + file.once('error', () => resolve()); + }) + : undefined; + return instance; + } + + beforeEach(() => { + tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), 'dbsql-logger-')); + }); + + afterEach(async () => { + if (fileSettled) { + await fileSettled; + } + logger?.logger.close(); + logger = undefined; + fileSettled = undefined; + fs.rmSync(tmpDir, { recursive: true, force: true }); + }); + + it('writes to a default file inside the directory when filepath is an existing directory', () => { + logger = createLogger(tmpDir); + + expect(logger.transports.file).to.not.be.undefined; + expect(logger.transports.file?.dirname).to.equal(tmpDir); + expect(logger.transports.file?.filename).to.equal('databricks-sql-nodejs.log'); + }); + + it('writes log lines to the default file inside the directory', async () => { + logger = createLogger(tmpDir); + logger.transports.console.silent = true; + + await logger.log(LogLevel.info, 'hello from DBSQLLogger test'); + + const content = await waitForFileContent(path.join(tmpDir, 'databricks-sql-nodejs.log'), 'hello from'); + expect(content).to.contain('hello from DBSQLLogger test'); + }); + + it('resolves an existing directory with a trailing separator to the default file inside it', () => { + logger = createLogger(`${tmpDir}${path.sep}`); + + expect(logger.transports.file?.dirname).to.equal(tmpDir); + expect(logger.transports.file?.filename).to.equal('databricks-sql-nodejs.log'); + }); + + it('keeps writing to an existing file when filepath has a trailing separator', () => { + const filepath = path.join(tmpDir, 'logs'); + fs.writeFileSync(filepath, ''); + logger = createLogger(`${filepath}${path.sep}`); + + expect(logger.transports.file?.dirname).to.equal(tmpDir); + expect(logger.transports.file?.filename).to.equal('logs'); + }); + + for (const level of [LogLevel.info, LogLevel.error]) { + it(`falls back to console only, with a notice, when the log file cannot be opened (level: ${level})`, async () => { + const notADir = path.join(tmpDir, 'not-a-dir'); + fs.writeFileSync(notADir, ''); + const logged: Array<{ level: string; message: string }> = []; + const consoleLog = sinon.stub(winston.transports.Console.prototype, 'log').callsFake((...args: unknown[]) => { + logged.push(args[0] as { level: string; message: string }); + (args[1] as () => void)(); + }); + try { + logger = createLogger(path.join(notADir, 'driver.log'), level); + // Delivery to the Console transport goes through winston's stream piping, + // so poll rather than assuming it completes within a single tick. + const deadline = Date.now() + 2000; + while (logged.length === 0 && Date.now() < deadline) { + // eslint-disable-next-line no-await-in-loop + await new Promise((resolve) => { + setTimeout(resolve, 20); + }); + } + + expect(logger.transports.file).to.be.undefined; + expect(logged).to.have.length(1); + expect(logged[0].level).to.equal(LogLevel.error); + expect(logged[0].message).to.contain('logging to console only'); + } finally { + consoleLog.restore(); + } + }); + } + + it('uses a non-existent filepath unchanged', () => { + const filepath = path.join(tmpDir, 'custom.log'); + logger = createLogger(filepath); + + expect(logger.transports.file).to.not.be.undefined; + expect(logger.transports.file?.dirname).to.equal(tmpDir); + expect(logger.transports.file?.filename).to.equal('custom.log'); + }); + + it('creates missing parent directories and still attaches the file transport', () => { + const nestedDir = path.join(tmpDir, 'a', 'b'); + const filepath = path.join(nestedDir, 'driver.log'); + logger = createLogger(filepath); + + expect(logger.transports.file).to.not.be.undefined; + expect(logger.transports.file?.dirname).to.equal(nestedDir); + expect(logger.transports.file?.filename).to.equal('driver.log'); + expect(fs.statSync(nestedDir).isDirectory()).to.be.true; + expect(fs.existsSync(filepath)).to.be.true; + }); + + it('uses an existing file path unchanged', () => { + const filepath = path.join(tmpDir, 'existing.log'); + fs.writeFileSync(filepath, ''); + logger = createLogger(filepath); + + expect(logger.transports.file?.dirname).to.equal(tmpDir); + expect(logger.transports.file?.filename).to.equal('existing.log'); + }); +});