parallel.test-tls-socket-close is flaky #49902

anonrig · 2023-09-27T17:05:27Z

Test

parallel.test-tls-socket-close

Platform

No response

Console output

not ok 2868 parallel/test-tls-socket-close
  ---
  duration_ms: 220.38800
  severity: fail
  exitcode: 1
  stack: |-
    node:assert:125
      throw new AssertionError(obj);
      ^
    
    AssertionError [ERR_ASSERTION]: Expected values to be strictly equal:
    
    false !== true
    
        at Immediate._onImmediate (/home/iojs/build/workspace/node-test-commit-linuxone/test/parallel/test-tls-socket-close.js:49:18)
        at process.processImmediate (node:internal/timers:478:21) {
      generatedMessage: true,
      code: 'ERR_ASSERTION',
      actual: false,
      expected: true,
      operator: 'strictEqual'
    }
    
    Node.js v21.0.0-pre
  ...

Build links

https://ci.nodejs.org/job/node-test-commit-linuxone/39972/nodes=rhel8-s390x/console

Additional information

No response

The text was updated successfully, but these errors were encountered:

lpinca · 2023-09-27T18:07:40Z

It seems #49575 did not fully fix it.

joyeecheung · 2023-09-28T01:29:30Z

I wonder if we really need to check the client socket in the immediate, perhaps it's already enough, say, checking it on process exit?

joyeecheung · 2023-09-28T01:32:58Z

Not quite sure what the test was going for, perhaps we could also switch to process.nextTick...

EDIT: nope probably not useful

joyeecheung · 2023-09-28T02:02:31Z

A dumb idea: maybe we can keep checking if the client socket is destroyed in setImmediate, when it's destroyed, log the count of immediates run, assert that the count should be no more then 1, then run a stress test on it to see if it goes beyond one and if it does, what exactly it is. I am fairly certain though that there probably is just no way you can be sure about this count, there's nothing in the API contract for you to tell how long you need to wait after the server socket is destroyed until the client socket is destroyed. So maybe again it's already enough to check on process exit..

lpinca · 2023-09-29T16:50:08Z

Before Joyee's comments I tried to remove setImmediate() and rely on the 'close' events. If the 'close' event is emitted, then socket.destroy is true.

diff --git a/test/parallel/test-tls-socket-close.js b/test/parallel/test-tls-socket-close.js
index 70af760d53..e661da94f0 100644
--- a/test/parallel/test-tls-socket-close.js
+++ b/test/parallel/test-tls-socket-close.js
@@ -6,6 +6,7 @@ if (!common.hasCrypto)
 const assert = require('assert');
 const tls = require('tls');
 const net = require('net');
+const Countdown = require('../common/countdown');
 const fixtures = require('../common/fixtures');
 
 const key = fixtures.readKey('agent2-key.pem');
@@ -27,6 +28,10 @@ const netServer = net.createServer((socket) => {
   connectClient(netServer);
 }));
 
+const countdown = new Countdown(2, () => {
+  netServer.close();
+});
+
 // A client that connects, sends one message, and closes the raw connection:
 function connectClient(server) {
   const clientTlsSocket = tls.connect({
@@ -42,17 +47,12 @@ function connectClient(server) {
 
       netSocket.destroy();
 
-      setImmediate(() => {
-        assert.strictEqual(netSocket.destroyed, true);
-
-        setImmediate(() => {
-          assert.strictEqual(clientTlsSocket.destroyed, true);
-          assert.strictEqual(serverTlsSocket.destroyed, true);
-
-          tlsServer.close();
-          netServer.close();
-        });
-      });
+      clientTlsSocket.on('close', dec);
+      serverTlsSocket.on('close', dec);
     }));
   }));
 }
+
+function dec() {
+  countdown.dec();
+}

However the 'close' event is not emitted by serverTlsSocket. I'm not sure if this is intentional. Older versions of Node.js have the same behavior but I find it surprising.

Ensure that the `'close'` event is emitted on a `TLSSocket` when it is created from an existing raw `net.Socket` and the raw socket is not closed cleanly (destroyed). Fixes: nodejs#49902

Ensure that the `'close'` event is emitted on a `TLSSocket` when it is created from an existing raw `net.Socket` and the raw socket is not closed cleanly (destroyed). Refs: nodejs#49902 (comment) Fixes: nodejs#49902

Ensure that the `'close'` event is emitted on a `TLSSocket` when it is created from an existing raw `net.Socket` and the raw socket is not closed cleanly (destroyed). Refs: nodejs@048e0bec5147 Refs: nodejs#49902 (comment) Fixes: nodejs#49902

Ensure that the `'close'` event is emitted on a `TLSSocket` when it is created from an existing raw `net.Socket` and the raw socket is not closed cleanly (destroyed). Refs: 048e0bec5147 Refs: #49902 (comment) Fixes: #49902 PR-URL: #49980 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com>

Ensure that the `'close'` event is emitted on a `TLSSocket` when it is created from an existing raw `net.Socket` and the raw socket is not closed cleanly (destroyed). Refs: nodejs@048e0bec5147 Refs: nodejs#49902 (comment) Fixes: nodejs#49902 PR-URL: nodejs#49980 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com>

