[coverage] Conformance findings: LOGGING-002 (#494)

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);
+      }
     }
   }
 

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;
 }

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<string> {
+  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<void> | 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<void>((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');
+  });
+});