AG-17519 improve logMessage helper and update tests

Merge in ADGUARD-FILTERS/scriptlets from fix/AG-17519 to release/v1.8 Squashed commit of the following: commit f54bbcc Author: Stanislav A <[email protected]> Date: Wed Dec 28 15:52:35 2022 +0300 tweak prevent-xhr test commit 4060687 Author: Stanislav A <[email protected]> Date: Tue Dec 27 19:54:06 2022 +0300 improve helper tests commit 855ce89 Author: Stanislav A <[email protected]> Date: Tue Dec 27 19:14:57 2022 +0300 fix changelog commit 7054753 Author: Stanislav A <[email protected]> Date: Tue Dec 27 18:48:09 2022 +0300 remove max-len from tests commit f93dc21 Author: Stanislav A <[email protected]> Date: Tue Dec 27 18:42:29 2022 +0300 improve naming commit 21da001 Author: Stanislav A <[email protected]> Date: Tue Dec 27 18:30:38 2022 +0300 update tests commit 0903fb6 Author: Stanislav A <[email protected]> Date: Tue Dec 27 18:10:55 2022 +0300 improve helper and add tests commit 6e3dc40 Author: Stanislav A <[email protected]> Date: Tue Dec 27 17:21:56 2022 +0300 improve naming commit d4aa78e Author: Stanislav A <[email protected]> Date: Tue Dec 27 16:04:39 2022 +0300 update CHANGELOG commit 8342527 Author: Stanislav A <[email protected]> Date: Tue Dec 27 16:00:11 2022 +0300 improve logMessage helper and update tests
AdguardTeam · Dec 28, 2022 · b2624bf · b2624bf
1 parent 1caed03
commit b2624bf
Show file tree

Hide file tree

