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

Critical issue with 5.3.0 release #1138

Closed cconstab closed 2 weeks ago

cconstab commented 2 weeks ago

Describe the bug

Set up new server using Ubuntu Studio 24..04 LTS using 5.3.0 and unable to connect to sshnpd even using 5.3.0 client.

Steps to reproduce

  1. Set up ubuntu Studio
  2. Then install openssh/sshnpd
  3. And then trued to connect
  4. Fails

This is what I see in the logs...

INFO|2024-06-17 22:04:49.528939|SrvImplExec|SrvImplExec.run(): executing /home/kryz/.local/bin/srv -h 85.239.53
.170 -p 44859 --local-port 22 --local-host localhost --rv-auth --rv-e2ee
INFO|2024-06-17 22:04:49.535389|SrvImplExec|rv stderr | INFO|2024-06-17 22:04:49.535164| SrvImplDart |New SrvImplDart - loca
lPort 22
INFO|2024-06-17 22:04:49.600433|SrvImplExec|rv stderr | INFO|2024-06-17 22:04:49.600202| SrvImplDart |_runDaemonSideSingle a
uthenticating socketB to rvd
INFO|2024-06-17 22:04:49.600480|SrvImplExec|rv stderr | rv started successfully
INFO|2024-06-17 22:04:49.701639| sshnpd |Started rv - pid is 5453
SEVERE|2024-06-17 22:04:49.703210| sshnpd |startDirectSsh failed with unexpected error : ProcessException: No such file or d
irectory
  Command: ssh-keygen -t ed25519 -a 100 -f ephemeral_6c9541f1-ce5b-4a95-b36a-1f395432e431 -q -N

I moved back to 5.2.0 release and things work fine.. The above command seems to be missing the "" after the -N and perhaps that is why it is failing..

Expected behavior

This should not fail..

&& This should be caught in E2E tests ?

Very odd ..

Screenshots

No response

Smartphones

Were you using an atApplication when the bug was found?

sshnp

Additional context

No response

cpswan commented 2 weeks ago

@cconstab what is your sshnp command line?

cconstab commented 2 weeks ago

Just regular commands

Changed to 5.2.0 worked first time

Made sure bin in PATH etc etc

-N without "" will error ssh-keygen

cpswan commented 2 weeks ago

I'm going to test the 5.4.0 pre release and see if we have the same problem there.

cpswan commented 2 weeks ago

I've replicated the problem with 5.4.0:

sshnpd logs:

