search

atsign-foundation / noports

Connect to any device with no external listening ports open
https://noports.com
BSD 3-Clause "New" or "Revised" License
263 stars 15 forks source link

fix: (c sshnpd) non-threaded csshnpd memory leaks #1152

Closed JeremyTubongbanua closed 1 week ago

JeremyTubongbanua commented 2 weeks ago

- What I did

- How to verify it Leak summary ran locally from valgrind as of commit https://github.com/atsign-foundation/noports/pull/1152/commits/e41e61bc78df114de09af0d0bd46fa8d661ffe38

This is the leak summary after conducting the steps:

  1. Start C Daemon SSHNPD
  2. Connect with a v5.3.0 SSHNP client to the C Daemon, and successfully establish SSH connection
  3. Ctrl + D (logout) on client SSHNP
  4. Ctrl + C (SIGINT) on daemon process

Thread leak summary:

==61254== LEAK SUMMARY:
==61254==    definitely lost: 0 bytes in 0 blocks
==61254==    indirectly lost: 0 bytes in 0 blocks
==61254==      possibly lost: 272 bytes in 1 blocks
==61254==    still reachable: 121,622 bytes in 201 blocks
==61254==         suppressed: 585 bytes in 5 blocks

There are no more main process leaks

XavierChanth commented 1 week ago

So it seems that in addition to the username and ping puts, something is wrong with the ping notification too, that is why the e2e test is failing.

XavierChanth commented 1 week ago

But trunk is building okay, unless the fix is on trunk already?

JeremyTubongbanua commented 1 week ago

Error