Showing 23 changed files with 161 additions and 42 deletions.
diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -8,6 +8,7 @@
 ### Changed
 
 - add decimal delay matching for `prevent-setInterval` and `prevent-setTimeout` [#247](https://github.com/AdguardTeam/Scriptlets/issues/247)
+- debug logging to include rule text when available
 
 ### Fixed
 

diff --git a/src/helpers/log-message.js b/src/helpers/log-message.js
@@ -12,8 +12,28 @@
  * @param {boolean} [forced=false] to log message unconditionally
  */
 export const logMessage = (source, message, forced = false) => {
-    if (forced || source.verbose) {
-        // eslint-disable-next-line no-console
-        console.log(`${source.name}: ${message}`);
+    const {
+        name,
+        ruleText,
+        verbose,
+    } = source;
+
+    if (!forced && !verbose) {
+        return;
     }
+
+    let messageStr = `${name}: ${message}`;
+
+    // Extract scriptlet part from rule text
+    if (ruleText) {
+        const RULE_MARKER = '#%#//scriptlet';
+        const markerIdx = ruleText.indexOf(RULE_MARKER);
+        if (markerIdx > -1) {
+            const ruleWithoutDomains = ruleText.slice(markerIdx, ruleText.length);
+            messageStr += `; cannot apply rule: ${ruleWithoutDomains}`;
+        }
+    }
+
+    // eslint-disable-next-line no-console
+    console.log(messageStr);
 };
diff --git a/src/scriptlets/adjust-setInterval.js b/src/scriptlets/adjust-setInterval.js
@@ -71,7 +71,7 @@ export function adjustSetInterval(source, matchCallback, matchDelay, boost) {
         // https://github.com/AdguardTeam/Scriptlets/issues/221
         if (!isValidCallback(callback)) {
             // eslint-disable-next-line max-len
-            const message = `Scriptlet can't be applied because of invalid callback: '${String(callback)}'.`;
+            const message = `Scriptlet can't be applied because of invalid callback: '${String(callback)}'`;
             logMessage(source, message);
         } else if (matchRegexp.test(callback.toString()) && isDelayMatched(matchDelay, delay)) {
             delay *= getBoostMultiplier(boost);

diff --git a/src/scriptlets/adjust-setTimeout.js b/src/scriptlets/adjust-setTimeout.js
@@ -71,7 +71,7 @@ export function adjustSetTimeout(source, matchCallback, matchDelay, boost) {
         // https://github.com/AdguardTeam/Scriptlets/issues/221
         if (!isValidCallback(callback)) {
             // eslint-disable-next-line max-len
-            const message = `Scriptlet can't be applied because of invalid callback: '${String(callback)}'.`;
+            const message = `Scriptlet can't be applied because of invalid callback: '${String(callback)}'`;
             logMessage(source, message);
         } else if (matchRegexp.test(callback.toString()) && isDelayMatched(matchDelay, delay)) {
             delay *= getBoostMultiplier(boost);

diff --git a/src/scriptlets/trusted-replace-fetch-response.js b/src/scriptlets/trusted-replace-fetch-response.js
@@ -88,7 +88,7 @@ export function trustedReplaceFetchResponse(source, pattern = '', replacement =
 
     // Only allow pattern as empty string for logging purposes
     if (pattern === '' && replacement !== '') {
-        logMessage(source, 'Pattern argument should not be empty string.');
+        logMessage(source, 'Pattern argument should not be empty string');
         return;
     }
     const shouldLog = pattern === '' && replacement === '';

diff --git a/src/scriptlets/trusted-set-cookie-reload.js b/src/scriptlets/trusted-set-cookie-reload.js
@@ -72,11 +72,11 @@ import {
 
 export function trustedSetCookieReload(source, name, value, offsetExpiresSec = '', path = '/') {
     if (typeof name === 'undefined') {
-        logMessage(source, 'Cookie name should be specified.');
+        logMessage(source, 'Cookie name should be specified');
         return;
     }
     if (typeof value === 'undefined') {
-        logMessage(source, 'Cookie value should be specified.');
+        logMessage(source, 'Cookie value should be specified');
         return;
     }
 

diff --git a/src/scriptlets/trusted-set-cookie.js b/src/scriptlets/trusted-set-cookie.js
@@ -71,11 +71,11 @@ import {
 
 export function trustedSetCookie(source, name, value, offsetExpiresSec = '', path = '/') {
     if (typeof name === 'undefined') {
-        logMessage(source, 'Cookie name should be specified.');
+        logMessage(source, 'Cookie name should be specified');
         return;
     }
     if (typeof value === 'undefined') {
-        logMessage(source, 'Cookie value should be specified.');
+        logMessage(source, 'Cookie value should be specified');
         return;
     }
 

diff --git a/src/scriptlets/trusted-set-local-storage-item.js b/src/scriptlets/trusted-set-local-storage-item.js
@@ -56,12 +56,12 @@ import {
 
 export function trustedSetLocalStorageItem(source, key, value) {
     if (typeof key === 'undefined') {
-        logMessage(source, 'Item key should be specified.');
+        logMessage(source, 'Item key should be specified');
         return;
     }
 
     if (typeof value === 'undefined') {
-        logMessage(source, 'Item value should be specified.');
+        logMessage(source, 'Item value should be specified');
         return;
     }
 

diff --git a/tests/helpers/index.test.js b/tests/helpers/index.test.js
@@ -4,3 +4,4 @@ import './noop.test';
 import './number-utils.test';
 import './string-utils.test';
 import './object-utils.test';
+import './log-message.test';
diff --git a/tests/helpers/log-message.test.js b/tests/helpers/log-message.test.js
@@ -0,0 +1,83 @@
+/* eslint-disable no-console */
+import {
+    logMessage,
+} from '../../src/helpers';
+
+const { test, module } = QUnit;
+const name = 'scriptlets-redirects helpers';
+const nativeConsole = console.log;
+
+const afterEach = () => {
+    console.log = nativeConsole;
+};
+
+module(name, { afterEach });
+
+const RULE_TEXT = 'example.org#%#//scriptlet(\'set-cookie\', \'name\', \'value\')';
+const SCRIPTLET_NAME = 'set-cookie';
+const MESSAGE = 'arbitrary text message';
+const MESSAGE_EXTENSION = '; cannot apply rule: #%#//scriptlet(\'set-cookie\', \'name\', \'value\')';
+
+test('Logs message conditionally', async (assert) => {
+    // eslint-disable-next-line no-console
+    console.log = function log(input) {
+        if (input.indexOf('trace') > -1) {
+            return;
+        }
+        assert.strictEqual(
+            input,
+            `${SCRIPTLET_NAME}: ${MESSAGE}${MESSAGE_EXTENSION}`,
+            'message logged correctly',
+        );
+    };
+
+    assert.expect(2);
+
+    // Log forced message
+    let forced = true;
+    let source = {
+        name: SCRIPTLET_NAME,
+        ruleText: RULE_TEXT,
+        verbose: false,
+    };
+    logMessage(source, MESSAGE, forced);
+
+    // Log message on verbose
+    forced = false;
+    source = {
+        name: SCRIPTLET_NAME,
+        ruleText: RULE_TEXT,
+        verbose: true,
+    };
+    logMessage(source, MESSAGE, forced);
+
+    // Message should not be logged this time, thus expected 2 asserts
+    forced = false;
+    source = {
+        name: SCRIPTLET_NAME,
+        ruleText: RULE_TEXT,
+        verbose: false,
+    };
+    logMessage(source, MESSAGE, forced);
+});
+
+test('Logs message without ruleText', async (assert) => {
+    // eslint-disable-next-line no-console
+    console.log = function log(input) {
+        if (input.indexOf('trace') > -1) {
+            return;
+        }
+        assert.strictEqual(
+            input,
+            `${SCRIPTLET_NAME}: ${MESSAGE}`,
+            'message logged correctly',
+        );
+    };
+
+    const FORCED = true;
+    const source = {
+        name: SCRIPTLET_NAME,
+        verbose: false,
+    };
+    logMessage(source, MESSAGE, FORCED);
+});
diff --git a/tests/scriptlets/adjust-setInterval.test.js b/tests/scriptlets/adjust-setInterval.test.js
@@ -288,7 +288,7 @@ test('no match -- invalid callback - undefined', (assert) => {
     assert.strictEqual(window.hit, undefined, 'hit should not fire');
     assert.strictEqual(
         loggedMessage,
-        `${name}: Scriptlet can't be applied because of invalid callback: '${String(callback)}'.`, // eslint-disable-line max-len
+        `${name}: Scriptlet can't be applied because of invalid callback: '${String(callback)}'`,
         'console.logged warning ok',
     );
     clearInterval(testInterval);

diff --git a/tests/scriptlets/adjust-setTimeout.test.js b/tests/scriptlets/adjust-setTimeout.test.js
@@ -288,7 +288,7 @@ test('no match -- invalid callback - undefined', (assert) => {
     assert.strictEqual(window.hit, undefined, 'hit should not fire');
     assert.strictEqual(
         loggedMessage,
-        `${name}: Scriptlet can't be applied because of invalid callback: '${String(callback)}'.`, // eslint-disable-line max-len
+        `${name}: Scriptlet can't be applied because of invalid callback: '${String(callback)}'`,
         'console.logged warning ok',
     );
     clearTimeout(testTimeout);

diff --git a/tests/scriptlets/nowebrtc.test.js b/tests/scriptlets/nowebrtc.test.js
@@ -86,8 +86,8 @@ if (!isSupported) {
             if (input.indexOf('trace') > -1) {
                 return;
             }
-            // eslint-disable-next-line max-len
-            const EXPECTED_LOG_STR = `${name}: Document tried to create an RTCPeerConnection: ${TEST_URL_VALUE}`;
+
+            const EXPECTED_LOG_STR = `${name}: Document tried to create an RTCPeerConnection: ${TEST_URL_VALUE};`;
             assert.ok(endsWith(input, EXPECTED_LOG_STR), 'console.hit input');
         };
 

diff --git a/tests/scriptlets/prevent-eval-if.test.js b/tests/scriptlets/prevent-eval-if.test.js
@@ -46,7 +46,7 @@ test('AG prevent-eval-if works', (assert) => {
     const firstActual = evalWrapper(`(function () {return '${agPreventEvalIf}'})()`);
     assert.strictEqual(window.hit, undefined, 'hit function should not fire for not matched function');
     assert.strictEqual(firstActual, agPreventEvalIf, 'result of eval evaluation should exist');
-    // eslint-disable-next-line max-len
+
     const secondActual = evalWrapper(`(function () {const test = 0; return '${agPreventEvalIf}'})()`);
     assert.strictEqual(window.hit, 'FIRED', 'hit function should fire');
     assert.strictEqual(secondActual, undefined, 'result of eval evaluation should be undefined');

diff --git a/tests/scriptlets/prevent-fetch.test.js b/tests/scriptlets/prevent-fetch.test.js
@@ -70,7 +70,6 @@ if (!isSupported) {
             if (input.indexOf('trace') > -1) {
                 return;
             }
-            // eslint-disable-next-line max-len
             const EXPECTED_LOG_STR_START = `${name}: fetch( url:"${INPUT_JSON_PATH}" method:"${TEST_METHOD}"`;
             assert.ok(startsWith(input, EXPECTED_LOG_STR_START), 'console.hit input');
         };

diff --git a/tests/scriptlets/prevent-requestAnimationFrame.test.js b/tests/scriptlets/prevent-requestAnimationFrame.test.js
@@ -62,7 +62,11 @@ test('prevent-requestAnimationFrame: no args -- logging', (assert) => {
     // do test checking after scriptlet's execution end
     setTimeout(() => {
         assert.strictEqual(window.hit, 'FIRED', 'hit fired');
-        assert.strictEqual(loggedMessage, `prevent-requestAnimationFrame: requestAnimationFrame(${testFunction.toString()})`, 'console.hit input');
+        assert.strictEqual(
+            loggedMessage,
+            `prevent-requestAnimationFrame: requestAnimationFrame(${testFunction.toString()})`,
+            'console.hit input',
+        );
         assert.strictEqual(window[logProperty], 'changed', 'property changed');
         clearGlobalProps(logProperty);
         done();

diff --git a/tests/scriptlets/prevent-setInterval.test.js b/tests/scriptlets/prevent-setInterval.test.js
@@ -85,7 +85,6 @@ test('setInterval callback name matching', (assert) => {
     // We need to run our assertion after all timeouts
     setTimeout(() => {
         assert.equal(window.one, 'value', 'Target property not changed');
-        // eslint-disable-next-line max-len
         assert.equal(window.two, 'new value', 'Another property should successfully changed by another timeout');
         assert.strictEqual(window.hit, 'FIRED', 'hit fired');
         done();
@@ -113,7 +112,6 @@ test('code matching', (assert) => {
     // We need to run our assertion after all timeouts
     setTimeout(() => {
         assert.equal(window.one, 'value', 'Target property not changed');
-        // eslint-disable-next-line max-len
         assert.equal(window.two, 'new value', 'Another property should  be successfully changed by another timeout');
         assert.strictEqual(window.hit, 'FIRED', 'hit fired');
         done();

diff --git a/tests/scriptlets/prevent-setTimeout.test.js b/tests/scriptlets/prevent-setTimeout.test.js
@@ -85,7 +85,6 @@ test('setTimeout callback name matching', (assert) => {
     // We need to run our assertion after all timeouts
     nativeSetTimeout(() => {
         assert.equal(window.one, 'value', 'Target property not changed');
-        // eslint-disable-next-line max-len
         assert.equal(window.two, 'new value', 'Another property should successfully changed by another timeout');
         assert.strictEqual(window.hit, 'FIRED', 'hit fired');
         done();
@@ -113,7 +112,6 @@ test('code matching', (assert) => {
     // We need to run our assertion after all timeouts
     nativeSetTimeout(() => {
         assert.equal(window.one, 'value', 'Target property not changed');
-        // eslint-disable-next-line max-len
         assert.equal(window.two, 'new value', 'Another property should  be successfully changed by another timeout');
         assert.strictEqual(window.hit, 'FIRED', 'hit fired');
         done();

diff --git a/tests/scriptlets/prevent-window-open.test.js b/tests/scriptlets/prevent-window-open.test.js
@@ -207,7 +207,6 @@ test('new syntax: log checking - url + args', (assert) => {
         if (input.indexOf('trace') > -1) {
             return;
         }
-        // eslint-disable-next-line max-len
         const EXPECTED_LOG_STR = `${name}: ${testUrl}, ${testWindowName}, ${testWindowFeatures}`;
         assert.strictEqual(input, EXPECTED_LOG_STR, 'console.hit input');
     };

diff --git a/tests/scriptlets/prevent-xhr.test.js b/tests/scriptlets/prevent-xhr.test.js
@@ -129,8 +129,10 @@ if (isSupported) {
         xhr.open(METHOD, URL);
         xhr.onload = () => {
             assert.strictEqual(typeof xhr.responseText, 'string', 'Response text mocked');
-            // eslint-disable-next-line max-len
-            assert.ok(xhr.responseText.length > 20000, `Response text randomized, response length: ${xhr.responseText.length}`);
+            assert.ok(
+                xhr.responseText.length > 20000,
+                `Response text randomized, response length: ${xhr.responseText.length}`,
+            );
             assert.strictEqual(window.hit, 'FIRED', 'hit function fired');
             done();
         };
@@ -151,8 +153,10 @@ if (isSupported) {
         xhr.onload = () => {
             assert.strictEqual(xhr.readyState, 4, 'Response done');
             assert.strictEqual(typeof xhr.responseText, 'string', 'Response text mocked');
-            // eslint-disable-next-line max-len
-            assert.ok(xhr.responseText.length > 20000, `Response text randomized, response length: ${xhr.responseText.length}`);
+            assert.ok(
+                xhr.responseText.length > 20000,
+                `Response text randomized, response length: ${xhr.responseText.length}`,
+            );
             assert.strictEqual(window.hit, 'FIRED', 'hit function fired');
             done();
         };
@@ -173,8 +177,10 @@ if (isSupported) {
         xhr.onload = () => {
             assert.strictEqual(xhr.readyState, 4, 'Response done');
             assert.strictEqual(typeof xhr.responseText, 'string', 'Response text mocked');
-            // eslint-disable-next-line max-len
-            assert.ok(xhr.responseText.length === 100, `Response text randomized, response length: ${xhr.responseText.length}`);
+            assert.ok(
+                xhr.responseText.length === 100,
+                `Response text randomized, response length: ${xhr.responseText.length}`,
+            );
             assert.strictEqual(window.hit, 'FIRED', 'hit function fired');
             done();
         };
@@ -195,8 +201,10 @@ if (isSupported) {
         xhr.onload = () => {
             assert.strictEqual(xhr.readyState, 4, 'Response done');
             assert.strictEqual(typeof xhr.responseText, 'string', 'Response text mocked');
-            // eslint-disable-next-line max-len
-            assert.ok(xhr.responseText.length === 500000, `Response text randomized, response length: ${xhr.responseText.length}`);
+            assert.ok(
+                xhr.responseText.length === 500000,
+                `Response text randomized, response length: ${xhr.responseText.length}`,
+            );
             assert.strictEqual(window.hit, 'FIRED', 'hit function fired');
             done();
         };
@@ -216,7 +224,6 @@ if (isSupported) {
         xhr.open(METHOD, URL);
         xhr.onload = () => {
             assert.strictEqual(typeof xhr.responseText, 'string', 'Response text mocked');
-            // eslint-disable-next-line max-len
             assert.ok(xhr.responseText.length === 0, 'Response text is not randomized');
             assert.strictEqual(window.hit, 'FIRED', 'hit function fired');
             done();
@@ -257,8 +264,10 @@ if (isSupported) {
         xhr.open(METHOD, URL);
         xhr.onload = () => {
             assert.strictEqual(typeof xhr.responseText, 'string', 'Response text mocked');
-            // eslint-disable-next-line max-len
-            assert.ok(xhr.responseText.length >= 100 && xhr.responseText.length <= 300, `Response text randomized, response length: ${xhr.responseText.length}`);
+            assert.ok(
+                xhr.responseText.length >= 100 && xhr.responseText.length <= 300,
+                `Response text randomized, response length: ${xhr.responseText.length}`,
+            );
             assert.strictEqual(window.hit, 'FIRED', 'hit function fired');
             done();
         };
@@ -278,8 +287,10 @@ if (isSupported) {
         xhr.open(METHOD, URL);
         xhr.onload = () => {
             assert.strictEqual(typeof xhr.responseText, 'string', 'Response text mocked');
-            // eslint-disable-next-line max-len
-            assert.ok(xhr.responseText.length >= 10 && xhr.responseText.length <= 20, `Response text randomized, response length: ${xhr.responseText.length}`);
+            assert.ok(
+                xhr.responseText.length >= 10 && xhr.responseText.length <= 20,
+                `Response text randomized, response length: ${xhr.responseText.length}`,
+            );
             assert.strictEqual(window.hit, 'FIRED', 'hit function fired');
             done();
         };
@@ -623,7 +634,7 @@ if (isSupported) {
 
         xhr1.send();
         // use timeout to avoid hit collisions
-        setTimeout(() => xhr2.send(), 1);
+        setTimeout(() => xhr2.send(), 10);
     });
 } else {
     test('unsupported', (assert) => {