Jun 18 08:48:42 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:42.430420| sshnpd |Received: ping
Jun 18 08:48:42 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:42.430469| sshnpd |ping received from @cpswan ( ping )
Jun 18 08:48:42 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:42.430483| sshnpd |ping received from @cpswan notification id : 987222a9-141e-4368-a241-f27449e849aa
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:44.068338| sshnpd |Received: ssh_request
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:44.068391| sshnpd |ssh_request received from @cpswan ( {"payload":{"direct":true,"sessionId":"b3cf9296-1f6e-4638-97f4-cee0a559609a","host":"85.239.63.180","port":33127,"authenticateToRvd":true,"clientNonce":"2024-06-18T09:48:41.331275","rvdNonce":"2024-06-18T08:42:06.888544","encryptRvdTraffic":true,"clientEphemeralPK":"MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAjbKM34rXvnYl8XocgDIzpKi82/UgOoNHQ4lHiQ8h1WpEiRKJ0+P1YxJDJhhpGZfaXejWNr7vfW7I+iq4UYCklE/wr1SAiYFd6zsnWs773KeHCBnyd1AM73stWYZiu5pajpgmnCnVNNrrsCwfQAf0ZVdfBzmV2nGoerFJENOoKU8p70biXX4IHTqNMItLVaktAg+EF06hfAipuDwefBokYPhhDMkay7k0jBr2dW3uR238d/PVt9ZPsLlAgnCmSDrO+UIeDEVBEgvGq2MxdVoTuB7fZHVUqqJdNmJLCcM25ZAoLvhGfQMNr8OglI6z9MNyWEriKGdxMpyhk5z/SZJzkwIDAQAB","clientEphemeralPKType":"rsa2048"},"signature":"pM3wQrSjlZbmBQVs6ipfHUtHLaSUe8EQ/G8aBT4faPRcTvRR80Dd3tHNku/V2L+hkqbfFMkFDv666chcEhyuTZY8Mp6QP10XkTO1sb6KyjKsDaCSt0Bel0Xxe9U7r3LJBoR31uYMAWF1hulbtNmCOvprS62jH+vvSdmB8XbWv/85rs0lgrMXRzt6ud/6KmQAOjOgJwIqQEqzzg4bPe17qP8XR0AWtZRdo+HECQysvX8nab8ZA5vi1Rpl93PgpJ2HEI6q/teH1mP50aC8vwku0Dtb7LVVIO+KUIM/xUsX640XBvLC5cHv5/sI2LqgVk451KZzkCrdLry67Gvj+0RDRA==","hashingAlgo":"sha256","signingAlgo":"rsa2048"} )
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:44.235376| sshnpd |Signing Verification Result: ResultType: bool, Result: true, SigningMetadata: {HashingAlgo: sha256, SigningAlgo: rsa2048, SignatureTimestamp: 2024-06-18 08:48:44.234851Z}
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:44.235418| sshnpd |svr.result is a bool
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:44.235429| sshnpd |svr.result is true
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:44.235447| sshnpd |Setting up ports for direct ssh session using openssh (openssh) from: @cpswan session: b3cf9296-1f6e-4638-97f4-cee0a559609a
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:44.241548|SrvImplExec|SrvImplExec.run(): executing /usr/local/bin/srv -h 85.239.63.180 -p 33127 --local-port 22 --local-host localhost --rv-auth --rv-e2ee
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:44.254474|SrvImplExec|rv stderr | INFO|2024-06-18 08:48:44.253490| SrvImplDart |New SrvImplDart - localPort 22
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:44.263714|SrvImplExec|rv stderr | INFO|2024-06-18 08:48:44.263360| SrvImplDart |_runDaemonSideSingle authenticating socketB to rvd
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:44.263760|SrvImplExec|rv stderr | rv started successfully
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: INFO|2024-06-18 08:48:44.364358| sshnpd |Started rv - pid is 1469
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]: SEVERE|2024-06-18 08:48:44.366320| sshnpd |startDirectSsh failed with unexpected error : ProcessException: No such file or directory
Jun 18 08:48:44 ubuntu2404-test5 sshnpd[1426]:   Command: ssh-keygen -t ed25519 -a 100 -f ephemeral_b3cf9296-1f6e-4638-97f4-cee0a559609a -q -N

My sshnp command line:

./sshnp/sshnp -t @bareindoornetball -f @cpswan --device ubuntu2404test5 -u ubuntu -h @rv_eu -l 5679 -v

sshnp verbose output:

