From 89303860d49cff5620219c4f5eb72eecfc8e3702 Mon Sep 17 00:00:00 2001
From: Danil Uzlov <36223296+d-uzlov@users.noreply.github.com>
Date: Wed, 26 Mar 2025 11:14:08 +0000
Subject: [PATCH 1/8] logs: create context logger for each request

---
 bin/democratic-csi   | 31 ++++++++++++++++++-------------
 src/utils/general.js | 44 ++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 62 insertions(+), 13 deletions(-)

diff --git a/bin/democratic-csi b/bin/democratic-csi
index 3d6b39e..bebfd1b 100755
--- a/bin/democratic-csi
+++ b/bin/democratic-csi
@@ -118,6 +118,7 @@ const cache = new LRU({ max: 500 });
 const { logger } = require("../src/utils/logger");
 const { GrpcError } = require("../src/utils/grpc");
 const GeneralUtils = require("../src/utils/general");
+const uuidv4 = require("uuid").v4;
 
 if (args.logLevel) {
   logger.level = args.logLevel;
@@ -178,17 +179,25 @@ async function requestHandlerProxy(call, callback, serviceMethodName) {
     }
   }
 
+  const requestReadableID = GeneralUtils.loggerIdFromRequest(call, serviceMethodName);
+  const requestUUID = uuidv4();
+  const callContext = {
+    logger: logger.child({
+      method: serviceMethodName,
+      requestId: requestReadableID,
+      uuid: requestUUID,
+    }),
+  };
   try {
-    logger.info(
-      "new request - driver: %s method: %s call: %j",
+    callContext.logger.info(
+      "new request: driver: %s, call: %j",
       driver.constructor.name,
-      serviceMethodName,
       cleansedCall
     );
 
     const lockKeys = GeneralUtils.lockKeysFromRequest(call, serviceMethodName);
     if (lockKeys.length > 0) {
-      logger.debug("operation lock keys: %j", lockKeys);
+      callContext.logger.debug("operation lock keys: %j", lockKeys);
       // check locks
       lockKeys.forEach((key) => {
         if (operationLock.has(key)) {
@@ -216,7 +225,7 @@ async function requestHandlerProxy(call, callback, serviceMethodName) {
     let response;
     let responseError;
     try {
-      // aquire locks
+      // acquire locks
       if (lockKeys.length > 0) {
         lockKeys.forEach((key) => {
           operationLock.add(key);
@@ -246,10 +255,8 @@ async function requestHandlerProxy(call, callback, serviceMethodName) {
       );
     }
 
-    logger.info(
-      "new response - driver: %s method: %s response: %j",
-      driver.constructor.name,
-      serviceMethodName,
+    callContext.logger.info(
+      "new response: %j",
       response
     );
 
@@ -265,10 +272,8 @@ async function requestHandlerProxy(call, callback, serviceMethodName) {
       message = stringify(e);
     }
 
-    logger.error(
-      "handler error - driver: %s method: %s error: %s",
-      driver.constructor.name,
-      serviceMethodName,
+    callContext.logger.error(
+      "handler error: %s",
       message
     );
 
diff --git a/src/utils/general.js b/src/utils/general.js
index 7ffddcb..bb7dfbb 100644
--- a/src/utils/general.js
+++ b/src/utils/general.js
@@ -92,6 +92,49 @@ function lockKeysFromRequest(call, serviceMethodName) {
   }
 }
 
+function loggerIdFromRequest(call, serviceMethodName) {
+  switch (serviceMethodName) {
+    // controller
+    case "CreateVolume":
+      return call.request.name;
+    case "DeleteVolume":
+    case "ControllerExpandVolume":
+    case "ControllerPublishVolume":
+    case "ControllerUnpublishVolume":
+    case "ValidateVolumeCapabilities":
+    case "ControllerGetVolume":
+    case "ControllerModifyVolume":
+      return call.request.volume_id;
+    case "CreateSnapshot":
+      return call.request.source_volume_id;
+    case "DeleteSnapshot":
+      return call.request.snapshot_id;
+    case "ListVolumes":
+    case "GetCapacity":
+    case "ControllerGetCapabilities":
+    case "ListSnapshots":
+      return '';
+
+    // node
+    case "NodeStageVolume":
+    case "NodeUnstageVolume":
+    case "NodePublishVolume":
+    case "NodeUnpublishVolume":
+    case "NodeGetVolumeStats":
+    case "NodeExpandVolume":
+      return call.request.volume_id;
+
+    case "NodeGetCapabilities":
+    case "NodeGetInfo":
+    case "GetPluginInfo":
+    case "GetPluginCapabilities":
+    case "Probe":
+      return '';
+    default:
+      throw `loggerIdFromRequest: unknown method: ${serviceMethodName}`;
+  }
+}
+
 function getLargestNumber() {
   let number;
   for (let i = 0; i < arguments.length; i++) {
@@ -278,6 +321,7 @@ module.exports.crc32 = crc32;
 module.exports.crc16 = crc16;
 module.exports.crc8 = crc8;
 module.exports.lockKeysFromRequest = lockKeysFromRequest;
+module.exports.loggerIdFromRequest = loggerIdFromRequest;
 module.exports.getLargestNumber = getLargestNumber;
 module.exports.stringify = stringify;
 module.exports.before_string = before_string;

From cff82dc2c3b6bce7423d97ec3e5648e2f695f7bb Mon Sep 17 00:00:00 2001
From: Danil Uzlov <36223296+d-uzlov@users.noreply.github.com>
Date: Wed, 26 Mar 2025 11:20:34 +0000
Subject: [PATCH 2/8] add callContext to all driver interface methods

---
 bin/democratic-csi                            |  2 +-
 src/driver/controller-client-common/index.js  | 18 +++++++-------
 src/driver/controller-local-hostpath/index.js |  2 +-
 src/driver/controller-objectivefs/index.js    | 20 ++++++++--------
 src/driver/controller-synology/index.js       | 18 +++++++-------
 src/driver/controller-zfs-local/index.js      |  2 +-
 src/driver/controller-zfs/index.js            | 22 ++++++++---------
 src/driver/freenas/api.js                     | 22 ++++++++---------
 src/driver/freenas/ssh.js                     |  2 +-
 src/driver/index.js                           | 24 +++++++++----------
 src/driver/node-manual/index.js               | 18 +++++++-------
 .../zfs-local-ephemeral-inline/index.js       |  8 +++----
 12 files changed, 79 insertions(+), 79 deletions(-)

diff --git a/bin/democratic-csi b/bin/democratic-csi
index bebfd1b..55926c6 100755
--- a/bin/democratic-csi
+++ b/bin/democratic-csi
@@ -231,7 +231,7 @@ async function requestHandlerProxy(call, callback, serviceMethodName) {
           operationLock.add(key);
         });
       }
-      response = await driver[serviceMethodName](call);
+      response = await driver[serviceMethodName](callContext, call);
     } catch (e) {
       responseError = e;
     } finally {
diff --git a/src/driver/controller-client-common/index.js b/src/driver/controller-client-common/index.js
index b2a7272..50f0595 100644
--- a/src/driver/controller-client-common/index.js
+++ b/src/driver/controller-client-common/index.js
@@ -548,7 +548,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateVolume(call) {
+  async CreateVolume(callContext, call) {
     const driver = this;
 
     const config_key = driver.getConfigKey();
@@ -840,7 +840,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteVolume(call) {
+  async DeleteVolume(callContext, call) {
     const driver = this;
 
     const volume_id = call.request.volume_id;
@@ -873,7 +873,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ControllerExpandVolume(call) {
+  async ControllerExpandVolume(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -885,7 +885,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async GetCapacity(call) {
+  async GetCapacity(callContext, call) {
     const driver = this;
 
     if (
@@ -925,7 +925,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListVolumes(call) {
+  async ListVolumes(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -936,7 +936,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListSnapshots(call) {
+  async ListSnapshots(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -963,7 +963,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateSnapshot(call) {
+  async CreateSnapshot(callContext, call) {
     const driver = this;
 
     const config_key = driver.getConfigKey();
@@ -1305,7 +1305,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteSnapshot(call) {
+  async DeleteSnapshot(callContext, call) {
     const driver = this;
 
     let snapshot_id = call.request.snapshot_id;
@@ -1393,7 +1393,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ValidateVolumeCapabilities(call) {
+  async ValidateVolumeCapabilities(callContext, call) {
     const driver = this;
 
     const volume_id = call.request.volume_id;
diff --git a/src/driver/controller-local-hostpath/index.js b/src/driver/controller-local-hostpath/index.js
index a838cac..225b147 100644
--- a/src/driver/controller-local-hostpath/index.js
+++ b/src/driver/controller-local-hostpath/index.js
@@ -78,7 +78,7 @@ class ControllerLocalHostpathDriver extends ControllerClientCommonDriver {
    * @param {*} call
    * @returns
    */
-  async NodeGetInfo(call) {
+  async NodeGetInfo(callContext, call) {
     const response = await super.NodeGetInfo(...arguments);
     response.accessible_topology = {
       segments: {
diff --git a/src/driver/controller-objectivefs/index.js b/src/driver/controller-objectivefs/index.js
index 121570f..6b64d50 100644
--- a/src/driver/controller-objectivefs/index.js
+++ b/src/driver/controller-objectivefs/index.js
@@ -270,7 +270,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async Probe(call) {
+  async Probe(callContext, call) {
     const driver = this;
     const pool = _.get(driver.options, "objectivefs.pool");
     const object_store = _.get(driver.options, "objectivefs.env.OBJECTSTORE");
@@ -301,7 +301,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateVolume(call) {
+  async CreateVolume(callContext, call) {
     const driver = this;
     const ofsClient = await driver.getObjectiveFSClient();
     const pool = _.get(driver.options, "objectivefs.pool");
@@ -446,7 +446,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteVolume(call) {
+  async DeleteVolume(callContext, call) {
     const driver = this;
     const ofsClient = await driver.getObjectiveFSClient();
     const pool = _.get(driver.options, "objectivefs.pool");
@@ -481,7 +481,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ControllerExpandVolume(call) {
+  async ControllerExpandVolume(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -493,7 +493,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async GetCapacity(call) {
+  async GetCapacity(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -506,7 +506,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListVolumes(call) {
+  async ListVolumes(callContext, call) {
     const driver = this;
     const ofsClient = await driver.getObjectiveFSClient();
     const pool = _.get(driver.options, "objectivefs.pool");
@@ -588,7 +588,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListSnapshots(call) {
+  async ListSnapshots(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -599,7 +599,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateSnapshot(call) {
+  async CreateSnapshot(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -612,7 +612,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteSnapshot(call) {
+  async DeleteSnapshot(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -623,7 +623,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ValidateVolumeCapabilities(call) {
+  async ValidateVolumeCapabilities(callContext, call) {
     const driver = this;
     const ofsClient = await driver.getObjectiveFSClient();
     const pool = _.get(driver.options, "objectivefs.pool");
diff --git a/src/driver/controller-synology/index.js b/src/driver/controller-synology/index.js
index bbae748..7645aa4 100644
--- a/src/driver/controller-synology/index.js
+++ b/src/driver/controller-synology/index.js
@@ -319,7 +319,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateVolume(call) {
+  async CreateVolume(callContext, call) {
     const driver = this;
     const httpClient = await driver.getHttpClient();
 
@@ -677,7 +677,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteVolume(call) {
+  async DeleteVolume(callContext, call) {
     const driver = this;
     const httpClient = await driver.getHttpClient();
 
@@ -785,7 +785,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ControllerExpandVolume(call) {
+  async ControllerExpandVolume(callContext, call) {
     const driver = this;
     const httpClient = await driver.getHttpClient();
 
@@ -877,7 +877,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async GetCapacity(call) {
+  async GetCapacity(callContext, call) {
     const driver = this;
     const httpClient = await driver.getHttpClient();
     const location = driver.getLocation();
@@ -907,7 +907,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListVolumes(call) {
+  async ListVolumes(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -918,7 +918,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListSnapshots(call) {
+  async ListSnapshots(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -929,7 +929,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateSnapshot(call) {
+  async CreateSnapshot(callContext, call) {
     const driver = this;
     const httpClient = await driver.getHttpClient();
 
@@ -1049,7 +1049,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteSnapshot(call) {
+  async DeleteSnapshot(callContext, call) {
     // throw new GrpcError(
     //   grpc.status.UNIMPLEMENTED,
     //   `operation not supported by driver`
@@ -1100,7 +1100,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ValidateVolumeCapabilities(call) {
+  async ValidateVolumeCapabilities(callContext, call) {
     const driver = this;
     const httpClient = await driver.getHttpClient();
 
diff --git a/src/driver/controller-zfs-local/index.js b/src/driver/controller-zfs-local/index.js
index bfc3295..34f5bba 100644
--- a/src/driver/controller-zfs-local/index.js
+++ b/src/driver/controller-zfs-local/index.js
@@ -227,7 +227,7 @@ class ControllerZfsLocalDriver extends ControllerZfsBaseDriver {
    * @param {*} call
    * @returns
    */
-  async NodeGetInfo(call) {
+  async NodeGetInfo(callContext, call) {
     const response = await super.NodeGetInfo(...arguments);
     response.accessible_topology = {
       segments: {
diff --git a/src/driver/controller-zfs/index.js b/src/driver/controller-zfs/index.js
index d665979..959a9f6 100644
--- a/src/driver/controller-zfs/index.js
+++ b/src/driver/controller-zfs/index.js
@@ -562,7 +562,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async Probe(call) {
+  async Probe(callContext, call) {
     const driver = this;
 
     if (driver.ctx.args.csiMode.includes("controller")) {
@@ -634,7 +634,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateVolume(call) {
+  async CreateVolume(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const execClient = this.getExecClient();
@@ -1269,7 +1269,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteVolume(call) {
+  async DeleteVolume(callContext, call) {
     const driver = this;
     const zb = await this.getZetabyte();
 
@@ -1401,7 +1401,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ControllerExpandVolume(call) {
+  async ControllerExpandVolume(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const zb = await this.getZetabyte();
@@ -1520,7 +1520,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async GetCapacity(call) {
+  async GetCapacity(callContext, call) {
     const driver = this;
     const zb = await this.getZetabyte();
 
@@ -1569,7 +1569,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ControllerGetVolume(call) {
+  async ControllerGetVolume(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const zb = await this.getZetabyte();
@@ -1650,7 +1650,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListVolumes(call) {
+  async ListVolumes(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const zb = await this.getZetabyte();
@@ -1790,7 +1790,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListSnapshots(call) {
+  async ListSnapshots(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const zb = await this.getZetabyte();
@@ -2044,7 +2044,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateSnapshot(call) {
+  async CreateSnapshot(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const zb = await this.getZetabyte();
@@ -2352,7 +2352,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteSnapshot(call) {
+  async DeleteSnapshot(callContext, call) {
     const driver = this;
     const zb = await this.getZetabyte();
 
@@ -2423,7 +2423,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ValidateVolumeCapabilities(call) {
+  async ValidateVolumeCapabilities(callContext, call) {
     const driver = this;
     const zb = await this.getZetabyte();
 
diff --git a/src/driver/freenas/api.js b/src/driver/freenas/api.js
index c5df0a0..fc37fac 100644
--- a/src/driver/freenas/api.js
+++ b/src/driver/freenas/api.js
@@ -2177,7 +2177,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async Probe(call) {
+  async Probe(callContext, call) {
     const driver = this;
     const httpApiClient = await driver.getTrueNASHttpApiClient();
 
@@ -2228,7 +2228,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateVolume(call) {
+  async CreateVolume(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const httpApiClient = await this.getTrueNASHttpApiClient();
@@ -3000,7 +3000,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteVolume(call) {
+  async DeleteVolume(callContext, call) {
     const driver = this;
     const httpApiClient = await this.getTrueNASHttpApiClient();
     const zb = await this.getZetabyte();
@@ -3133,7 +3133,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ControllerExpandVolume(call) {
+  async ControllerExpandVolume(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const httpApiClient = await this.getTrueNASHttpApiClient();
@@ -3254,7 +3254,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async GetCapacity(call) {
+  async GetCapacity(callContext, call) {
     const driver = this;
     const httpApiClient = await this.getTrueNASHttpApiClient();
     const zb = await this.getZetabyte();
@@ -3302,7 +3302,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ControllerGetVolume(call) {
+  async ControllerGetVolume(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const httpApiClient = await this.getTrueNASHttpApiClient();
@@ -3376,7 +3376,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListVolumes(call) {
+  async ListVolumes(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const httpClient = await this.getHttpClient();
@@ -3518,7 +3518,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListSnapshots(call) {
+  async ListSnapshots(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const httpClient = await this.getHttpClient();
@@ -3935,7 +3935,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateSnapshot(call) {
+  async CreateSnapshot(callContext, call) {
     const driver = this;
     const driverZfsResourceType = this.getDriverZfsResourceType();
     const httpClient = await this.getHttpClient();
@@ -4333,7 +4333,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteSnapshot(call) {
+  async DeleteSnapshot(callContext, call) {
     const driver = this;
     const httpApiClient = await this.getTrueNASHttpApiClient();
     const zb = await this.getZetabyte();
@@ -4413,7 +4413,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ValidateVolumeCapabilities(call) {
+  async ValidateVolumeCapabilities(callContext, call) {
     const driver = this;
     const httpApiClient = await this.getTrueNASHttpApiClient();
 
diff --git a/src/driver/freenas/ssh.js b/src/driver/freenas/ssh.js
index 3f635ac..c94015c 100644
--- a/src/driver/freenas/ssh.js
+++ b/src/driver/freenas/ssh.js
@@ -35,7 +35,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
    *
    * @param {*} call
    */
-  async Probe(call) {
+  async Probe(callContext, call) {
     const driver = this;
 
     if (driver.ctx.args.csiMode.includes("controller")) {
diff --git a/src/driver/index.js b/src/driver/index.js
index f0fe630..992a401 100644
--- a/src/driver/index.js
+++ b/src/driver/index.js
@@ -497,14 +497,14 @@ class CsiBaseDriver {
     return volume_id;
   }
 
-  async GetPluginInfo(call) {
+  async GetPluginInfo(callContext, call) {
     return {
       name: this.ctx.args.csiName,
       vendor_version: this.ctx.args.version,
     };
   }
 
-  async GetPluginCapabilities(call) {
+  async GetPluginCapabilities(callContext, call) {
     let capabilities;
     const response = {
       capabilities: [],
@@ -589,11 +589,11 @@ class CsiBaseDriver {
     return response;
   }
 
-  async Probe(call) {
+  async Probe(callContext, call) {
     return { ready: { value: true } };
   }
 
-  async ControllerGetCapabilities(call) {
+  async ControllerGetCapabilities(callContext, call) {
     let capabilities;
     const response = {
       capabilities: [],
@@ -636,7 +636,7 @@ class CsiBaseDriver {
     return response;
   }
 
-  async NodeGetCapabilities(call) {
+  async NodeGetCapabilities(callContext, call) {
     let capabilities;
     const response = {
       capabilities: [],
@@ -661,7 +661,7 @@ class CsiBaseDriver {
     return response;
   }
 
-  async NodeGetInfo(call) {
+  async NodeGetInfo(callContext, call) {
     return {
       node_id: process.env.CSI_NODE_ID || os.hostname(),
       max_volumes_per_node: 0,
@@ -678,7 +678,7 @@ class CsiBaseDriver {
    *
    * @param {*} call
    */
-  async NodeStageVolume(call) {
+  async NodeStageVolume(callContext, call) {
     const driver = this;
     const mount = driver.getDefaultMountInstance();
     const filesystem = driver.getDefaultFilesystemInstance();
@@ -2437,7 +2437,7 @@ class CsiBaseDriver {
    *
    * @param {*} call
    */
-  async NodeUnstageVolume(call) {
+  async NodeUnstageVolume(callContext, call) {
     const driver = this;
     const mount = driver.getDefaultMountInstance();
     const filesystem = driver.getDefaultFilesystemInstance();
@@ -2969,7 +2969,7 @@ class CsiBaseDriver {
     return {};
   }
 
-  async NodePublishVolume(call) {
+  async NodePublishVolume(callContext, call) {
     const driver = this;
     const mount = driver.getDefaultMountInstance();
     const filesystem = driver.getDefaultFilesystemInstance();
@@ -3290,7 +3290,7 @@ class CsiBaseDriver {
     }
   }
 
-  async NodeUnpublishVolume(call) {
+  async NodeUnpublishVolume(callContext, call) {
     const driver = this;
     const mount = driver.getDefaultMountInstance();
     const filesystem = driver.getDefaultFilesystemInstance();
@@ -3458,7 +3458,7 @@ class CsiBaseDriver {
     return {};
   }
 
-  async NodeGetVolumeStats(call) {
+  async NodeGetVolumeStats(callContext, call) {
     const driver = this;
     const mount = driver.getDefaultMountInstance();
     const filesystem = driver.getDefaultFilesystemInstance();
@@ -3692,7 +3692,7 @@ class CsiBaseDriver {
    *
    * @param {*} call
    */
-  async NodeExpandVolume(call) {
+  async NodeExpandVolume(callContext, call) {
     const driver = this;
     const mount = driver.getDefaultMountInstance();
     const filesystem = driver.getDefaultFilesystemInstance();
diff --git a/src/driver/node-manual/index.js b/src/driver/node-manual/index.js
index c55915e..f30d63c 100644
--- a/src/driver/node-manual/index.js
+++ b/src/driver/node-manual/index.js
@@ -242,7 +242,7 @@ class NodeManualDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateVolume(call) {
+  async CreateVolume(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -253,7 +253,7 @@ class NodeManualDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteVolume(call) {
+  async DeleteVolume(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -264,7 +264,7 @@ class NodeManualDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ControllerExpandVolume(call) {
+  async ControllerExpandVolume(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -275,7 +275,7 @@ class NodeManualDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async GetCapacity(call) {
+  async GetCapacity(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -286,7 +286,7 @@ class NodeManualDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListVolumes(call) {
+  async ListVolumes(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -297,7 +297,7 @@ class NodeManualDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ListSnapshots(call) {
+  async ListSnapshots(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -308,7 +308,7 @@ class NodeManualDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async CreateSnapshot(call) {
+  async CreateSnapshot(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -319,7 +319,7 @@ class NodeManualDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async DeleteSnapshot(call) {
+  async DeleteSnapshot(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
@@ -330,7 +330,7 @@ class NodeManualDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ValidateVolumeCapabilities(call) {
+  async ValidateVolumeCapabilities(callContext, call) {
     throw new GrpcError(
       grpc.status.UNIMPLEMENTED,
       `operation not supported by driver`
diff --git a/src/driver/zfs-local-ephemeral-inline/index.js b/src/driver/zfs-local-ephemeral-inline/index.js
index 276b1f4..57be40b 100644
--- a/src/driver/zfs-local-ephemeral-inline/index.js
+++ b/src/driver/zfs-local-ephemeral-inline/index.js
@@ -272,7 +272,7 @@ class ZfsLocalEphemeralInlineDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async NodePublishVolume(call) {
+  async NodePublishVolume(callContext, call) {
     const driver = this;
     const zb = this.getZetabyte();
 
@@ -386,7 +386,7 @@ class ZfsLocalEphemeralInlineDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async NodeUnpublishVolume(call) {
+  async NodeUnpublishVolume(callContext, call) {
     const zb = this.getZetabyte();
     const filesystem = new Filesystem();
     let result;
@@ -454,7 +454,7 @@ class ZfsLocalEphemeralInlineDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async GetCapacity(call) {
+  async GetCapacity(callContext, call) {
     const driver = this;
     const zb = this.getZetabyte();
 
@@ -488,7 +488,7 @@ class ZfsLocalEphemeralInlineDriver extends CsiBaseDriver {
    *
    * @param {*} call
    */
-  async ValidateVolumeCapabilities(call) {
+  async ValidateVolumeCapabilities(callContext, call) {
     const driver = this;
     const result = this.assertCapabilities(call.request.volume_capabilities);
 

From 7e78977c836a48661be9c05de8fe7eda05cd12cf Mon Sep 17 00:00:00 2001
From: Danil Uzlov <36223296+d-uzlov@users.noreply.github.com>
Date: Wed, 26 Mar 2025 11:33:37 +0000
Subject: [PATCH 3/8] add callContext to assertCapabilities method

---
 src/driver/controller-client-common/index.js   | 8 ++++----
 src/driver/controller-objectivefs/index.js     | 6 +++---
 src/driver/controller-synology/index.js        | 8 ++++----
 src/driver/controller-zfs/index.js             | 8 ++++----
 src/driver/freenas/api.js                      | 8 ++++----
 src/driver/index.js                            | 4 ++--
 src/driver/node-manual/index.js                | 2 +-
 src/driver/zfs-local-ephemeral-inline/index.js | 8 ++++----
 8 files changed, 26 insertions(+), 26 deletions(-)

diff --git a/src/driver/controller-client-common/index.js b/src/driver/controller-client-common/index.js
index 50f0595..8621447 100644
--- a/src/driver/controller-client-common/index.js
+++ b/src/driver/controller-client-common/index.js
@@ -156,7 +156,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
     return access_modes;
   }
 
-  assertCapabilities(capabilities) {
+  assertCapabilities(callContext, capabilities) {
     const driver = this;
     this.ctx.logger.verbose("validating capabilities: %j", capabilities);
 
@@ -560,7 +560,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
       call.request.volume_capabilities &&
       call.request.volume_capabilities.length > 0
     ) {
-      const result = this.assertCapabilities(call.request.volume_capabilities);
+      const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
       if (result.valid !== true) {
         throw new GrpcError(grpc.status.INVALID_ARGUMENT, result.message);
       }
@@ -902,7 +902,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
     }
 
     if (call.request.volume_capabilities) {
-      const result = this.assertCapabilities(call.request.volume_capabilities);
+      const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
 
       if (result.valid !== true) {
         return { available_capacity: 0 };
@@ -1414,7 +1414,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
       );
     }
 
-    const result = this.assertCapabilities(call.request.volume_capabilities);
+    const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
 
     if (result.valid !== true) {
       return { message: result.message };
diff --git a/src/driver/controller-objectivefs/index.js b/src/driver/controller-objectivefs/index.js
index 6b64d50..d30e4e7 100644
--- a/src/driver/controller-objectivefs/index.js
+++ b/src/driver/controller-objectivefs/index.js
@@ -159,7 +159,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
     return ["fuse.objectivefs", "objectivefs"];
   }
 
-  assertCapabilities(capabilities) {
+  assertCapabilities(callContext, capabilities) {
     const driver = this;
     this.ctx.logger.verbose("validating capabilities: %j", capabilities);
 
@@ -347,7 +347,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
       call.request.volume_capabilities &&
       call.request.volume_capabilities.length > 0
     ) {
-      const result = this.assertCapabilities(call.request.volume_capabilities);
+      const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
       if (result.valid !== true) {
         throw new GrpcError(grpc.status.INVALID_ARGUMENT, result.message);
       }
@@ -651,7 +651,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
       throw new GrpcError(grpc.status.INVALID_ARGUMENT, `missing capabilities`);
     }
 
-    const result = this.assertCapabilities(call.request.volume_capabilities);
+    const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
 
     if (result.valid !== true) {
       return { message: result.message };
diff --git a/src/driver/controller-synology/index.js b/src/driver/controller-synology/index.js
index 7645aa4..deb3091 100644
--- a/src/driver/controller-synology/index.js
+++ b/src/driver/controller-synology/index.js
@@ -250,7 +250,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
     return access_modes;
   }
 
-  assertCapabilities(capabilities) {
+  assertCapabilities(callContext, capabilities) {
     const driverResourceType = this.getDriverResourceType();
     this.ctx.logger.verbose("validating capabilities: %j", capabilities);
 
@@ -330,7 +330,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
       call.request.volume_capabilities &&
       call.request.volume_capabilities.length > 0
     ) {
-      const result = this.assertCapabilities(call.request.volume_capabilities);
+      const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
       if (result.valid !== true) {
         throw new GrpcError(grpc.status.INVALID_ARGUMENT, result.message);
       }
@@ -890,7 +890,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
     }
 
     if (call.request.volume_capabilities) {
-      const result = this.assertCapabilities(call.request.volume_capabilities);
+      const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
 
       if (result.valid !== true) {
         return { available_capacity: 0 };
@@ -1150,7 +1150,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
         break;
     }
 
-    const result = this.assertCapabilities(call.request.volume_capabilities);
+    const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
     if (result.valid !== true) {
       return { message: result.message };
     }
diff --git a/src/driver/controller-zfs/index.js b/src/driver/controller-zfs/index.js
index 959a9f6..b147732 100644
--- a/src/driver/controller-zfs/index.js
+++ b/src/driver/controller-zfs/index.js
@@ -250,7 +250,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
     return access_modes;
   }
 
-  assertCapabilities(capabilities) {
+  assertCapabilities(callContext, capabilities) {
     const driverZfsResourceType = this.getDriverZfsResourceType();
     this.ctx.logger.verbose("validating capabilities: %j", capabilities);
 
@@ -658,7 +658,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       call.request.volume_capabilities &&
       call.request.volume_capabilities.length > 0
     ) {
-      const result = this.assertCapabilities(call.request.volume_capabilities);
+      const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
       if (result.valid !== true) {
         throw new GrpcError(grpc.status.INVALID_ARGUMENT, result.message);
       }
@@ -1534,7 +1534,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
     }
 
     if (call.request.volume_capabilities) {
-      const result = this.assertCapabilities(call.request.volume_capabilities);
+      const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
 
       if (result.valid !== true) {
         return { available_capacity: 0 };
@@ -2461,7 +2461,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       }
     }
 
-    const result = this.assertCapabilities(call.request.volume_capabilities);
+    const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
 
     if (result.valid !== true) {
       return { message: result.message };
diff --git a/src/driver/freenas/api.js b/src/driver/freenas/api.js
index fc37fac..1d53bee 100644
--- a/src/driver/freenas/api.js
+++ b/src/driver/freenas/api.js
@@ -2082,7 +2082,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
     return access_modes;
   }
 
-  assertCapabilities(capabilities) {
+  assertCapabilities(callContext, capabilities) {
     const driverZfsResourceType = this.getDriverZfsResourceType();
     this.ctx.logger.verbose("validating capabilities: %j", capabilities);
 
@@ -2254,7 +2254,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
       call.request.volume_capabilities &&
       call.request.volume_capabilities.length > 0
     ) {
-      const result = this.assertCapabilities(call.request.volume_capabilities);
+      const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
       if (result.valid !== true) {
         throw new GrpcError(grpc.status.INVALID_ARGUMENT, result.message);
       }
@@ -3269,7 +3269,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
     }
 
     if (call.request.volume_capabilities) {
-      const result = this.assertCapabilities(call.request.volume_capabilities);
+      const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
 
       if (result.valid !== true) {
         return { available_capacity: 0 };
@@ -4450,7 +4450,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
       }
     }
 
-    const result = this.assertCapabilities(capabilities);
+    const result = this.assertCapabilities(callContext, capabilities);
 
     if (result.valid !== true) {
       return { message: result.message };
diff --git a/src/driver/index.js b/src/driver/index.js
index 992a401..c308a8e 100644
--- a/src/driver/index.js
+++ b/src/driver/index.js
@@ -767,7 +767,7 @@ class CsiBaseDriver {
     }
 
     if (call.request.volume_context.provisioner_driver == "node-manual") {
-      result = await this.assertCapabilities([capability], node_attach_driver);
+      result = await this.assertCapabilities(callContext, [capability], node_attach_driver);
       if (!result.valid) {
         throw new GrpcError(
           grpc.status.INVALID_ARGUMENT,
@@ -775,7 +775,7 @@ class CsiBaseDriver {
         );
       }
     } else {
-      result = await this.assertCapabilities([capability]);
+      result = await this.assertCapabilities(callContext, [capability]);
       if (!result.valid) {
         throw new GrpcError(
           grpc.status.INVALID_ARGUMENT,
diff --git a/src/driver/node-manual/index.js b/src/driver/node-manual/index.js
index f30d63c..61cccd1 100644
--- a/src/driver/node-manual/index.js
+++ b/src/driver/node-manual/index.js
@@ -100,7 +100,7 @@ class NodeManualDriver extends CsiBaseDriver {
     }
   }
 
-  assertCapabilities(capabilities, node_attach_driver) {
+  assertCapabilities(callContext, capabilities, node_attach_driver) {
     this.ctx.logger.verbose("validating capabilities: %j", capabilities);
 
     let message = null;
diff --git a/src/driver/zfs-local-ephemeral-inline/index.js b/src/driver/zfs-local-ephemeral-inline/index.js
index 57be40b..05c6683 100644
--- a/src/driver/zfs-local-ephemeral-inline/index.js
+++ b/src/driver/zfs-local-ephemeral-inline/index.js
@@ -165,7 +165,7 @@ class ZfsLocalEphemeralInlineDriver extends CsiBaseDriver {
     return datasetParentName;
   }
 
-  assertCapabilities(capabilities) {
+  assertCapabilities(callContext, capabilities) {
     // hard code this for now
     const driverZfsResourceType = "filesystem";
     this.ctx.logger.verbose("validating capabilities: %j", capabilities);
@@ -309,7 +309,7 @@ class ZfsLocalEphemeralInlineDriver extends CsiBaseDriver {
     }
 
     if (capability) {
-      const result = this.assertCapabilities([capability]);
+      const result = this.assertCapabilities(callContext, [capability]);
 
       if (result.valid !== true) {
         throw new GrpcError(grpc.status.INVALID_ARGUMENT, result.message);
@@ -468,7 +468,7 @@ class ZfsLocalEphemeralInlineDriver extends CsiBaseDriver {
     }
 
     if (call.request.volume_capabilities) {
-      const result = this.assertCapabilities(call.request.volume_capabilities);
+      const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
 
       if (result.valid !== true) {
         return { available_capacity: 0 };
@@ -490,7 +490,7 @@ class ZfsLocalEphemeralInlineDriver extends CsiBaseDriver {
    */
   async ValidateVolumeCapabilities(callContext, call) {
     const driver = this;
-    const result = this.assertCapabilities(call.request.volume_capabilities);
+    const result = this.assertCapabilities(callContext, call.request.volume_capabilities);
 
     if (result.valid !== true) {
       return { message: result.message };

From 3ec110a7d9e5aa2e46c73d420cd0db171916583b Mon Sep 17 00:00:00 2001
From: Danil Uzlov <36223296+d-uzlov@users.noreply.github.com>
Date: Mon, 24 Mar 2025 21:42:05 +0000
Subject: [PATCH 4/8] logs: use context logger in node driver

---
 src/driver/index.js | 44 ++++++++++++++++++++++----------------------
 1 file changed, 22 insertions(+), 22 deletions(-)

diff --git a/src/driver/index.js b/src/driver/index.js
index c308a8e..bc89b69 100644
--- a/src/driver/index.js
+++ b/src/driver/index.js
@@ -944,7 +944,7 @@ class CsiBaseDriver {
 
                 let current_time = Math.round(new Date().getTime() / 1000);
                 if (!result && current_time - timer_start > timer_max) {
-                  driver.ctx.logger.warn(
+                  callContext.logger.warn(
                     `hit timeout waiting for device node to appear: ${device}`
                   );
                   break;
@@ -955,7 +955,7 @@ class CsiBaseDriver {
                 device = await filesystem.realpath(device);
                 iscsiDevices.push(device);
 
-                driver.ctx.logger.info(
+                callContext.logger.info(
                   `successfully logged into portal ${iscsiConnection.portal} and created device ${deviceByPath} with realpath ${device}`
                 );
               }
@@ -979,7 +979,7 @@ class CsiBaseDriver {
             }
 
             if (iscsiDevices.length != iscsiConnections.length) {
-              driver.ctx.logger.warn(
+              callContext.logger.warn(
                 `failed to attach all iscsi devices/targets/portals`
               );
 
@@ -1061,7 +1061,7 @@ class CsiBaseDriver {
                     );
                   });
                 } catch (err) {
-                  driver.ctx.logger.warn(
+                  callContext.logger.warn(
                     `error: ${JSON.stringify(err)} connecting to transport: ${
                       nvmeofConnection.transport
                     }`
@@ -1085,7 +1085,7 @@ class CsiBaseDriver {
                     }
                   });
                 } catch (err) {
-                  driver.ctx.logger.warn(
+                  callContext.logger.warn(
                     `error finding nvme controller device: ${JSON.stringify(
                       err
                     )}`
@@ -1112,7 +1112,7 @@ class CsiBaseDriver {
                     }
                   });
                 } catch (err) {
-                  driver.ctx.logger.warn(
+                  callContext.logger.warn(
                     `error finding nvme namespace device: ${JSON.stringify(
                       err
                     )}`
@@ -1146,7 +1146,7 @@ class CsiBaseDriver {
 
                   let current_time = Math.round(new Date().getTime() / 1000);
                   if (!result && current_time - timer_start > timer_max) {
-                    driver.ctx.logger.warn(
+                    callContext.logger.warn(
                       `hit timeout waiting for namespace device node to appear: ${namespaceDevice}`
                     );
                     break;
@@ -1158,7 +1158,7 @@ class CsiBaseDriver {
                   nvmeofControllerDevices.push(controllerDevice);
                   nvmeofNamespaceDevices.push(namespaceDevice);
 
-                  driver.ctx.logger.info(
+                  callContext.logger.info(
                     `successfully logged into nvmeof transport ${nvmeofConnection.transport} and created controller device: ${controllerDevice}, namespace device: ${namespaceDevice}`
                   );
                 }
@@ -1190,7 +1190,7 @@ class CsiBaseDriver {
               }
 
               if (nvmeofControllerDevices.length != nvmeofConnections.length) {
-                driver.ctx.logger.warn(
+                callContext.logger.warn(
                   `failed to attach all nvmeof devices/subsystems/transports`
                 );
 
@@ -1452,7 +1452,7 @@ class CsiBaseDriver {
                 // data partion MUST be the last partition on the drive
                 // to properly support expand/resize operations
                 device = await filesystem.getBlockDeviceLastPartition(device);
-                driver.ctx.logger.debug(
+                callContext.logger.debug(
                   `device has partitions, mount device is: ${device}`
                 );
 
@@ -1623,7 +1623,7 @@ class CsiBaseDriver {
                       err.stdout.includes("find valid filesystem superblock") &&
                       err.stderr.includes("checksum does not match superblock")
                     ) {
-                      driver.ctx.logger.warn(
+                      callContext.logger.warn(
                         `successful mount, unsuccessful fs resize: attempting abnormal umount/mount/resize2fs to clear things up ${staging_target_path} (${device})`
                       );
 
@@ -1846,7 +1846,7 @@ class CsiBaseDriver {
                       target_port
                     );
                   } catch (e) {
-                    driver.ctx.logger.warn(
+                    callContext.logger.warn(
                       `failed adding target portal: ${JSON.stringify(
                         iscsiConnection
                       )}: ${e.stderr}`
@@ -1927,7 +1927,7 @@ class CsiBaseDriver {
                         "The target has already been logged in via an iSCSI session"
                       )
                     ) {
-                      driver.ctx.logger.warn(
+                      callContext.logger.warn(
                         `failed connection to ${JSON.stringify(
                           iscsiConnection
                         )}: ${e.stderr}`
@@ -1946,7 +1946,7 @@ class CsiBaseDriver {
                 }
 
                 if (iscsiConnections.length != successful_logins) {
-                  driver.ctx.logger.warn(
+                  callContext.logger.warn(
                     `failed to login to all portals: total - ${iscsiConnections.length}, logins - ${successful_logins}`
                   );
                 }
@@ -2481,7 +2481,7 @@ class CsiBaseDriver {
            * AND the fs is probably stalled
            */
           if (err.timeout) {
-            driver.ctx.logger.warn(
+            callContext.logger.warn(
               `detected stale mount, attempting to force unmount: ${normalized_staging_path}`
             );
             await mount.umount(
@@ -2531,14 +2531,14 @@ class CsiBaseDriver {
             );
           } catch (err) {
             if (err.timeout) {
-              driver.ctx.logger.warn(
+              callContext.logger.warn(
                 `hit timeout waiting to unmount path: ${normalized_staging_path}`
               );
               result = await mount.getMountDetails(normalized_staging_path);
               switch (result.fstype) {
                 case "nfs":
                 case "nfs4":
-                  driver.ctx.logger.warn(
+                  callContext.logger.warn(
                     `detected stale nfs filesystem, attempting to force unmount: ${normalized_staging_path}`
                   );
                   result = await mount.umount(
@@ -3316,7 +3316,7 @@ class CsiBaseDriver {
           // the only time this should timeout is on a stale fs
           // so if timeout is hit we should be near certain it is indeed mounted
           if (err.timeout) {
-            driver.ctx.logger.warn(
+            callContext.logger.warn(
               `detected stale mount, attempting to force unmount: ${target_path}`
             );
             await mount.umount(
@@ -3348,7 +3348,7 @@ class CsiBaseDriver {
             );
           } catch (err) {
             if (err.timeout) {
-              driver.ctx.logger.warn(
+              callContext.logger.warn(
                 `hit timeout waiting to unmount path: ${target_path}`
               );
               // bind mounts do show the 'real' fs details
@@ -3356,7 +3356,7 @@ class CsiBaseDriver {
               switch (result.fstype) {
                 case "nfs":
                 case "nfs4":
-                  driver.ctx.logger.warn(
+                  callContext.logger.warn(
                     `detected stale nfs filesystem, attempting to force unmount: ${target_path}`
                   );
                   result = await mount.umount(
@@ -3536,7 +3536,7 @@ class CsiBaseDriver {
                 });
               }
             } catch (err) {
-              driver.ctx.logger.debug("failed to retrieve inode info", err);
+              callContext.logger.debug("failed to retrieve inode info", err);
             }
             break;
           case "block":
@@ -3954,7 +3954,7 @@ class CsiBaseDriver {
                    * TODO: possibly change this to a percentage instead of absolute numbers
                    */
                   let max_delta = 104857600;
-                  driver.ctx.logger.debug(
+                  callContext.logger.debug(
                     "resize diff %s (%s%%)",
                     diff,
                     percentage_diff

From f36ea774f453222ed5956141bd966846f1325b46 Mon Sep 17 00:00:00 2001
From: Danil Uzlov <36223296+d-uzlov@users.noreply.github.com>
Date: Sun, 13 Apr 2025 06:03:00 +0000
Subject: [PATCH 5/8] use context logger in ControllerZfsBaseDriver and
 descendants

---
 src/driver/controller-zfs-generic/index.js    | 56 ++++++------
 src/driver/controller-zfs-local/index.js      |  6 +-
 src/driver/controller-zfs/index.js            | 86 ++++++++++---------
 src/driver/freenas/ssh.js                     | 64 +++++++-------
 .../zfs-local-ephemeral-inline/index.js       |  2 +-
 5 files changed, 108 insertions(+), 106 deletions(-)

diff --git a/src/driver/controller-zfs-generic/index.js b/src/driver/controller-zfs-generic/index.js
index 3e4836f..153556b 100644
--- a/src/driver/controller-zfs-generic/index.js
+++ b/src/driver/controller-zfs-generic/index.js
@@ -74,10 +74,10 @@ class ControllerZfsGenericDriver extends ControllerZfsBaseDriver {
     }
   }
 
-  generateSmbShareName(datasetName) {
+  generateSmbShareName(callContext, datasetName) {
     const driver = this;
 
-    driver.ctx.logger.verbose(
+    callContext.logger.verbose(
       `generating smb share name for dataset: ${datasetName}`
     );
 
@@ -85,7 +85,7 @@ class ControllerZfsGenericDriver extends ControllerZfsBaseDriver {
     name = name.replaceAll("/", "_");
     name = name.replaceAll("-", "_");
 
-    driver.ctx.logger.verbose(
+    callContext.logger.verbose(
       `generated smb share name for dataset (${datasetName}): ${name}`
     );
 
@@ -98,7 +98,7 @@ class ControllerZfsGenericDriver extends ControllerZfsBaseDriver {
    *
    * @param {*} datasetName
    */
-  async createShare(call, datasetName) {
+  async createShare(callContext, call, datasetName) {
     const driver = this;
     const zb = await this.getZetabyte();
     const execClient = this.getExecClient();
@@ -133,7 +133,7 @@ class ControllerZfsGenericDriver extends ControllerZfsBaseDriver {
 
         properties = await zb.zfs.get(datasetName, ["mountpoint"]);
         properties = properties[datasetName];
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         volume_context = {
           node_attach_driver: "nfs",
@@ -160,7 +160,7 @@ class ControllerZfsGenericDriver extends ControllerZfsBaseDriver {
               }
             }
 
-            share = driver.generateSmbShareName(datasetName);
+            share = driver.generateSmbShareName(callContext, datasetName);
             break;
           default:
             break;
@@ -168,7 +168,7 @@ class ControllerZfsGenericDriver extends ControllerZfsBaseDriver {
 
         properties = await zb.zfs.get(datasetName, ["mountpoint"]);
         properties = properties[datasetName];
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         volume_context = {
           node_attach_driver: "smb",
@@ -264,7 +264,7 @@ class ControllerZfsGenericDriver extends ControllerZfsBaseDriver {
               3,
               2000,
               async () => {
-                await this.targetCliCommand(
+                await this.targetCliCommand(callContext,
                   `
 # create target
 cd /iscsi
@@ -303,7 +303,7 @@ create /backstores/block/${assetName}
 
         // iqn = target
         let iqn = basename + ":" + assetName;
-        this.ctx.logger.info("iqn: " + iqn);
+        callContext.logger.info("iqn: " + iqn);
 
         // store this off to make delete process more bullet proof
         await zb.zfs.set(datasetName, {
@@ -403,7 +403,7 @@ create ${basename}:${assetName}
                 3,
                 2000,
                 async () => {
-                  await this.nvmetCliCommand(
+                  await this.nvmetCliCommand(callContext,
                     `
 # create subsystem
 cd /subsystems
@@ -487,7 +487,7 @@ create ${listenerAttributesText}
                 3,
                 2000,
                 async () => {
-                  await this.spdkCliCommand(
+                  await this.spdkCliCommand(callContext,
                     `
 # create bdev
 cd /bdevs/${this.options.nvmeof.shareStrategySpdkCli.bdev.type}
@@ -528,7 +528,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
 
         // iqn = target
         let nqn = basename + ":" + assetName;
-        this.ctx.logger.info("nqn: " + nqn);
+        callContext.logger.info("nqn: " + nqn);
 
         // store this off to make delete process more bullet proof
         await zb.zfs.set(datasetName, {
@@ -555,7 +555,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
     }
   }
 
-  async deleteShare(call, datasetName) {
+  async deleteShare(callContext, call, datasetName) {
     const zb = await this.getZetabyte();
     const execClient = this.getExecClient();
 
@@ -640,7 +640,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
         }
 
         properties = properties[datasetName];
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         assetName = properties[ISCSI_ASSETS_NAME_PROPERTY_NAME].value;
 
@@ -666,7 +666,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
               3,
               2000,
               async () => {
-                await this.targetCliCommand(
+                await this.targetCliCommand(callContext,
                   `
 # delete target
 cd /iscsi
@@ -712,7 +712,7 @@ delete ${assetName}
         }
 
         properties = properties[datasetName];
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         assetName = properties[NVMEOF_ASSETS_NAME_PROPERTY_NAME].value;
 
@@ -756,7 +756,7 @@ delete ${basename}:${assetName}
                 3,
                 2000,
                 async () => {
-                  await this.nvmetCliCommand(
+                  await this.nvmetCliCommand(callContext,
                     `
 # delete subsystem from port
 ${portCommands}
@@ -787,7 +787,7 @@ saveconfig ${savefile}
                 3,
                 2000,
                 async () => {
-                  await this.spdkCliCommand(
+                  await this.spdkCliCommand(callContext,
                     `
 # delete subsystem
 cd /nvmf/subsystem/
@@ -830,7 +830,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
     return {};
   }
 
-  async expandVolume(call, datasetName) {
+  async expandVolume(callContext, call, datasetName) {
     switch (this.options.driver) {
       case "zfs-generic-nfs":
         break;
@@ -850,7 +850,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
     }
   }
 
-  async targetCliCommand(data) {
+  async targetCliCommand(callContext, data) {
     const execClient = this.getExecClient();
     const driver = this;
 
@@ -887,7 +887,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
       logCommand += "\n";
     });
 
-    driver.ctx.logger.verbose("TargetCLI command: " + logCommand);
+    callContext.logger.verbose("TargetCLI command: " + logCommand);
 
     // https://github.com/democratic-csi/democratic-csi/issues/127
     // https://bugs.launchpad.net/ubuntu/+source/python-configshell-fb/+bug/1776761
@@ -901,7 +901,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
       execClient.buildCommand(command, args),
       options
     );
-    driver.ctx.logger.verbose(
+    callContext.logger.verbose(
       "TargetCLI response: " + JSON.stringify(response)
     );
     if (response.code != 0) {
@@ -910,7 +910,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
     return response;
   }
 
-  async nvmetCliCommand(data) {
+  async nvmetCliCommand(callContext, data) {
     const execClient = this.getExecClient();
     const driver = this;
 
@@ -974,7 +974,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
       logCommand += "\n";
     });
 
-    driver.ctx.logger.verbose("nvmetCLI command: " + logCommand);
+    callContext.logger.verbose("nvmetCLI command: " + logCommand);
     //process.exit(0);
 
     // https://github.com/democratic-csi/democratic-csi/issues/127
@@ -989,14 +989,14 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
       execClient.buildCommand(command, args),
       options
     );
-    driver.ctx.logger.verbose("nvmetCLI response: " + JSON.stringify(response));
+    callContext.logger.verbose("nvmetCLI response: " + JSON.stringify(response));
     if (response.code != 0) {
       throw response;
     }
     return response;
   }
 
-  async spdkCliCommand(data) {
+  async spdkCliCommand(callContext, data) {
     const execClient = this.getExecClient();
     const driver = this;
 
@@ -1033,7 +1033,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
       logCommand += "\n";
     });
 
-    driver.ctx.logger.verbose("spdkCLI command: " + logCommand);
+    callContext.logger.verbose("spdkCLI command: " + logCommand);
     //process.exit(0);
 
     // https://github.com/democratic-csi/democratic-csi/issues/127
@@ -1048,7 +1048,7 @@ save_config filename=${this.options.nvmeof.shareStrategySpdkCli.configPath}
       execClient.buildCommand(command, args),
       options
     );
-    driver.ctx.logger.verbose("spdkCLI response: " + JSON.stringify(response));
+    callContext.logger.verbose("spdkCLI response: " + JSON.stringify(response));
     if (response.code != 0) {
       throw response;
     }
diff --git a/src/driver/controller-zfs-local/index.js b/src/driver/controller-zfs-local/index.js
index 34f5bba..607ee28 100644
--- a/src/driver/controller-zfs-local/index.js
+++ b/src/driver/controller-zfs-local/index.js
@@ -160,7 +160,7 @@ class ControllerZfsLocalDriver extends ControllerZfsBaseDriver {
    *
    * @param {*} datasetName
    */
-  async createShare(call, datasetName) {
+  async createShare(callContext, call, datasetName) {
     let volume_context = {};
 
     switch (this.options.driver) {
@@ -193,7 +193,7 @@ class ControllerZfsLocalDriver extends ControllerZfsBaseDriver {
    * @param {*} datasetName
    * @returns
    */
-  async deleteShare(call, datasetName) {
+  async deleteShare(callContext, call, datasetName) {
     return {};
   }
 
@@ -203,7 +203,7 @@ class ControllerZfsLocalDriver extends ControllerZfsBaseDriver {
    * @param {*} call
    * @param {*} datasetName
    */
-  async expandVolume(call, datasetName) {}
+  async expandVolume(callContext, call, datasetName) {}
 
   /**
    * List of topologies associated with the *volume*
diff --git a/src/driver/controller-zfs/index.js b/src/driver/controller-zfs/index.js
index b147732..2b60d3c 100644
--- a/src/driver/controller-zfs/index.js
+++ b/src/driver/controller-zfs/index.js
@@ -41,9 +41,9 @@ const MAX_ZVOL_NAME_LENGTH_CACHE_KEY = "controller-zfs:max_zvol_name_length";
  *  - getFSTypes() // optional
  *  - getAccessModes(capability) // optional
  *  - async getAccessibleTopology() // optional
- *  - async createShare(call, datasetName) // return appropriate volume_context for Node operations
- *  - async deleteShare(call, datasetName) // no return expected
- *  - async expandVolume(call, datasetName) // no return expected, used for restarting services etc if needed
+ *  - async createShare(callContext, call, datasetName) // return appropriate volume_context for Node operations
+ *  - async deleteShare(callContext, call, datasetName) // no return expected
+ *  - async expandVolume(callContext, call, datasetName) // no return expected, used for restarting services etc if needed
  */
 class ControllerZfsBaseDriver extends CsiBaseDriver {
   constructor(ctx, options) {
@@ -152,11 +152,11 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
     }
   }
 
-  async getWhoAmI() {
+  async getWhoAmI(callContext) {
     const driver = this;
     const execClient = driver.getExecClient();
     const command = "whoami";
-    driver.ctx.logger.verbose("whoami command: %s", command);
+    callContext.logger.verbose("whoami command: %s", command);
     const response = await execClient.exec(command);
     if (response.code !== 0) {
       throw new Error("failed to run uname to determine max zvol name length");
@@ -252,7 +252,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
 
   assertCapabilities(callContext, capabilities) {
     const driverZfsResourceType = this.getDriverZfsResourceType();
-    this.ctx.logger.verbose("validating capabilities: %j", capabilities);
+    callContext.logger.verbose("validating capabilities: %j", capabilities);
 
     let message = null;
     //[{"access_mode":{"mode":"SINGLE_NODE_WRITER"},"mount":{"mount_flags":["noatime","_netdev"],"fs_type":"nfs"},"access_type":"mount"}]
@@ -346,7 +346,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
     return volume_status;
   }
 
-  async populateCsiVolumeFromData(row) {
+  async populateCsiVolumeFromData(callContext, row) {
     const driver = this;
     const zb = await this.getZetabyte();
     const driverZfsResourceType = this.getDriverZfsResourceType();
@@ -360,7 +360,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
     if (
       !zb.helpers.isPropertyValueSet(row[SHARE_VOLUME_CONTEXT_PROPERTY_NAME])
     ) {
-      driver.ctx.logger.warn(`${row.name} is missing share context`);
+      callContext.logger.warn(`${row.name} is missing share context`);
       return;
     }
 
@@ -430,7 +430,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
    * https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=238112
    * https://svnweb.freebsd.org/base?view=revision&revision=343485
    */
-  async getMaxZvolNameLength() {
+  async getMaxZvolNameLength(callContext) {
     const driver = this;
     const execClient = driver.getExecClient();
 
@@ -449,7 +449,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
 
     // get kernel
     command = "uname -s";
-    driver.ctx.logger.verbose("uname command: %s", command);
+    callContext.logger.verbose("uname command: %s", command);
     response = await execClient.exec(command);
     if (response.code !== 0) {
       throw new Error("failed to run uname to determine max zvol name length");
@@ -468,7 +468,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       case "freebsd":
         // get kernel_release
         command = "uname -r";
-        driver.ctx.logger.verbose("uname command: %s", command);
+        callContext.logger.verbose("uname command: %s", command);
         response = await execClient.exec(command);
         if (response.code !== 0) {
           throw new Error(
@@ -496,16 +496,16 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
     return max;
   }
 
-  async setFilesystemMode(path, mode) {
+  async setFilesystemMode(callContext, path, mode) {
     const driver = this;
     const execClient = this.getExecClient();
 
     let command = execClient.buildCommand("chmod", [mode, path]);
-    if ((await driver.getWhoAmI()) != "root") {
+    if ((await driver.getWhoAmI(callContext)) != "root") {
       command = (await driver.getSudoPath()) + " " + command;
     }
 
-    driver.ctx.logger.verbose("set permission command: %s", command);
+    callContext.logger.verbose("set permission command: %s", command);
 
     let response = await execClient.exec(command);
     if (response.code != 0) {
@@ -516,7 +516,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
     }
   }
 
-  async setFilesystemOwnership(path, user = false, group = false) {
+  async setFilesystemOwnership(callContext, path, user = false, group = false) {
     const driver = this;
     const execClient = this.getExecClient();
 
@@ -539,11 +539,11 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       (user.length > 0 ? user : "") + ":" + (group.length > 0 ? group : ""),
       path,
     ]);
-    if ((await driver.getWhoAmI()) != "root") {
+    if ((await driver.getWhoAmI(callContext)) != "root") {
       command = (await driver.getSudoPath()) + " " + command;
     }
 
-    driver.ctx.logger.verbose("set ownership command: %s", command);
+    callContext.logger.verbose("set ownership command: %s", command);
 
     let response = await execClient.exec(command);
     if (response.code != 0) {
@@ -590,7 +590,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
        */
       if (!driver.currentExecShell || timerEnabled === false) {
         const execClient = this.getExecClient();
-        driver.ctx.logger.debug("performing exec sanity check..");
+        callContext.logger.debug("performing exec sanity check..");
         const response = await execClient.exec("echo $0");
         driver.currentExecShell = response.stdout.split("\n")[0];
       }
@@ -600,7 +600,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
         const intervalTime = 60000;
         driver.currentExecShellInterval = setInterval(async () => {
           try {
-            driver.ctx.logger.debug("performing exec sanity check..");
+            callContext.logger.debug("performing exec sanity check..");
             const execClient = this.getExecClient();
             const response = await execClient.exec("echo $0");
             driver.currentExecShell = response.stdout.split("\n")[0];
@@ -792,8 +792,8 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
      */
     if (driverZfsResourceType == "volume") {
       let extentDiskName = "zvol/" + datasetName;
-      let maxZvolNameLength = await driver.getMaxZvolNameLength();
-      driver.ctx.logger.debug("max zvol name length: %s", maxZvolNameLength);
+      let maxZvolNameLength = await driver.getMaxZvolNameLength(callContext);
+      callContext.logger.debug("max zvol name length: %s", maxZvolNameLength);
 
       if (extentDiskName.length > maxZvolNameLength) {
         throw new GrpcError(
@@ -849,7 +849,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       volumeProperties[VOLUME_CONTENT_SOURCE_TYPE_PROPERTY_NAME] =
         volume_content_source.type;
       switch (volume_content_source.type) {
-        // must be available when adverstising CREATE_DELETE_SNAPSHOT
+        // must be available when advertising CREATE_DELETE_SNAPSHOT
         // simply clone
         case "snapshot":
           try {
@@ -883,7 +883,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
               volume_id;
           }
 
-          driver.ctx.logger.debug("full snapshot name: %s", fullSnapshotName);
+          callContext.logger.debug("full snapshot name: %s", fullSnapshotName);
 
           if (!zb.helpers.isZfsSnapshot(volume_content_source_snapshot_id)) {
             try {
@@ -997,7 +997,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
             VOLUME_SOURCE_CLONE_SNAPSHOT_PREFIX +
             volume_id;
 
-          driver.ctx.logger.debug("full snapshot name: %s", fullSnapshotName);
+          callContext.logger.debug("full snapshot name: %s", fullSnapshotName);
 
           // create snapshot
           try {
@@ -1130,11 +1130,12 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
           VOLUME_CONTENT_SOURCE_ID_PROPERTY_NAME,
         ]);
         properties = properties[datasetName];
-        driver.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         // set mode
         if (this.options.zfs.datasetPermissionsMode) {
           await driver.setFilesystemMode(
+            callContext,
             properties.mountpoint.value,
             this.options.zfs.datasetPermissionsMode
           );
@@ -1148,6 +1149,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
             .length > 0
         ) {
           await driver.setFilesystemOwnership(
+            callContext,
             properties.mountpoint.value,
             this.options.zfs.datasetPermissionsUser,
             this.options.zfs.datasetPermissionsGroup
@@ -1155,7 +1157,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
         }
 
         // set acls
-        // TODO: this is unsfafe approach, make it better
+        // TODO: this is unsafe approach, make it better
         // probably could see if ^-.*\s and split and then shell escape
         if (this.options.zfs.datasetPermissionsAcls) {
           let aclBinary = _.get(
@@ -1168,11 +1170,11 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
               acl,
               properties.mountpoint.value,
             ]);
-            if ((await this.getWhoAmI()) != "root") {
+            if ((await driver.getWhoAmI(callContext)) != "root") {
               command = (await this.getSudoPath()) + " " + command;
             }
 
-            driver.ctx.logger.verbose("set acl command: %s", command);
+            callContext.logger.verbose("set acl command: %s", command);
             response = await execClient.exec(command);
             if (response.code != 0) {
               throw new GrpcError(
@@ -1222,7 +1224,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
         break;
     }
 
-    volume_context = await this.createShare(call, datasetName);
+    volume_context = await this.createShare(callContext, call, datasetName);
     await zb.zfs.set(datasetName, {
       [SHARE_VOLUME_CONTEXT_PROPERTY_NAME]: JSON.stringify(volume_context),
     });
@@ -1314,7 +1316,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       }
     }
 
-    driver.ctx.logger.debug("dataset properties: %j", properties);
+    callContext.logger.debug("dataset properties: %j", properties);
 
     // deleteStrategy
     const delete_strategy = _.get(
@@ -1328,7 +1330,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
     }
 
     // remove share resources
-    await this.deleteShare(call, datasetName);
+    await this.deleteShare(callContext, call, datasetName);
 
     // remove parent snapshot if appropriate with defer
     if (
@@ -1339,7 +1341,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
         .extractSnapshotName(properties.origin.value)
         .startsWith(VOLUME_SOURCE_CLONE_SNAPSHOT_PREFIX)
     ) {
-      driver.ctx.logger.debug(
+      callContext.logger.debug(
         "removing with defer source snapshot: %s",
         properties.origin.value
       );
@@ -1503,7 +1505,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       await zb.zfs.set(datasetName, properties);
     }
 
-    await this.expandVolume(call, datasetName);
+    await this.expandVolume(callContext, call, datasetName);
 
     return {
       capacity_bytes:
@@ -1632,8 +1634,8 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       throw err;
     }
 
-    driver.ctx.logger.debug("list volumes result: %j", response);
-    let volume = await driver.populateCsiVolumeFromData(response.indexed[0]);
+    callContext.logger.debug("list volumes result: %j", response);
+    let volume = await driver.populateCsiVolumeFromData(callContext, response.indexed[0]);
     let status = await driver.getVolumeStatus(datasetName);
 
     let res = { volume };
@@ -1747,7 +1749,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       throw err;
     }
 
-    driver.ctx.logger.debug("list volumes result: %j", response);
+    callContext.logger.debug("list volumes result: %j", response);
 
     // remove parent dataset from results
     if (driverZfsResourceType == "filesystem") {
@@ -1761,7 +1763,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
         continue;
       }
 
-      let volume = await driver.populateCsiVolumeFromData(row);
+      let volume = await driver.populateCsiVolumeFromData(callContext, row);
       if (volume) {
         let status = await driver.getVolumeStatus(datasetName);
         entries.push({
@@ -2113,7 +2115,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       source_volume_id;
     snapshotProperties[MANAGED_PROPERTY_NAME] = "true";
 
-    driver.ctx.logger.verbose("requested snapshot name: %s", name);
+    callContext.logger.verbose("requested snapshot name: %s", name);
 
     let invalid_chars;
     invalid_chars = name.match(/[^a-z0-9_\-:.+]+/gi);
@@ -2130,7 +2132,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
     // https://stackoverflow.com/questions/32106243/regex-to-remove-all-non-alpha-numeric-and-replace-spaces-with/32106277
     name = name.replace(/[^a-z0-9_\-:.+]+/gi, "");
 
-    driver.ctx.logger.verbose("cleansed snapshot name: %s", name);
+    callContext.logger.verbose("cleansed snapshot name: %s", name);
 
     // check for other snapshopts with the same name on other volumes and fail as appropriate
     {
@@ -2189,7 +2191,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       fullSnapshotName = datasetName + "@" + name;
     }
 
-    driver.ctx.logger.verbose("full snapshot name: %s", fullSnapshotName);
+    callContext.logger.verbose("full snapshot name: %s", fullSnapshotName);
 
     if (detachedSnapshot) {
       tmpSnapshotName =
@@ -2297,7 +2299,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
       { types }
     );
     properties = properties[fullSnapshotName];
-    driver.ctx.logger.verbose("snapshot properties: %j", properties);
+    callContext.logger.verbose("snapshot properties: %j", properties);
 
     // TODO: properly handle use-case where datasetEnableQuotas is not turned on
     if (driverZfsResourceType == "filesystem") {
@@ -2383,7 +2385,7 @@ class ControllerZfsBaseDriver extends CsiBaseDriver {
 
     const fullSnapshotName = datasetParentName + "/" + snapshot_id;
 
-    driver.ctx.logger.verbose("deleting snapshot: %s", fullSnapshotName);
+    callContext.logger.verbose("deleting snapshot: %s", fullSnapshotName);
 
     try {
       await zb.zfs.destroy(fullSnapshotName, {
diff --git a/src/driver/freenas/ssh.js b/src/driver/freenas/ssh.js
index c94015c..4da2e78 100644
--- a/src/driver/freenas/ssh.js
+++ b/src/driver/freenas/ssh.js
@@ -249,7 +249,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
    *
    * @param {*} datasetName
    */
-  async createShare(call, datasetName) {
+  async createShare(callContext, call, datasetName) {
     const driver = this;
     const driverShareType = this.getDriverShareType();
     const execClient = this.getExecClient();
@@ -284,7 +284,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
           FREENAS_NFS_SHARE_PROPERTY_NAME,
         ]);
         properties = properties[datasetName];
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         // create nfs share
         if (
@@ -495,7 +495,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
           FREENAS_SMB_SHARE_PROPERTY_NAME,
         ]);
         properties = properties[datasetName];
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         let smbName;
 
@@ -518,7 +518,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
 
         smbName = smbName.toLowerCase();
 
-        this.ctx.logger.info(
+        callContext.logger.info(
           "FreeNAS creating smb share with name: " + smbName
         );
 
@@ -744,7 +744,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
           FREENAS_ISCSI_TARGETTOEXTENT_ID_PROPERTY_NAME,
         ]);
         properties = properties[datasetName];
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         let basename;
         let iscsiName;
@@ -773,8 +773,8 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
         iscsiName = iscsiName.toLowerCase();
 
         let extentDiskName = "zvol/" + datasetName;
-        let maxZvolNameLength = await driver.getMaxZvolNameLength();
-        driver.ctx.logger.debug("max zvol name length: %s", maxZvolNameLength);
+        let maxZvolNameLength = await driver.getMaxZvolNameLength(callContext);
+        callContext.logger.debug("max zvol name length: %s", maxZvolNameLength);
 
         /**
          * limit is a FreeBSD limitation
@@ -796,7 +796,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
           );
         }
 
-        this.ctx.logger.info(
+        callContext.logger.info(
           "FreeNAS creating iscsi assets with name: " + iscsiName
         );
 
@@ -870,7 +870,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
               );
             }
             basename = response.body.iscsi_basename;
-            this.ctx.logger.verbose("FreeNAS ISCSI BASENAME: " + basename);
+            callContext.logger.verbose("FreeNAS ISCSI BASENAME: " + basename);
             break;
           case 2:
             response = await httpClient.get("/iscsi/global");
@@ -883,7 +883,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
               );
             }
             basename = response.body.basename;
-            this.ctx.logger.verbose("FreeNAS ISCSI BASENAME: " + basename);
+            callContext.logger.verbose("FreeNAS ISCSI BASENAME: " + basename);
             break;
           default:
             throw new GrpcError(
@@ -953,7 +953,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
                 );
               }
 
-              this.ctx.logger.verbose("FreeNAS ISCSI TARGET: %j", target);
+              callContext.logger.verbose("FreeNAS ISCSI TARGET: %j", target);
 
               // set target.id on zvol
               await zb.zfs.set(datasetName, {
@@ -1035,7 +1035,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
                   );
                 }
 
-                this.ctx.logger.verbose(
+                callContext.logger.verbose(
                   "FreeNAS ISCSI TARGET_GROUP: %j",
                   targetGroup
                 );
@@ -1101,7 +1101,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
                 );
               }
 
-              this.ctx.logger.verbose("FreeNAS ISCSI EXTENT: %j", extent);
+              callContext.logger.verbose("FreeNAS ISCSI EXTENT: %j", extent);
 
               await zb.zfs.set(datasetName, {
                 [FREENAS_ISCSI_EXTENT_ID_PROPERTY_NAME]: extent.id,
@@ -1159,7 +1159,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
                   `unknown error creating iscsi targettoextent`
                 );
               }
-              this.ctx.logger.verbose(
+              callContext.logger.verbose(
                 "FreeNAS ISCSI TARGET_TO_EXTENT: %j",
                 targetToExtent
               );
@@ -1285,7 +1285,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
                 }
               }
 
-              this.ctx.logger.verbose("FreeNAS ISCSI TARGET: %j", target);
+              callContext.logger.verbose("FreeNAS ISCSI TARGET: %j", target);
 
               // set target.id on zvol
               await zb.zfs.set(datasetName, {
@@ -1350,7 +1350,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
                 );
               }
 
-              this.ctx.logger.verbose("FreeNAS ISCSI EXTENT: %j", extent);
+              callContext.logger.verbose("FreeNAS ISCSI EXTENT: %j", extent);
 
               await zb.zfs.set(datasetName, {
                 [FREENAS_ISCSI_EXTENT_ID_PROPERTY_NAME]: extent.id,
@@ -1407,7 +1407,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
                   `unknown error creating iscsi targetextent`
                 );
               }
-              this.ctx.logger.verbose(
+              callContext.logger.verbose(
                 "FreeNAS ISCSI TARGET_TO_EXTENT: %j",
                 targetToExtent
               );
@@ -1428,7 +1428,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
 
         // iqn = target
         let iqn = basename + ":" + iscsiName;
-        this.ctx.logger.info("FreeNAS iqn: " + iqn);
+        callContext.logger.info("FreeNAS iqn: " + iqn);
 
         // store this off to make delete process more bullet proof
         await zb.zfs.set(datasetName, {
@@ -1455,7 +1455,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
     }
   }
 
-  async deleteShare(call, datasetName) {
+  async deleteShare(callContext, call, datasetName) {
     const driverShareType = this.getDriverShareType();
     const httpClient = await this.getHttpClient();
     const apiVersion = httpClient.getApiVersion();
@@ -1482,7 +1482,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
           throw err;
         }
         properties = properties[datasetName];
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         shareId = properties[FREENAS_NFS_SHARE_PROPERTY_NAME].value;
 
@@ -1585,7 +1585,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
           throw err;
         }
         properties = properties[datasetName];
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         shareId = properties[FREENAS_SMB_SHARE_PROPERTY_NAME].value;
 
@@ -1697,7 +1697,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
         }
 
         properties = properties[datasetName];
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         let targetId = properties[FREENAS_ISCSI_TARGET_ID_PROPERTY_NAME].value;
         let extentId = properties[FREENAS_ISCSI_EXTENT_ID_PROPERTY_NAME].value;
@@ -1763,7 +1763,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
                     _.get(response, "body.errno") == 14
                   ) {
                     retries++;
-                    this.ctx.logger.debug(
+                    callContext.logger.debug(
                       "target: %s is in use, retry %s shortly",
                       targetId,
                       retries
@@ -1788,7 +1788,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
                     FREENAS_ISCSI_TARGET_ID_PROPERTY_NAME
                   );
                 } else {
-                  this.ctx.logger.debug(
+                  callContext.logger.debug(
                     "not deleting iscsitarget asset as it appears ID %s has been re-used: zfs name - %s, iscsitarget name - %s",
                     targetId,
                     iscsiName,
@@ -1850,7 +1850,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
                     FREENAS_ISCSI_EXTENT_ID_PROPERTY_NAME
                   );
                 } else {
-                  this.ctx.logger.debug(
+                  callContext.logger.debug(
                     "not deleting iscsiextent asset as it appears ID %s has been re-used: zfs name - %s, iscsiextent name - %s",
                     extentId,
                     iscsiName,
@@ -1875,7 +1875,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
     }
   }
 
-  async setFilesystemMode(path, mode) {
+  async setFilesystemMode(callContext, path, mode) {
     const httpClient = await this.getHttpClient();
     const apiVersion = httpClient.getApiVersion();
     const httpApiClient = await this.getTrueNASHttpApiClient();
@@ -1925,7 +1925,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
     }
   }
 
-  async setFilesystemOwnership(path, user = false, group = false) {
+  async setFilesystemOwnership(callContext, path, user = false, group = false) {
     const httpClient = await this.getHttpClient();
     const apiVersion = httpClient.getApiVersion();
     const httpApiClient = await this.getTrueNASHttpApiClient();
@@ -2011,7 +2011,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
     }
   }
 
-  async expandVolume(call, datasetName) {
+  async expandVolume(callContext, call, datasetName) {
     const driverShareType = this.getDriverShareType();
     const execClient = this.getExecClient();
     const httpClient = await this.getHttpClient();
@@ -2029,7 +2029,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
             FREENAS_ISCSI_ASSETS_NAME_PROPERTY_NAME,
           ]);
           properties = properties[datasetName];
-          this.ctx.logger.debug("zfs props data: %j", properties);
+          callContext.logger.debug("zfs props data: %j", properties);
           let iscsiName =
             properties[FREENAS_ISCSI_ASSETS_NAME_PROPERTY_NAME].value;
 
@@ -2063,7 +2063,7 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
               reload = true;
               break;
             case 2:
-              this.ctx.logger.verbose(
+              callContext.logger.verbose(
                 "FreeNAS reloading iscsi daemon using api"
               );
               // POST /service/reload
@@ -2092,11 +2092,11 @@ class FreeNASSshDriver extends ControllerZfsBaseDriver {
         }
 
         if (reload) {
-          if ((await this.getWhoAmI()) != "root") {
+          if ((await this.getWhoAmI(callContext)) != "root") {
             command = (await this.getSudoPath()) + " " + command;
           }
 
-          this.ctx.logger.verbose(
+          callContext.logger.verbose(
             "FreeNAS reloading iscsi daemon: %s",
             command
           );
diff --git a/src/driver/zfs-local-ephemeral-inline/index.js b/src/driver/zfs-local-ephemeral-inline/index.js
index 05c6683..d455805 100644
--- a/src/driver/zfs-local-ephemeral-inline/index.js
+++ b/src/driver/zfs-local-ephemeral-inline/index.js
@@ -168,7 +168,7 @@ class ZfsLocalEphemeralInlineDriver extends CsiBaseDriver {
   assertCapabilities(callContext, capabilities) {
     // hard code this for now
     const driverZfsResourceType = "filesystem";
-    this.ctx.logger.verbose("validating capabilities: %j", capabilities);
+    callContext.logger.verbose("validating capabilities: %j", capabilities);
 
     let message = null;
     //[{"access_mode":{"mode":"SINGLE_NODE_WRITER"},"mount":{"mount_flags":["noatime","_netdev"],"fs_type":"nfs"},"access_type":"mount"}]

From eb2b357fb713aeeb6093b31a94f1ef2a72a9992a Mon Sep 17 00:00:00 2001
From: Danil Uzlov <36223296+d-uzlov@users.noreply.github.com>
Date: Sun, 13 Apr 2025 06:12:50 +0000
Subject: [PATCH 6/8] logs: use context logger in freenas-api drivers

---
 src/driver/freenas/api.js | 94 +++++++++++++++++++--------------------
 1 file changed, 47 insertions(+), 47 deletions(-)

diff --git a/src/driver/freenas/api.js b/src/driver/freenas/api.js
index 1d53bee..27985c6 100644
--- a/src/driver/freenas/api.js
+++ b/src/driver/freenas/api.js
@@ -174,7 +174,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    *
    * @param {*} datasetName
    */
-  async createShare(call, datasetName) {
+  async createShare(callContext, call, datasetName) {
     const driver = this;
     const driverShareType = this.getDriverShareType();
     const httpClient = await this.getHttpClient();
@@ -207,7 +207,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
           "mountpoint",
           FREENAS_NFS_SHARE_PROPERTY_NAME,
         ]);
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         // create nfs share
         if (
@@ -419,7 +419,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
           "mountpoint",
           FREENAS_SMB_SHARE_PROPERTY_NAME,
         ]);
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         let smbName;
 
@@ -442,7 +442,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
 
         smbName = smbName.toLowerCase();
 
-        this.ctx.logger.info(
+        callContext.logger.info(
           "FreeNAS creating smb share with name: " + smbName
         );
 
@@ -668,7 +668,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
           FREENAS_ISCSI_EXTENT_ID_PROPERTY_NAME,
           FREENAS_ISCSI_TARGETTOEXTENT_ID_PROPERTY_NAME,
         ]);
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         let basename;
         let iscsiName;
@@ -698,7 +698,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
 
         let extentDiskName = "zvol/" + datasetName;
         let maxZvolNameLength = await driver.getMaxZvolNameLength();
-        driver.ctx.logger.debug("max zvol name length: %s", maxZvolNameLength);
+        callContext.logger.debug("max zvol name length: %s", maxZvolNameLength);
 
         /**
          * limit is a FreeBSD limitation
@@ -719,7 +719,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
           );
         }
 
-        this.ctx.logger.info(
+        callContext.logger.info(
           "FreeNAS creating iscsi assets with name: " + iscsiName
         );
 
@@ -793,7 +793,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
               );
             }
             basename = response.body.iscsi_basename;
-            this.ctx.logger.verbose("FreeNAS ISCSI BASENAME: " + basename);
+            callContext.logger.verbose("FreeNAS ISCSI BASENAME: " + basename);
             break;
           case 2:
             response = await httpClient.get("/iscsi/global");
@@ -806,7 +806,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
               );
             }
             basename = response.body.basename;
-            this.ctx.logger.verbose("FreeNAS ISCSI BASENAME: " + basename);
+            callContext.logger.verbose("FreeNAS ISCSI BASENAME: " + basename);
             break;
           default:
             throw new GrpcError(
@@ -876,7 +876,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
                 );
               }
 
-              this.ctx.logger.verbose("FreeNAS ISCSI TARGET: %j", target);
+              callContext.logger.verbose("FreeNAS ISCSI TARGET: %j", target);
 
               // set target.id on zvol
               await zb.zfs.set(datasetName, {
@@ -958,7 +958,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
                   );
                 }
 
-                this.ctx.logger.verbose(
+                callContext.logger.verbose(
                   "FreeNAS ISCSI TARGET_GROUP: %j",
                   targetGroup
                 );
@@ -1024,7 +1024,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
                 );
               }
 
-              this.ctx.logger.verbose("FreeNAS ISCSI EXTENT: %j", extent);
+              callContext.logger.verbose("FreeNAS ISCSI EXTENT: %j", extent);
 
               await httpApiClient.DatasetSet(datasetName, {
                 [FREENAS_ISCSI_EXTENT_ID_PROPERTY_NAME]: extent.id,
@@ -1082,7 +1082,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
                   `unknown error creating iscsi targettoextent`
                 );
               }
-              this.ctx.logger.verbose(
+              callContext.logger.verbose(
                 "FreeNAS ISCSI TARGET_TO_EXTENT: %j",
                 targetToExtent
               );
@@ -1208,7 +1208,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
                 }
               }
 
-              this.ctx.logger.verbose("FreeNAS ISCSI TARGET: %j", target);
+              callContext.logger.verbose("FreeNAS ISCSI TARGET: %j", target);
 
               // set target.id on zvol
               await httpApiClient.DatasetSet(datasetName, {
@@ -1273,7 +1273,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
                 );
               }
 
-              this.ctx.logger.verbose("FreeNAS ISCSI EXTENT: %j", extent);
+              callContext.logger.verbose("FreeNAS ISCSI EXTENT: %j", extent);
 
               await httpApiClient.DatasetSet(datasetName, {
                 [FREENAS_ISCSI_EXTENT_ID_PROPERTY_NAME]: extent.id,
@@ -1330,7 +1330,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
                   `unknown error creating iscsi targetextent`
                 );
               }
-              this.ctx.logger.verbose(
+              callContext.logger.verbose(
                 "FreeNAS ISCSI TARGET_TO_EXTENT: %j",
                 targetToExtent
               );
@@ -1351,7 +1351,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
 
         // iqn = target
         let iqn = basename + ":" + iscsiName;
-        this.ctx.logger.info("FreeNAS iqn: " + iqn);
+        callContext.logger.info("FreeNAS iqn: " + iqn);
 
         // store this off to make delete process more bullet proof
         await httpApiClient.DatasetSet(datasetName, {
@@ -1378,7 +1378,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
     }
   }
 
-  async deleteShare(call, datasetName) {
+  async deleteShare(callContext, call, datasetName) {
     const driverShareType = this.getDriverShareType();
     const httpClient = await this.getHttpClient();
     const httpApiClient = await this.getTrueNASHttpApiClient();
@@ -1405,7 +1405,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
           }
           throw err;
         }
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         shareId = properties[FREENAS_NFS_SHARE_PROPERTY_NAME].value;
 
@@ -1507,7 +1507,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
           }
           throw err;
         }
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         shareId = properties[FREENAS_SMB_SHARE_PROPERTY_NAME].value;
 
@@ -1618,7 +1618,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
           throw err;
         }
 
-        this.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         let targetId = properties[FREENAS_ISCSI_TARGET_ID_PROPERTY_NAME].value;
         let extentId = properties[FREENAS_ISCSI_EXTENT_ID_PROPERTY_NAME].value;
@@ -1684,7 +1684,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
                     _.get(response, "body.errno") == 14
                   ) {
                     retries++;
-                    this.ctx.logger.debug(
+                    callContext.logger.debug(
                       "target: %s is in use, retry %s shortly",
                       targetId,
                       retries
@@ -1709,7 +1709,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
                     FREENAS_ISCSI_TARGET_ID_PROPERTY_NAME
                   );
                 } else {
-                  this.ctx.logger.debug(
+                  callContext.logger.debug(
                     "not deleting iscsitarget asset as it appears ID %s has been re-used: zfs name - %s, iscsitarget name - %s",
                     targetId,
                     iscsiName,
@@ -1771,7 +1771,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
                     FREENAS_ISCSI_EXTENT_ID_PROPERTY_NAME
                   );
                 } else {
-                  this.ctx.logger.debug(
+                  callContext.logger.debug(
                     "not deleting iscsiextent asset as it appears ID %s has been re-used: zfs name - %s, iscsiextent name - %s",
                     extentId,
                     iscsiName,
@@ -1809,7 +1809,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
    * @param {*} datasetName
    * @returns
    */
-  async expandVolume(call, datasetName) {
+  async expandVolume(callContext, call, datasetName) {
     // TODO: fix me
     return;
     const driverShareType = this.getDriverShareType();
@@ -1833,7 +1833,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
             command = (await this.getSudoPath()) + " " + command;
           }
 
-          this.ctx.logger.verbose(
+          callContext.logger.verbose(
             "FreeNAS reloading iscsi daemon: %s",
             command
           );
@@ -1887,7 +1887,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
     return volume_status;
   }
 
-  async populateCsiVolumeFromData(row) {
+  async populateCsiVolumeFromData(callContext, row) {
     const driver = this;
     const zb = await this.getZetabyte();
     const driverZfsResourceType = this.getDriverZfsResourceType();
@@ -1901,7 +1901,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
     if (
       !zb.helpers.isPropertyValueSet(row[SHARE_VOLUME_CONTEXT_PROPERTY_NAME])
     ) {
-      driver.ctx.logger.warn(`${row.name} is missing share context`);
+      callContext.logger.warn(`${row.name} is missing share context`);
       return;
     }
 
@@ -2084,7 +2084,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
 
   assertCapabilities(callContext, capabilities) {
     const driverZfsResourceType = this.getDriverZfsResourceType();
-    this.ctx.logger.verbose("validating capabilities: %j", capabilities);
+    callContext.logger.verbose("validating capabilities: %j", capabilities);
 
     let message = null;
     //[{"access_mode":{"mode":"SINGLE_NODE_WRITER"},"mount":{"mount_flags":["noatime","_netdev"],"fs_type":"nfs"},"access_type":"mount"}]
@@ -2403,7 +2403,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
     if (driverZfsResourceType == "volume") {
       let extentDiskName = "zvol/" + datasetName;
       let maxZvolNameLength = await driver.getMaxZvolNameLength();
-      driver.ctx.logger.debug("max zvol name length: %s", maxZvolNameLength);
+      callContext.logger.debug("max zvol name length: %s", maxZvolNameLength);
       if (extentDiskName.length > maxZvolNameLength) {
         throw new GrpcError(
           grpc.status.FAILED_PRECONDITION,
@@ -2495,7 +2495,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
               volume_id;
           }
 
-          driver.ctx.logger.debug("full snapshot name: %s", fullSnapshotName);
+          callContext.logger.debug("full snapshot name: %s", fullSnapshotName);
 
           if (!zb.helpers.isZfsSnapshot(volume_content_source_snapshot_id)) {
             try {
@@ -2656,7 +2656,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
             VOLUME_SOURCE_CLONE_SNAPSHOT_PREFIX +
             volume_id;
 
-          driver.ctx.logger.debug("full snapshot name: %s", fullSnapshotName);
+            callContext.logger.debug("full snapshot name: %s", fullSnapshotName);
 
           // create snapshot
           try {
@@ -2841,7 +2841,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
           VOLUME_CONTENT_SOURCE_TYPE_PROPERTY_NAME,
           VOLUME_CONTENT_SOURCE_ID_PROPERTY_NAME,
         ]);
-        driver.ctx.logger.debug("zfs props data: %j", properties);
+        callContext.logger.debug("zfs props data: %j", properties);
 
         // set mode
         let perms = {
@@ -2957,7 +2957,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
         break;
     }
 
-    volume_context = await this.createShare(call, datasetName);
+    volume_context = await this.createShare(callContext, call, datasetName);
     await httpApiClient.DatasetSet(datasetName, {
       [SHARE_VOLUME_CONTEXT_PROPERTY_NAME]: JSON.stringify(volume_context),
     });
@@ -3045,7 +3045,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
       }
     }
 
-    driver.ctx.logger.debug("dataset properties: %j", properties);
+    callContext.logger.debug("dataset properties: %j", properties);
 
     // deleteStrategy
     const delete_strategy = _.get(
@@ -3059,7 +3059,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
     }
 
     // remove share resources
-    await this.deleteShare(call, datasetName);
+    await this.deleteShare(callContext, call, datasetName);
 
     // remove parent snapshot if appropriate with defer
     if (
@@ -3070,7 +3070,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
         .extractSnapshotName(properties.origin.value)
         .startsWith(VOLUME_SOURCE_CLONE_SNAPSHOT_PREFIX)
     ) {
-      driver.ctx.logger.debug(
+      callContext.logger.debug(
         "removing with defer source snapshot: %s",
         properties.origin.value
       );
@@ -3237,7 +3237,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
       await httpApiClient.DatasetSet(datasetName, properties);
     }
 
-    await this.expandVolume(call, datasetName);
+    await this.expandVolume(callContext, call, datasetName);
 
     return {
       capacity_bytes:
@@ -3358,8 +3358,8 @@ class FreeNASApiDriver extends CsiBaseDriver {
       row[p] = response[p].rawvalue;
     }
 
-    driver.ctx.logger.debug("list volumes result: %j", row);
-    let volume = await driver.populateCsiVolumeFromData(row);
+    callContext.logger.debug("list volumes result: %j", row);
+    let volume = await driver.populateCsiVolumeFromData(callContext, row);
     let status = await driver.getVolumeStatus(datasetName);
 
     let res = { volume };
@@ -3475,7 +3475,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
       }
     }
 
-    driver.ctx.logger.debug("list volumes result: %j", rows);
+    callContext.logger.debug("list volumes result: %j", rows);
 
     entries = [];
     for (let row of rows) {
@@ -3489,7 +3489,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
         ""
       );
 
-      let volume = await driver.populateCsiVolumeFromData(row);
+      let volume = await driver.populateCsiVolumeFromData(callContext, row);
       if (volume) {
         let status = await driver.getVolumeStatus(volume_id);
         entries.push({
@@ -4005,7 +4005,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
       source_volume_id;
     snapshotProperties[MANAGED_PROPERTY_NAME] = "true";
 
-    driver.ctx.logger.verbose("requested snapshot name: %s", name);
+    callContext.logger.verbose("requested snapshot name: %s", name);
 
     let invalid_chars;
     invalid_chars = name.match(/[^a-z0-9_\-:.+]+/gi);
@@ -4022,7 +4022,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
     // https://stackoverflow.com/questions/32106243/regex-to-remove-all-non-alpha-numeric-and-replace-spaces-with/32106277
     name = name.replace(/[^a-z0-9_\-:.+]+/gi, "");
 
-    driver.ctx.logger.verbose("cleansed snapshot name: %s", name);
+    callContext.logger.verbose("cleansed snapshot name: %s", name);
 
     // check for other snapshopts with the same name on other volumes and fail as appropriate
     {
@@ -4107,7 +4107,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
       fullSnapshotName = datasetName + "@" + name;
     }
 
-    driver.ctx.logger.verbose("full snapshot name: %s", fullSnapshotName);
+    callContext.logger.verbose("full snapshot name: %s", fullSnapshotName);
 
     if (detachedSnapshot) {
       tmpSnapshotName =
@@ -4266,7 +4266,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
       );
     }
 
-    driver.ctx.logger.verbose("snapshot properties: %j", properties);
+    callContext.logger.verbose("snapshot properties: %j", properties);
 
     // TODO: properly handle use-case where datasetEnableQuotas is not turned on
     if (driverZfsResourceType == "filesystem") {
@@ -4365,7 +4365,7 @@ class FreeNASApiDriver extends CsiBaseDriver {
 
     const fullSnapshotName = datasetParentName + "/" + snapshot_id;
 
-    driver.ctx.logger.verbose("deleting snapshot: %s", fullSnapshotName);
+    callContext.logger.verbose("deleting snapshot: %s", fullSnapshotName);
 
     if (detachedSnapshot) {
       try {

From 64b4583eed4d59242f02cb05ffb13f67930860fa Mon Sep 17 00:00:00 2001
From: Danil Uzlov <36223296+d-uzlov@users.noreply.github.com>
Date: Mon, 24 Mar 2025 21:42:05 +0000
Subject: [PATCH 7/8] logs: use context logger in client-common driver

---
 src/driver/controller-client-common/index.js | 32 ++++++++++----------
 1 file changed, 16 insertions(+), 16 deletions(-)

diff --git a/src/driver/controller-client-common/index.js b/src/driver/controller-client-common/index.js
index 8621447..2c1a3ae 100644
--- a/src/driver/controller-client-common/index.js
+++ b/src/driver/controller-client-common/index.js
@@ -158,7 +158,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
 
   assertCapabilities(callContext, capabilities) {
     const driver = this;
-    this.ctx.logger.verbose("validating capabilities: %j", capabilities);
+    callContext.logger.verbose("validating capabilities: %j", capabilities);
 
     let message = null;
     let fs_types = driver.getFsTypes();
@@ -661,7 +661,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
                   );
                 }
 
-                driver.ctx.logger.debug(
+                callContext.logger.debug(
                   "controller volume source path: %s",
                   source_path
                 );
@@ -740,7 +740,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
               );
           }
           break;
-        // must be available when adverstising CLONE_VOLUME
+        // must be available when advertising CLONE_VOLUME
         // create snapshot first, then clone
         case "volume":
           source_path = driver.getControllerVolumePath(
@@ -754,7 +754,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
             );
           }
 
-          driver.ctx.logger.debug(
+          callContext.logger.debug(
             "controller volume source path: %s",
             source_path
           );
@@ -770,7 +770,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
 
     // set mode
     if (this.options[config_key].dirPermissionsMode) {
-      driver.ctx.logger.verbose(
+      callContext.logger.verbose(
         "setting dir mode to: %s on dir: %s",
         this.options[config_key].dirPermissionsMode,
         volume_path
@@ -783,14 +783,14 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
       this.options[config_key].dirPermissionsUser ||
       this.options[config_key].dirPermissionsGroup
     ) {
-      driver.ctx.logger.verbose(
+      callContext.logger.verbose(
         "setting ownership to: %s:%s on dir: %s",
         this.options[config_key].dirPermissionsUser,
         this.options[config_key].dirPermissionsGroup,
         volume_path
       );
       if (this.getNodeIsWindows()) {
-        driver.ctx.logger.warn("chown not implemented on windows");
+        callContext.logger.warn("chown not implemented on windows");
       } else {
         await driver.exec("chown", [
           (this.options[config_key].dirPermissionsUser
@@ -1003,7 +1003,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
       );
     }
 
-    driver.ctx.logger.verbose("requested snapshot name: %s", name);
+    callContext.logger.verbose("requested snapshot name: %s", name);
 
     let invalid_chars;
     invalid_chars = name.match(/[^a-z0-9_\-:.+]+/gi);
@@ -1020,7 +1020,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
     // https://stackoverflow.com/questions/32106243/regex-to-remove-all-non-alpha-numeric-and-replace-spaces-with/32106277
     name = name.replace(/[^a-z0-9_\-:.+]+/gi, "");
 
-    driver.ctx.logger.verbose("cleansed snapshot name: %s", name);
+    callContext.logger.verbose("cleansed snapshot name: %s", name);
     const volume_path = driver.getControllerVolumePath(source_volume_id);
     //const volume_path = "/home/thansen/beets/";
     //const volume_path = "/var/lib/docker/";
@@ -1044,11 +1044,11 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
             await driver.cloneDir(volume_path, snapshot_path).finally(() => {
               SNAPSHOTS_CUT_IN_FLIGHT.delete(name);
             });
-            driver.ctx.logger.info(
+            callContext.logger.info(
               `filecopy backup finished: snapshot_id=${snapshot_id}, path=${volume_path}`
             );
           } else {
-            driver.ctx.logger.debug(
+            callContext.logger.debug(
               `filecopy backup already cut: ${snapshot_id}`
             );
           }
@@ -1099,7 +1099,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
           if (response.length > 0) {
             snapshot_exists = true;
             const snapshot = response[response.length - 1];
-            driver.ctx.logger.debug(
+            callContext.logger.debug(
               `restic backup already cut: ${snapshot.id}`
             );
             const stats = await restic.stats([snapshot.id]);
@@ -1136,7 +1136,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
               return message.message_type == "summary";
             });
             snapshot_id = summary.snapshot_id;
-            driver.ctx.logger.info(
+            callContext.logger.info(
               `restic backup finished: snapshot_id=${snapshot_id}, path=${volume_path}, total_duration=${
                 summary.total_duration | 0
               }s`
@@ -1194,7 +1194,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
               );
             }
             snapshot_id = snapshot.id;
-            driver.ctx.logger.info(
+            callContext.logger.info(
               `restic backup successfully applied additional tags: new_snapshot_id=${snapshot_id}, original_snapshot_id=${original_snapshot_id} path=${volume_path}`
             );
           }
@@ -1233,7 +1233,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
           if (response.length > 0) {
             snapshot_exists = true;
             const snapshot = response[response.length - 1];
-            driver.ctx.logger.debug(
+            callContext.logger.debug(
               `kopia snapshot already cut: ${snapshot.id}`
             );
 
@@ -1262,7 +1262,7 @@ class ControllerClientCommonDriver extends CsiBaseDriver {
               1000;
             size_bytes = response.rootEntry.summ.size;
 
-            driver.ctx.logger.info(
+            callContext.logger.info(
               `kopia backup finished: snapshot_id=${snapshot_id}, path=${volume_path}, total_duration=${
                 total_duration | 0
               }s`

From 40412f12b9debf0e1dca45f85324947e4d8f1725 Mon Sep 17 00:00:00 2001
From: Danil Uzlov <36223296+d-uzlov@users.noreply.github.com>
Date: Mon, 24 Mar 2025 21:42:06 +0000
Subject: [PATCH 8/8] logs: use context logger in objectivefs, synology drivers

---
 src/driver/controller-objectivefs/index.js | 2 +-
 src/driver/controller-synology/index.js    | 4 ++--
 2 files changed, 3 insertions(+), 3 deletions(-)

diff --git a/src/driver/controller-objectivefs/index.js b/src/driver/controller-objectivefs/index.js
index d30e4e7..ff725c1 100644
--- a/src/driver/controller-objectivefs/index.js
+++ b/src/driver/controller-objectivefs/index.js
@@ -161,7 +161,7 @@ class ControllerObjectiveFSDriver extends CsiBaseDriver {
 
   assertCapabilities(callContext, capabilities) {
     const driver = this;
-    this.ctx.logger.verbose("validating capabilities: %j", capabilities);
+    callContext.logger.verbose("validating capabilities: %j", capabilities);
 
     let message = null;
     let fs_types = driver.getFsTypes();
diff --git a/src/driver/controller-synology/index.js b/src/driver/controller-synology/index.js
index deb3091..2a0a8b0 100644
--- a/src/driver/controller-synology/index.js
+++ b/src/driver/controller-synology/index.js
@@ -252,7 +252,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
 
   assertCapabilities(callContext, capabilities) {
     const driverResourceType = this.getDriverResourceType();
-    this.ctx.logger.verbose("validating capabilities: %j", capabilities);
+    callContext.logger.verbose("validating capabilities: %j", capabilities);
 
     let message = null;
     //[{"access_mode":{"mode":"SINGLE_NODE_WRITER"},"mount":{"mount_flags":["noatime","_netdev"],"fs_type":"nfs"},"access_type":"mount"}]
@@ -951,7 +951,7 @@ class ControllerSynologyDriver extends CsiBaseDriver {
       );
     }
 
-    driver.ctx.logger.verbose("requested snapshot name: %s", name);
+    callContext.logger.verbose("requested snapshot name: %s", name);
 
     let invalid_chars;
     invalid_chars = name.match(/[^a-z0-9_\-:.+]+/gi);