|
| 1 | +"use strict"; |
| 2 | + |
| 3 | +const { assert } = require("chai"); |
| 4 | +const Client = require("../../../lib/client"); |
| 5 | +const helper = require("../../test-helper"); |
| 6 | +const { types } = require("../../../main"); |
| 7 | +const { logLevels } = types; |
| 8 | + |
| 9 | +/** |
| 10 | + * Create a client with logging enabled at the given level, attach a log |
| 11 | + * listener that pushes events into the returned array, and connect. |
| 12 | + * |
| 13 | + * @param {string} [level] - Log level (defaults to "trace"). |
| 14 | + * @param {function} [filter] - Optional filter for the log listener; receives |
| 15 | + * (level, target, message, furtherInfo) and should return true to keep. |
| 16 | + * @returns {{ client: Client, events: Array }} |
| 17 | + */ |
| 18 | +async function createConnectedClientWithLogs(level = logLevels.trace, filter) { |
| 19 | + const events = []; |
| 20 | + const client = new Client( |
| 21 | + Object.assign({}, helper.baseOptions, { logLevel: level }), |
| 22 | + ); |
| 23 | + |
| 24 | + client.on("log", (level, target, message, furtherInfo) => { |
| 25 | + const event = { level, target, message, furtherInfo }; |
| 26 | + if (!filter || filter(level, target, message, furtherInfo)) { |
| 27 | + events.push(event); |
| 28 | + } |
| 29 | + }); |
| 30 | + |
| 31 | + await client.connect(); |
| 32 | + return { client, events }; |
| 33 | +} |
| 34 | + |
| 35 | +describe("Client logging @SERVER_API", function () { |
| 36 | + this.timeout(30000); |
| 37 | + |
| 38 | + // Start a single-node cluster shared by all tests in this file. |
| 39 | + const _setup = helper.setup(1); |
| 40 | + |
| 41 | + describe("during connect", function () { |
| 42 | + it("should emit Rust driver log events when logLevel is set", async function () { |
| 43 | + // In this test, we assume rust will generate this specific log event. |
| 44 | + // But when we filter for we guarantee we get the logs from the driver, not some random other place. |
| 45 | + // So if at some point rust driver decides to change / rename this log below check would need to be updated. |
| 46 | + const { client, events } = await createConnectedClientWithLogs( |
| 47 | + logLevels.trace, |
| 48 | + (_level, target) => |
| 49 | + target && target.includes("scylla::network::connection"), |
| 50 | + ); |
| 51 | + |
| 52 | + assert.isAbove( |
| 53 | + events.length, |
| 54 | + 0, |
| 55 | + "expected at least one log event from the Rust driver during connect", |
| 56 | + ); |
| 57 | + |
| 58 | + // Every Rust event must have a valid structure |
| 59 | + for (const event of events) { |
| 60 | + assert.isString(event.level); |
| 61 | + assert.include( |
| 62 | + [ |
| 63 | + logLevels.trace, |
| 64 | + logLevels.debug, |
| 65 | + logLevels.info, |
| 66 | + logLevels.warning, |
| 67 | + logLevels.error, |
| 68 | + ], |
| 69 | + event.level, |
| 70 | + `unexpected log level: ${event.level}`, |
| 71 | + ); |
| 72 | + assert.isString(event.target); |
| 73 | + assert.isString(event.message); |
| 74 | + } |
| 75 | + |
| 76 | + await client.shutdown(); |
| 77 | + }); |
| 78 | + |
| 79 | + it("should still emit JS-side log events alongside Rust events", async function () { |
| 80 | + const { client, events } = await createConnectedClientWithLogs( |
| 81 | + logLevels.info, |
| 82 | + (_level, target) => target === "Client", |
| 83 | + ); |
| 84 | + |
| 85 | + const connectLog = events.find((e) => |
| 86 | + e.message.includes("Connecting to cluster"), |
| 87 | + ); |
| 88 | + assert.isDefined( |
| 89 | + connectLog, |
| 90 | + "expected the JS-side 'Connecting to cluster' log event", |
| 91 | + ); |
| 92 | + assert.strictEqual(connectLog.level, logLevels.info); |
| 93 | + |
| 94 | + await client.shutdown(); |
| 95 | + }); |
| 96 | + }); |
| 97 | + |
| 98 | + describe("logging isolation across client lifecycles", function () { |
| 99 | + it("should disable logs for shut down client", async function () { |
| 100 | + const { client: firstClient, events: firstClientEvents } = |
| 101 | + await createConnectedClientWithLogs(); |
| 102 | + |
| 103 | + assert.isAbove( |
| 104 | + firstClientEvents.length, |
| 105 | + 0, |
| 106 | + "first client should have received log events during connect", |
| 107 | + ); |
| 108 | + |
| 109 | + await firstClient.shutdown(); |
| 110 | + // Allow any in-flight NonBlocking ThreadsafeFunction calls to drain |
| 111 | + // Repeating it will heuristically reduce chance of leaked events. |
| 112 | + for (let i = 0; i < 20; i++) { |
| 113 | + await new Promise((resolve) => setTimeout(resolve, 0)); |
| 114 | + } |
| 115 | + |
| 116 | + // Reset received events. Any event received after this point is either |
| 117 | + // - leaked event |
| 118 | + // - event from the second client, that is received due to a bug in the shutdown logic |
| 119 | + // First case while acceptable, will fail this test |
| 120 | + // Second case is what we want to test against here. |
| 121 | + firstClientEvents.length = 0; |
| 122 | + |
| 123 | + const { client: secondClient } = |
| 124 | + await createConnectedClientWithLogs(); |
| 125 | + |
| 126 | + assert.strictEqual( |
| 127 | + firstClientEvents.length, |
| 128 | + 0, |
| 129 | + "first client should NOT receive any log events after shutdown", |
| 130 | + ); |
| 131 | + |
| 132 | + await secondClient.shutdown(); |
| 133 | + }); |
| 134 | + |
| 135 | + it("should disable logs for finalized client", async function () { |
| 136 | + if (!global.gc) { |
| 137 | + console.warn( |
| 138 | + "Test skipped: To run this test add --expose-gc flag", |
| 139 | + ); |
| 140 | + return; |
| 141 | + } |
| 142 | + |
| 143 | + const firstClientEvents = []; |
| 144 | + |
| 145 | + let firstClient = new Client( |
| 146 | + Object.assign({}, helper.baseOptions, { |
| 147 | + logLevel: logLevels.trace, |
| 148 | + }), |
| 149 | + ); |
| 150 | + |
| 151 | + firstClient.on("log", (level, target, message, furtherInfo) => { |
| 152 | + firstClientEvents.push(level); |
| 153 | + }); |
| 154 | + |
| 155 | + await firstClient.connect(); |
| 156 | + |
| 157 | + // Release the client reference to allow GC |
| 158 | + // eslint-disable-next-line no-useless-assignment |
| 159 | + firstClient = undefined; |
| 160 | + |
| 161 | + for (let i = 0; i < 20; i++) { |
| 162 | + global.gc(); |
| 163 | + await new Promise((resolve) => setTimeout(resolve, 0)); |
| 164 | + } |
| 165 | + |
| 166 | + // Reset — any event after this point indicates a leak |
| 167 | + firstClientEvents.length = 0; |
| 168 | + |
| 169 | + const { client: secondClient } = |
| 170 | + await createConnectedClientWithLogs(); |
| 171 | + |
| 172 | + assert.strictEqual( |
| 173 | + firstClientEvents.length, |
| 174 | + 0, |
| 175 | + "first client should NOT receive any log events after being GC'd", |
| 176 | + ); |
| 177 | + |
| 178 | + await secondClient.shutdown(); |
| 179 | + }); |
| 180 | + }); |
| 181 | +}); |
0 commit comments