INFO|2024-06-18 09:48:41.331306|Sshnp|Initializing SshnpLocalSshKeyHandler
INFO|2024-06-18 09:48:41.331366|Sshnp|Initializing SshnpCore
INFO|2024-06-18 09:48:41.331404| SshnpdChannel |Starting monitor for notifications with regex: "b3cf9296-1f6e-4638-97f4-cee0a559609a.ubuntu2404test5.sshnp@bareindoornetball"
INFO|2024-06-18 09:48:41.331440| SshnpdChannel |Subscribing to notifications with regex: "b3cf9296-1f6e-4638-97f4-cee0a559609a.ubuntu2404test5.sshnp@bareindoornetball"
INFO|2024-06-18 09:48:41.331610| SshnpdChannel |Subscribing to notifications with regex: "heartbeat.ubuntu2404test5.sshnp"
INFO|2024-06-18 09:48:41.331652| SshnpdChannel |Sending ping to sshnpd
INFO|2024-06-18 09:48:41.331886| SshnpdChannel |Skipped sharing public key with sshnpd: sendSshPublicKey=false
INFO|2024-06-18 09:48:41.331928| SrvdChannel |Subscribing to notifications with regex: "b3cf9296-1f6e-4638-97f4-cee0a559609a.sshrvd@"
INFO|2024-06-18 09:48:41.331966| SrvdChannel |Started listening for srvd response
INFO|2024-06-18 09:48:41.332019| SrvdChannel |Sending notification to srvd with key @rv_eu:ubuntu2404test5.request_ports.sshrvd@cpswan and value {"sessionId":"b3cf9296-1f6e-4638-97f4-cee0a559609a","atSignA":"@cpswan","atSignB":"@bareindoornetball","authenticateSocketA":true,"authenticateSocketB":true,"clientNonce":"2024-06-18T09:48:41.331275"}
INFO|2024-06-18 09:48:41.756672|AbstractAtKeyEncryption (@cpswan)|Encrypted shared symmetric key for @cpswan not found in local storage
INFO|2024-06-18 09:48:41.756735|AbstractAtKeyEncryption (@cpswan)|Deleting @rv_eu:shared_key@cpswan from LocalSecondary
INFO|2024-06-18 09:48:41.757058|AbstractAtKeyEncryption (@cpswan)|Encrypted shared symmetric key for @cpswan not found in local storage
INFO|2024-06-18 09:48:41.757101|AbstractAtKeyEncryption (@cpswan)|Deleting @bareindoornetball:shared_key@cpswan from LocalSecondary
INFO|2024-06-18 09:48:41.757310|AbstractAtKeyEncryption (@cpswan)|Fetching shared symmetric key for @cpswan from atServer
INFO|2024-06-18 09:48:41.757595|AbstractAtKeyEncryption (@cpswan)|Fetching shared symmetric key for @cpswan from atServer
INFO|2024-06-18 09:48:42.522824|AbstractAtKeyEncryption (@cpswan)|Retrieved my encrypted copy of shared symmetric key for @rv_eu from atServer - saving to local storage
INFO|2024-06-18 09:48:42.527505|AbstractAtKeyEncryption (@cpswan)|'Their' copy of shared symmetric key for @rv_eu not found in local storage - will check atServer
INFO|2024-06-18 09:48:42.636833|AbstractAtKeyEncryption (@cpswan)|Retrieved my encrypted copy of shared symmetric key for @bareindoornetball from atServer - saving to local storage
INFO|2024-06-18 09:48:42.641152|AbstractAtKeyEncryption (@cpswan)|'Their' copy of shared symmetric key for @bareindoornetball not found in local storage - will check atServer
INFO|2024-06-18 09:48:42.756799|AbstractAtKeyEncryption (@cpswan)|Found 'their' copy of shared symmetric key for @rv_eu in atServer - saving to local storage
INFO|2024-06-18 09:48:42.875800|AbstractAtKeyEncryption (@cpswan)|Found 'their' copy of shared symmetric key for @bareindoornetball in atServer - saving to local storage
INFO|2024-06-18 09:48:44.271090| SrvdChannel |Received from srvd: 85.239.63.180,38101,33127,2024-06-18T08:42:06.888544
INFO|2024-06-18 09:48:44.271157| SrvdChannel |Received from srvd: rvdHost:clientPort:daemonPort 85.239.63.180:38101:33127 rvdNonce: 2024-06-18T08:42:06.888544
INFO|2024-06-18 09:48:44.271195| SrvdChannel |Daemon will connect to: 85.239.63.180:33127
INFO|2024-06-18 09:48:44.509915| SshnpdChannel |Received ping response from @bareindoornetball : @cpswan:heartbeat.ubuntu2404test5.sshnp@bareindoornetball : {"devicename":"ubuntu2404test5","version":"5.4.0","corePackageVersion":"6.1.0","supportedFeatures":{"srAuth":true,"srE2ee":true,"acceptsPublicKeys":true,"supportsPortChoice":true},"allowedServices":["localhost:22","localhost:3389"]}
INFO|2024-06-18 09:48:44.510048| SshnpdChannel |Completing the future
INFO|2024-06-18 09:48:44.518765|Sshnp|Sending session request to the device daemon
INFO|2024-06-18 09:48:45.917197| SshnpdChannel |Received b3cf9296-1f6e-4638-97f4-cee0a559609a.ubuntu2404test5.sshnp@bareindoornetball notification
SHOUT|2024-06-18 09:48:45.917250| SshnpdChannel |invalid daemon response: Failed to start up the daemon side of the srv socket tunnel : ProcessException: No such file or directory
  Command: ssh-keygen -t ed25519 -a 100 -f ephemeral_b3cf9296-1f6e-4638-97f4-cee0a559609a -q -N