out:         [DEBG] 2024-06-21 22:30:21.065184 | sshnpd | Received message of type: 1
out:         [DEBG] 2024-06-21 22:30:21.065186 | sshnpd | Notification value received: {"payload":{"direct":true,"sessionId":"a65d57ed-5efa-486d-a16f-2bc37719d5ca","host":"85.239.53.170","port":46087,"authenticateToRvd":true,"clientNonce":"2024-06-21T22:30:19.436915","rvdNonce":"2024-06-21T22:30:21.307026","encryptRvdTraffic":true,"clientEphemeralPK":"MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAsZEDMJtIrbEyPIwaBNmLJgwo4FgdMEcmmBMlYglKX2PyLSxb+pa51GTvnUE1dplVeO1ZjN4a+CmF4a9tEIT+DPHoY5hUHX07HDjrK66QFMqkckuamFkBrsUaiUO6d13Q3zCLbgnCJ3Ti2z81ER+7IIhCyLdfcOEItXVH0VonkYDHgt0cy5MCwT29LLD7cuaP43KW91uIWWG8D6VkjwAj13CsGD5XPxAGSPGA6920iZbVDmET1CYeypaw0elXCTwC0U6oFcBAtc2SHmiXpwCjC+rp7VGzuD92Ct+uhq55bCZCLtRBrTwGy+8uZGktBGqSaHVPkaUTG3+dUOY83hU6PwIDAQAB","clientEphemeralPKType":"rsa2048"},"signature":"CiiXLq5LjVl9zsLdoOifXGC3kONbxpwJJJKGu8uaOphNyhkTEMYOgeS8NfUvDndKHw4OMDRsp64I/sAooco8yZK2Gl5LzBd0zzyGwdko9G8VgHK/mqvqNOlqaVZBwq86/H2dHoBRTiFnjAzMsO5aiXMVVbH9ZZh1ad+pRHWvjWipAo43++vvglszuxfVXfFsYKhFtnas2DLtKygxuADxkIS6X25SDtyIxk2C3DZ1ZAgyJnDnuX1HeQEe5pAt48KRAREO3lWAdy7JIWuYzZ+PSLdnoXacHbZy/ppVwO/2MLirRGrsHSCeB40i6DIPLg7NYnSdlfl7wFIR8v6ZkS37Rw==","hashingAlgo":"sha256","signingAlgo":"rsa2048"}
out:         [DEBG] 2024-06-21 22:30:21.065190 | sshnpd | Executing handle_ssh_request
out:         [DEBG] 2024-06-21 22:30:21.065289 | connection |   SENT: "noop:0"
out:         [DEBG] 2024-06-21 22:30:21.097937 | connection |   RECV: "data:ok"
out:         [DEBG] 2024-06-21 22:30:21.097984 | connection |   SENT: "plookup:bypassCache:true:all:publickey@apricoteventual"
out:         [DEBG] 2024-06-21 22:30:21.387035 | connection |   RECV: "data:{"data":"MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAq27MNre6KG1yMmI1EwCdkjbZfnxwCAQ5DsWpgM5QUE1dBWNwwn8jy6kFkHe0QuTnbKhD1+GcqljX8v+LoBEYF9zNc0bCh9QPqHGs5Y5fNzlmaZ8jXp+5grtWnjbs3JpH1Vm4iuE9PMu5CGc2RfNxZdyYuvXu5xeJ/351jcNiV491h5zL8e05pV4ufetpgn5AEoq7jnx9TzZLu8NpOT+KLXEic87wpeoCTZjqOdAAfLpDIlkPFJlLrrNrR2dus23aZu1bW1EcaMULp82BvRaXe+JK/Co41usWlbU0qHvfgA7W/ZCB93Ag2TvcTlYtgx/kDTA8CDy7JcL0KXmpIuXsYQIDAQAB","metaData":{"createdBy":"@apricoteventual","updatedBy":"@apricoteventual","createdAt":"2023-10-27 11:01:25.914Z","updatedAt":"2024-02-09 15:07:11.054Z","status":"active","version":4,"ttl":86400000,"isBinary":false,"isEncrypted":false},"key":"public:publickey@apricoteventual"}"
out:         [DEBG] 2024-06-21 22:30:21.387327 | SSH_REQUEST | verify_envelope_signature (success)
out:         [DEBG] 2024-06-21 22:30:21.403541 | RUN SRV | Starting srv with command: srv -h ���*�U -p 46087 --local-port 22 --local-host localhost --rv-auth --rv-e2ee
out:         [INFO] 2024-06-21 22:30:21.403818 | srv - run | Configuring encrypter/decrypter for srv
out:         [INFO] 2024-06-21 22:30:21.403836 | srv - run | Starting socket to socket srv
out:         [INFO] 2024-06-21 22:30:21.403837 | srv - run | Initializing connection for side a
out:         [INFO] 2024-06-21 22:30:21.403839 | srv - side | Doing tcp connect to localhost:22
out:         [INFO] 2024-06-21 22:30:21.407381 | srv - run | Initializing connection for side b
out:         [INFO] 2024-06-21 22:30:21.407386 | srv - side | Doing tcp connect to ���*�U:46087
out:         [ERRO] 2024-06-21 22:30:21.407416 | srv - side | Failed: tcp connect - unknown host
out:         [ERRO] 2024-06-21 22:30:21.407418 | srv - run | Failed to initialize connection for side b
out:         [INFO] 2024-06-21 22:30:21.407634 | sshnpd | Exited main loop
out:         [DEBG] 2024-06-21 22:30:21.065289 | connection |   SENT: "noop:0"
out:         [DEBG] 2024-06-21 22:30:21.097937 | connection |   RECV: "data:ok"
out:         [DEBG] 2024-06-21 22:30:21.097984 | connection |   SENT: "plookup:bypassCache:true:all:publickey@apricoteventual"
out:         [DEBG] 2024-06-21 22:30:21.387035 | connection |   RECV: "data:{"data":"MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAq27MNre6KG1yMmI1EwCdkjbZfnxwCAQ5DsWpgM5QUE1dBWNwwn8jy6kFkHe0QuTnbKhD1+GcqljX8v+LoBEYF9zNc0bCh9QPqHGs5Y5fNzlmaZ8jXp+5grtWnjbs3JpH1Vm4iuE9PMu5CGc2RfNxZdyYuvXu5xeJ/351jcNiV491h5zL8e05pV4ufetpgn5AEoq7jnx9TzZLu8NpOT+KLXEic87wpeoCTZjqOdAAfLpDIlkPFJlLrrNrR2dus23aZu1bW1EcaMULp82BvRaXe+JK/Co41usWlbU0qHvfgA7W/ZCB93Ag2TvcTlYtgx/kDTA8CDy7JcL0KXmpIuXsYQIDAQAB","metaData":{"createdBy":"@apricoteventual","updatedBy":"@apricoteventual","createdAt":"2023-10-27 11:01:25.914Z","updatedAt":"2024-02-09 15:07:11.054Z","status":"active","version":4,"ttl":86400000,"isBinary":false,"isEncrypted":false},"key":"public:publickey@apricoteventual"}"
out:         [DEBG] 2024-06-21 22:30:21.387327 | SSH_REQUEST | verify_envelope_signature (success)
out:         [DEBG] 2024-06-21 22:30:21.418039 | connection |   SENT: "noop:0"
out:         [DEBG] 2024-06-21 22:30:21.450495 | connection |   RECV: "data:ok"
out:         [DEBG] 2024-06-21 22:30:21.450558 | connection |   SENT: "llookup:shared_key.apricoteventual@combinedbelgian"
out:         [DEBG] 2024-06-21 22:30:21.483744 | connection |   RECV: "data:U2ByE62hi8aLbQIB4R6TvzHUAIBqF5moNFZ8uSlBGrulmoSVPTlFkt/EadUIlB/obnpjeRJuMk1cfD+rHX0/GLUI/DeE4Tfh0lpCWY2xCyy4jMCtgXVo4suw3MFlVG5rqtWJ3lvqWofNDXLl3defzh43xSz6CV+uij+lgMeqMMIMW+nd0qMtpiTE2/FCJcyJ9Y6+bLWrKtn6WVq4adWoS7gZvYf6X/dTFkytqIiB1JJ/pcoUylIQo+cQSKdjb4NZFenOUsgapMx3nPZUhPLD/hU0ssQBCmVkU6G8ekOdG7SsQGoWJ/Y0uN+VNf+lT9ki4wAW1eRp0kEkPdQwQWhVNA=="
out:         [DEBG] 2024-06-21 22:30:21.493945 | connection |   SENT: "noop:0"
out:         [DEBG] 2024-06-21 22:30:21.526741 | connection |   RECV: "data:ok"
out:         [DEBG] 2024-06-21 22:30:21.526872 | connection |   SENT: "notify:update:messageType:key:priority:low:strategy:all:ttln:86400000:ttl:10000:isEncrypted:true:ivNonce:WSR+tEYSQUu1oFoS1HrljQ==:@apricoteventual:a65d57ed-5efa-486d-a16f-2bc37719d5ca.c0bf8a35ccf.sshnp@combinedbelgian:Dfb0ENNNH2E2RT5k5Wz3V8eWwjPO8nYdeBlFSq7cy2QLhXMIIu+dXFDZJBf8ap2rOa5+VddD82MGsYRHksa/J+6JUTZjSLtLp2K2MHojvbouKqCnMN1s+rBvXqpqUFWDa9i70VQXrVtjq/OUh9LLOx8JFni3X7dwDtmaPsF0i6nUAdY9nSTh0sD30rSbwb4DbZOJ7p8DioQPcrnq7QXxFDGQPjy9/PcHo//KnlZG8TrrDkMiYj+6PTe1gBlEM++0bmauVAmJvqV1D8gXa8GChDD6qv27S5yuF7m7r7F2r+xSpO6X0s2gEIBdOC91WrYwl0UiNcamb46IB0CKj3vpvo9OJnD06Rjm3/RzF1kuwH5DN6l4wIDkHPh6q02V+7yhStfpbwld9f9CcZr9qi4D2ZlTVXUJaxZGvnzCZxMBNV2zV2z/MDBFRkmYXRg8ibCiBBtljX6NysU5NyvWRWkKNru/a9sOBf4wEaMk+DpLy++mcxK5zqhPNRXTOwQJ0Z2uOAg6MtQFyZPAMysAvXR+47uQZAYkgIMGhlMO9p30JJtzpFXdMMkkona867+u0rhaQgkjpoBi4udgOIXWlFGusmUf5se93gtmwrwAdVEPra9kNVsBKIquQEZcf2Azy5xTQNIZ7VZ/P6MsPJ4Fx6RrAVAgT8Dkb++p8HRl22kHPA9dSgarWAVwZYORXZe62X1NaVKbooOjqrj51h47E2L6jjdkCE3uO6bKXQFxPbs86eDi7GTFWon0cWfP/Kg8Sh0q98c5hZKMO26SivXrlaDAirwQm9KdBwtn8891rgg2V7qoT8Ky3j/vOJwd+IAd6laHYRpzyLEEmIqyzHIh33DMEyw0HWbBgEd6haxv+wVW0qZgfRR3kS1/TcnodFClkCbr4qaMLD0IjpJolytCRhCNwhcszcUbjtnZwt8tZEPBhhusVKRAanWnSMF3h/Q6PKYj3a3tr122J3feCSMYVuqS+LB/JMjc6z4XA642dokvFA54tUUk61BduDH1/a2+feSy26Gez/avJdQFivjIysn8gjrnRO85+n/feIDvcWZDo494nQHCmnRwPpUaGcApL7ZWAwHg5YnCZM9vZUGfws4DAk5Oqm0BdeGTo4KA/bTxvv6Qkc9y9X2HKS/CJ6Mf7y/8Q7VOcpGDcMFAN0M1pAUniqsrngrkDhZ1yRSJBrKhBrBfv5WGhyse869jbQlFqXXvU3Xc+fQLf9wlPKFmwydFJMlu8uRNGx9m3oxzrJFiXwjpxAyk4DhHpWkjtEOrXGb+d2ZjlDFXj69iD9ehEejhFNu/QRR6VSoZTqjwI+jsllv7xhstcmwkPm4nyxObsOU0AxHZx23bZZjR0dqRo5JEGca+Y7aj3E6chV/MWqlw8txLkLixyx+SYFTLdYdd0YkrixhCdM/TMzftvxrDW+atbxejR5jdYVAC6aNa6zvut0vi28mfqwnCoyHYy9vpke+yuj240GG2IxwADahrtvF5kv8YrJp9CvBOUhDyIvJmeyi1gzdI4ufflNrwRNGijLo+vU0bao/6My5trHlVMYI124IvIlEc6IFslnBYe+CKms+z7Jv0kkdCK2Elqt5eevl5FCvZuOYEgzcc5/nMn2T2jm4f3dpVURyozSA+u4Az3bifree(): double free detected in tcache 2
out: 2024-06-21 22:30:39.109 |     WARN :     Exit status was 124; will retry in 3 seconds
out: 2024-06-21 22:30:42.112 |     Running test script ... 
out:     test execution's stdout: 
out:         2024-06-21 22:30:42.131 | Executing sshnp.expect with sshnpCommand /home/ubuntu/noports/tests/e2e_all/runtime/c0bf8a35/binaries/dart.branch/sshnp -f @apricoteventual -d c0bf8a35ccf -i /home/ubuntu/.ssh/e2e_all.c0bf8a35  -t @combinedbelgian -h @rv_am -u ubuntu  --root-domain root.atsign.org -s  --ssh-client dart 
out:         spawn /home/ubuntu/noports/tests/e2e_all/runtime/c0bf8a35/binaries/dart.branch/sshnp -f @apricoteventual -d c0bf8a35ccf -i /home/ubuntu/.ssh/e2e_all.c0bf8a35 -t @combinedbelgian -h @rv_am -u ubuntu --root-domain root.atsign.org -s --ssh-client dart
out:     test execution's stderr: 
out:     daemon log fragment: 
out: 2024-06-21 22:31:02.127 |     WARN :     Exit status was 124; will retry in 3 seconds
out: 2024-06-21 22:31:05.131 |     Running test script ... 
out:     test execution's stdout: 
out:         2024-06-21 22:31:05.148 | Executing sshnp.expect with sshnpCommand /home/ubuntu/noports/tests/e2e_all/runtime/c0bf8a35/binaries/dart.branch/sshnp -f @apricoteventual -d c0bf8a35ccf -i /home/ubuntu/.ssh/e2e_all.c0bf8a35  -t @combinedbelgian -h @rv_am -u ubuntu  --root-domain root.atsign.org -s  --ssh-client dart 
out:         spawn /home/ubuntu/noports/tests/e2e_all/runtime/c0bf8a35/binaries/dart.branch/sshnp -f @apricoteventual -d c0bf8a35ccf -i /home/ubuntu/.ssh/e2e_all.c0bf8a35 -t @combinedbelgian -h @rv_am -u ubuntu --root-domain root.atsign.org -s --ssh-client dart
out:     test execution's stderr: 
out:     daemon log fragment: 
out: 2024-06-21 22:31:25.143 |     WARN :     Exit status was 124; will retry in 3 seconds
out: 2024-06-21 22:31:28.146 |     Running test script ... 
out:     test execution's stdout: 
out:         2024-06-21 22:31:28.165 | Executing sshnp.expect with sshnpCommand /home/ubuntu/noports/tests/e2e_all/runtime/c0bf8a35/binaries/dart.branch/sshnp -f @apricoteventual -d c0bf8a35ccf -i /home/ubuntu/.ssh/e2e_all.c0bf8a35  -t @combinedbelgian -h @rv_am -u ubuntu  --root-domain root.atsign.org -s  --ssh-client dart 
out:         spawn /home/ubuntu/noports/tests/e2e_all/runtime/c0bf8a35/binaries/dart.branch/sshnp -f @apricoteventual -d c0bf8a35ccf -i /home/ubuntu/.ssh/e2e_all.c0bf8a35 -t @combinedbelgian -h @rv_am -u ubuntu --root-domain root.atsign.org -s --ssh-client dart
out:     test execution's stderr: 
out:     daemon log fragment: 
out: 2024-06-21 22:31:48.159 |     WARN :     Exit status was 124; will retry in 3 seconds
out: 2024-06-21 22:31:51.163 |     Running test script ... 
out:     test execution's stdout: 
out:         2024-06-21 22:31:51.183 | Executing sshnp.expect with sshnpCommand /home/ubuntu/noports/tests/e2e_all/runtime/c0bf8a35/binaries/dart.branch/sshnp -f @apricoteventual -d c0bf8a35ccf -i /home/ubuntu/.ssh/e2e_all.c0bf8a35  -t @combinedbelgian -h @rv_am -u ubuntu  --root-domain root.atsign.org -s  --ssh-client dart 
out:         spawn /home/ubuntu/noports/tests/e2e_all/runtime/c0bf8a35/binaries/dart.branch/sshnp -f @apricoteventual -d c0bf8a35ccf -i /home/ubuntu/.ssh/e2e_all.c0bf8a35 -t @combinedbelgian -h @rv_am -u ubuntu --root-domain root.atsign.org -s --ssh-client dart
out:     test execution's stderr: 
out:     daemon log fragment: 
out: 2024-06-21 22:32:11.174 |     ERROR:     Failed after 5 attempts
JeremyTubongbanua commented 1 week ago

This is the leak summary of the thread and main process that is in trunk right now.

==67743== LEAK SUMMARY:
==67743==    definitely lost: 1,628 bytes in 10 blocks
==67743==    indirectly lost: 2,110 bytes in 42 blocks
==67743==      possibly lost: 272 bytes in 1 blocks
==67743==    still reachable: 121,845 bytes in 202 blocks
==67743==         suppressed: 0 bytes in 0 blocks
==67682== LEAK SUMMARY:
==67682==    definitely lost: 1,037 bytes in 4 blocks
==67682==    indirectly lost: 2,110 bytes in 42 blocks
==67682==      possibly lost: 0 bytes in 0 blocks
==67682==    still reachable: 223 bytes in 1 blocks
==67682==         suppressed: 0 bytes in 0 blocks