Ensure that the `'close'` event is emitted on a `TLSSocket` when it is created from an existing raw `net.Socket` and the raw socket is not closed cleanly (destroyed). Refs: 048e0bec5147 Refs: #49902 (comment) Fixes: #49902 PR-URL: #49980 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com>

Ensure that the `'close'` event is emitted on a `TLSSocket` when it is created from an existing raw `net.Socket` and the raw socket is not closed cleanly (destroyed). Refs: nodejs@048e0bec5147 Refs: nodejs#49902 (comment) Fixes: nodejs#49902 PR-URL: nodejs#49980 Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com> Reviewed-By: Joyee Cheung <joyeec9h3@gmail.com>

targos · 2024-05-15T08:04:29Z

Still flaky:

https://ci.nodejs.org/job/node-test-commit-linux-containered/43411/nodes=ubuntu2204_sharedlibs_smallicu_x64/console

09:11:31 not ok 2947 parallel/test-tls-socket-close
09:11:31   ---
09:11:31   duration_ms: 383.31800
09:11:31   severity: fail
09:11:31   exitcode: 1
09:11:31   stack: |-
09:11:31     node:assert:408
09:11:31         throw err;
09:11:31         ^
09:11:31     
09:11:31     AssertionError [ERR_ASSERTION]: The expression evaluated to a falsy value:
09:11:31     
09:11:31       assert(serverTlsSocket)
09:11:31     
09:11:31         at Socket.<anonymous> (/home/iojs/build/workspace/node-test-commit-linux-containered/test/parallel/test-tls-socket-close.js:51:7)
09:11:31         at Socket.<anonymous> (/home/iojs/build/workspace/node-test-commit-linux-containered/test/common/index.js:470:15)
09:11:31         at Object.onceWrapper (node:events:634:28)
09:11:31         at Socket.emit (node:events:520:28)
09:11:31         at Socket._onTimeout (node:net:590:8)
09:11:31         at listOnTimeout (node:internal/timers:573:17)
09:11:31         at process.processTimers (node:internal/timers:514:7) {
09:11:31       generatedMessage: true,
09:11:31       code: 'ERR_ASSERTION',
09:11:31       actual: undefined,
09:11:31       expected: true,
09:11:31       operator: '=='
09:11:31     }
09:11:31     
09:11:31     Node.js v22.2.0
09:11:31   ...

Fixes: nodejs#49902

Fixes: #49902 PR-URL: #53019 Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>

Fixes: nodejs#49902 PR-URL: nodejs#53019 Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>

anonrig added the flaky-test Issues and PRs related to the tests with unstable failures on the CI. label Sep 27, 2023

lpinca mentioned this issue Sep 30, 2023

tls: handle cases where the raw socket is destroyed #49980

Merged

nodejs-github-bot closed this as completed in #49980 Oct 4, 2023

anonrig reopened this Oct 18, 2023

anonrig closed this as completed Oct 18, 2023

targos reopened this May 15, 2024

lpinca added a commit to lpinca/node that referenced this issue May 16, 2024

test: remove timers from test-tls-socket-close

c679e6f

Fixes: nodejs#49902

lpinca mentioned this issue May 16, 2024

test: remove timers from test-tls-socket-close #53019

Merged

lpinca added a commit to lpinca/node that referenced this issue May 16, 2024

test: remove timers from test-tls-socket-close

5581681

Fixes: nodejs#49902

nodejs-github-bot closed this as completed in #53019 May 23, 2024

nodejs-github-bot pushed a commit that referenced this issue May 23, 2024

test: remove timers from test-tls-socket-close

a81d833

Fixes: #49902 PR-URL: #53019 Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>

targos pushed a commit that referenced this issue Jun 1, 2024

test: remove timers from test-tls-socket-close

3ce7a9a

Fixes: #49902 PR-URL: #53019 Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>

lukins-cz pushed a commit to lukins-cz/OS-Aplet-node that referenced this issue Jun 1, 2024

test: remove timers from test-tls-socket-close

d476ff6

Fixes: nodejs#49902 PR-URL: nodejs#53019 Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

parallel.test-tls-socket-close is flaky #49902

parallel.test-tls-socket-close is flaky #49902

anonrig commented Sep 27, 2023

lpinca commented Sep 27, 2023

joyeecheung commented Sep 28, 2023

joyeecheung commented Sep 28, 2023 •

edited

joyeecheung commented Sep 28, 2023 •

edited

lpinca commented Sep 29, 2023

targos commented May 15, 2024

parallel.test-tls-socket-close is flaky #49902

parallel.test-tls-socket-close is flaky #49902

Comments

anonrig commented Sep 27, 2023

Test

Platform

Console output

Build links

Additional information

lpinca commented Sep 27, 2023

joyeecheung commented Sep 28, 2023

joyeecheung commented Sep 28, 2023 • edited

joyeecheung commented Sep 28, 2023 • edited

lpinca commented Sep 29, 2023

targos commented May 15, 2024

joyeecheung commented Sep 28, 2023 •

edited

joyeecheung commented Sep 28, 2023 •

edited