INFO|2024-06-18 09:48:46.048807| SshnpdChannel |sshnpdAck: SshnpdAck.acknowledgedWithErrors

Error : No response from the device daemon

Stack Trace: #0      SshnpOpensshLocalImpl.run (package:noports_core/src/sshnp/impl/sshnp_openssh_local_impl.dart:88)
<asynchronous suspension>
#1      main.<anonymous closure> (file:///home/runner/work/noports/noports/packages/dart/sshnoports/bin/sshnp.dart:188)
<asynchronous suspension>
#2      main (file:///home/runner/work/noports/noports/packages/dart/sshnoports/bin/sshnp.dart:96)
<asynchronous suspension>

@gkc @XavierChanth looks like we've somehow dropped the vital "", and that it hasn't been caught by the present test suite.

cpswan commented 2 weeks ago

This seems to be the line in the code - https://github.com/atsign-foundation/noports/blob/6e53afbab9b50b492ba7792e4db5c63b856c2c32/packages/dart/noports_core/lib/src/common/at_ssh_key_util/local_ssh_key_util.dart#L113

But it hasn't changed in 8m. I wonder if there's a compiler change which has turned the '' into nothing?

gkc commented 2 weeks ago

I'm wondering about this output ProcessException: No such file or directory ... I would have expected a different output as when I run ssh-keygen manually as shown above ssh-keygen: option requires an argument -- N

Is it possible that ssh-keygen is not installed by default on ubuntu studio 24.04 LTS?

cconstab commented 2 weeks ago

Its installed for sure as 5.2.0 works fine

gkc commented 2 weeks ago

So WEIRD

gkc commented 2 weeks ago

@cconstab and/or @cpswan: on your ubuntu machine, does an ~/.sshnp directory exist? (I'm presuming yes, but just double-checking)

cconstab commented 2 weeks ago

Good question!

cconstab commented 2 weeks ago

So moved back to 5.3.0 to find out and now it works yay.. Let me delete the dir and see if the same error pops up

cconstab commented 2 weeks ago

Yup! 5.2.0 creates the dir if missing and 5.3.0 does not it would seem!

Yup confirmed..

Need to bring back the create dir in 5.3.0 and above..

(Yay)

gkc commented 2 weeks ago

That is pretty bonkers. I don't think there have been any changes wrt creating directories

gkc commented 2 weeks ago

I'll make a fix first and then see if I can figure out what has changed

cpswan commented 2 weeks ago

I just went back to this morning's 5.4.0 testbed and mkdir .sshnp in my $HOME directory fixed it.

gkc commented 2 weeks ago

Again just double-checking but if the $HOME/.sshnp directory doesn't exist then the 5.2.0 sshnpd binary creates it?

gkc commented 2 weeks ago

https://github.com/atsign-foundation/noports/pull/1139 has a fix which will always ensure the directory exists

cconstab commented 2 weeks ago

Again just double-checking but if the $HOME/.sshnp directory doesn't exist then the 5.2.0 sshnpd binary creates it?

Yes confirmed with testing

gkc commented 2 weeks ago

OK #1139 fixes this; I'm going to spend a little while trying to figure out what has changed which caused this.

gkc commented 2 weeks ago

I know what happened ... before this PR, the daemon's storage was being created under ~/.sshnp, thus that directory was always present when required.