Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

oasis Error: could not connect to sbot #6

Closed
christianbundy opened this issue Jul 26, 2019 · 13 comments
Closed

oasis Error: could not connect to sbot #6

christianbundy opened this issue Jul 26, 2019 · 13 comments
Assignees
Labels
bug Something isn't working
Milestone

Comments

@christianbundy
Copy link
Member

Seems like this only happens the first time you start the server?

  oasis Listening on http://localhost:3000/ +0ms
  oasis Initial connection attempt failed +0ms
  oasis Starting Scuttlebutt server +0ms
ssb-friends: stream legacy api used
  oasis Error: could not connect to sbot
  oasis     at /home/christianbundy/.config/yarn/global/node_modules/ssb-client/client.js:70:23
  oasis     at next (/home/christianbundy/.config/yarn/global/node_modules/multiserver/compose.js:24:14)
  oasis     at /home/christianbundy/.config/yarn/global/node_modules/multiserver/compose.js:34:9
  oasis     at _cb (/home/christianbundy/.config/yarn/global/node_modules/multiserver/plugins/shs.js:28:20)
  oasis     at /home/christianbundy/.config/yarn/global/node_modules/secret-handshake/protocol.js:118:22
  oasis     at /home/christianbundy/.config/yarn/global/node_modules/pull-handshake/index.js:10:5
  oasis     at /home/christianbundy/.config/yarn/global/node_modules/pull-handshake/index.js:23:13
  oasis     at callback (/home/christianbundy/.config/yarn/global/node_modules/pull-pushable/index.js:81:7)
  oasis     at drain (/home/christianbundy/.config/yarn/global/node_modules/pull-pushable/index.js:68:39)
  oasis   Error: shs.client: server hung up when we sent hello (phase 3).
  oasis Possibly we dailed a wrong number, or the server does not wish to talk to us.
  oasis     at abort (/home/christianbundy/.config/yarn/global/node_modules/secret-handshake/protocol.js:37:45)
  oasis     at Object.cb (/home/christianbundy/.config/yarn/global/node_modules/secret-handshake/protocol.js:52:26)
  oasis     at drain (/home/christianbundy/.config/yarn/global/node_modules/pull-reader/index.js:43:23)
  oasis   Error: stream ended with:64 but wanted:80
  oasis     at drain (/home/christianbundy/.config/yarn/global/node_modules/pull-reader/index.js:43:26)
  oasis     at /home/christianbundy/.config/yarn/global/node_modules/pull-reader/index.js:63:18
  oasis     at /home/christianbundy/.config/yarn/global/node_modules/pull-reader/index.js:20:7
  oasis     at drain (/home/christianbundy/.config/yarn/global/node_modules/stream-to-pull-stream/index.js:126:18)
  oasis     at Socket.<anonymous> (/home/christianbundy/.config/yarn/global/node_modules/stream-to-pull-stream/index.js:147:5)
  oasis     at Socket.emit (events.js:203:15)
  oasis     at TCP._handle.close (net.js:606:12) +6s
  oasis Retrying connection to own server +3s

  TypeError: Cannot read property 'read' of undefined
      at Promise.all.messages.map (/home/christianbundy/.config/yarn/global/node_modules/@fraction/oasis/src/pages/models/post.js:27:59)
      at Array.map (<anonymous>)
      at transform (/home/christianbundy/.config/yarn/global/node_modules/@fraction/oasis/src/pages/models/post.js:10:69)
      at pull.collect (/home/christianbundy/.config/yarn/global/node_modules/@fraction/oasis/src/pages/models/post.js:188:19)
      at /home/christianbundy/.config/yarn/global/node_modules/pull-stream/sinks/reduce.js:10:5
      at /home/christianbundy/.config/yarn/global/node_modules/pull-stream/sinks/drain.js:20:24
      at PacketStreamSubstream.weird.read (/home/christianbundy/.config/yarn/global/node_modules/muxrpc/pull-weird.js:33:7)
      at PacketStream._onstream (/home/christianbundy/.config/yarn/global/node_modules/packet-stream/index.js:200:12)
      at PacketStream.write (/home/christianbundy/.config/yarn/global/node_modules/packet-stream/index.js:135:41)
      at /home/christianbundy/.config/yarn/global/node_modules/muxrpc/pull-weird.js:56:15


  TypeError: Cannot read property 'read' of undefined
      at Promise.all.messages.map (/home/christianbundy/.config/yarn/global/node_modules/@fraction/oasis/src/pages/models/post.js:27:59)
      at Array.map (<anonymous>)
      at transform (/home/christianbundy/.config/yarn/global/node_modules/@fraction/oasis/src/pages/models/post.js:10:69)
      at pull.collect (/home/christianbundy/.config/yarn/global/node_modules/@fraction/oasis/src/pages/models/post.js:188:19)
      at /home/christianbundy/.config/yarn/global/node_modules/pull-stream/sinks/reduce.js:10:5
      at /home/christianbundy/.config/yarn/global/node_modules/pull-stream/sinks/drain.js:20:24
      at PacketStreamSubstream.weird.read (/home/christianbundy/.config/yarn/global/node_modules/muxrpc/pull-weird.js:33:7)
      at PacketStream._onstream (/home/christianbundy/.config/yarn/global/node_modules/packet-stream/index.js:200:12)
      at PacketStream.write (/home/christianbundy/.config/yarn/global/node_modules/packet-stream/index.js:135:41)
      at /home/christianbundy/.config/yarn/global/node_modules/muxrpc/pull-weird.js:56:15
@christianbundy
Copy link
Member Author

Looks like this might happen when indexes are behind.

@khimaros
Copy link

I'm seeing the same error as above consistently with a pre-launched ssb-server.

Any known workaround?

This is with oasis and ssb-server installed via npm install.

There are no additional plugins enabled in my .ssb/config.

@christianbundy
Copy link
Member Author

@khimaros

I think this is actually just happening when your indexes are behind. Could you run ssb-server status in another tab? The progress and sync keys are the ones you're looking for, when it's up-to-date it should look like:

{
  "progress": {
    "indexes": {
      "start": 707179111,
      "current": 707179111,
      "target": 707179111
    }
  },
  "sync": {
    "since": 707179111,
    "plugins": {
      "last": 707179111,
      "keys": 707179111,
      "clock": 707179111,
      "time": 707179111,
      "feed": 707179111,
      "backlinks--oaWWDs8g": 707179111,
      "private--oaWWDs8g": 707179111,
      "query": 707179111,
      "search": 707179111,
      "tags": 707179111,
      "patchwork-subscriptions": 707179111,
      "patchwork-channels": 707179111,
      "patchwork-contacts": 707179111
    },
    "sync": true
  },
}

@khimaros
Copy link

Thank you for your help. This is a ssb-server with a very small number of follows. Index seems to be fully up to date:

{
  "progress": {
    "indexes": {
      "start": 14535,
      "current": 14535,
      "target": 14535
    }
  },
  "sync": {
    "since": 14535,
    "plugins": {
      "last": 14535,
      "keys": 14535,
      "clock": 14535,
      "time": 14535,
      "feed": 14535,
      "contacts2": 14535,
      "query": 14535,
      "links2": 14535,
      "backlinks-9O_u9-zjR": 14535
    },
    "sync": true
  },
  "gossip": {},
  "ooo": {}
}

Upon closer reading of this issue, I realize I may be encountering a different problem. The error I am seeing is not on startup, but rather when I hit any endpoint except /status:

2019-08-13T00:12:17.303928137Z 2019-08-13T00:12:17.303Z koa-router GET /
2019-08-13T00:12:17.438732254Z 2019-08-13T00:12:17.438Z oasis:model-post transforming %ExpI<elided>
2019-08-13T00:12:17.438921539Z 2019-08-13T00:12:17.438Z oasis:model-post transforming %/gHW<elided>
2019-08-13T00:12:17.439167016Z 2019-08-13T00:12:17.438Z oasis:model-post transforming %r92/<elided>
2019-08-13T00:12:17.439281364Z 2019-08-13T00:12:17.439Z oasis:model-post transforming %Gavf<elided>
2019-08-13T00:12:17.439524190Z 2019-08-13T00:12:17.439Z oasis:model-post transforming %XTxv<elided>
2019-08-13T00:12:17.442729528Z 
2019-08-13T00:12:17.442852390Z   TypeError: Cannot read property 'read' of undefined
2019-08-13T00:12:17.442873479Z       at Promise.all.messages.map (/srv/export/node_modules/@fraction/oasis/src/pages/models/post.js:28:59)
2019-08-13T00:12:17.442883593Z       at Array.map (<anonymous>)
2019-08-13T00:12:17.442892838Z       at transform (/srv/export/node_modules/@fraction/oasis/src/pages/models/post.js:11:69)
2019-08-13T00:12:17.442902348Z       at pull.collect (/srv/export/node_modules/@fraction/oasis/src/pages/models/post.js:224:19)
2019-08-13T00:12:17.442911120Z       at /srv/export/node_modules/pull-stream/sinks/reduce.js:10:5
2019-08-13T00:12:17.442919966Z       at /srv/export/node_modules/pull-stream/sinks/drain.js:20:24
2019-08-13T00:12:17.442927721Z       at PacketStreamSubstream.weird.read (/srv/export/node_modules/muxrpc/pull-weird.js:33:7)
2019-08-13T00:12:17.442951519Z       at PacketStream._onstream (/srv/export/node_modules/packet-stream/index.js:200:12)
2019-08-13T00:12:17.442960956Z       at PacketStream.write (/srv/export/node_modules/packet-stream/index.js:135:41)
2019-08-13T00:12:17.442969363Z       at /srv/export/node_modules/muxrpc/pull-weird.js:56:15

The keys mentioned are private-box messages of the form:

{
  "key": "%ExpI<elided>",
  "value": {
    "previous": "%eJlD<elided>",
    "author": "@TXRu<elided>",
    "sequence": 6,
    "timestamp": 1556246549084,
    "hash": "sha256",
    "content": {
      "text": "<elided>",
      "type": "post",
      "root": "%/gHW<elided>",
      "mentions": []
    },
    "signature": "<elided>"
  },
  "timestamp": 1556246550191
}
{
  "key": "%/gHW<elided>",
  "value": {
    "previous": "%r92/<elided>",
    "author": "@Z87k<elided>",
    "sequence": 7,
    "timestamp": 1556246286171,
    "hash": "sha256",
    "content": {
      "text": "<elided>",
      "type": "post",
      "mentions": []
    },
    "signature": "<elided>"
  },
  "timestamp": 1556246286929
}
{
  "key": "%r92/<elided>",
  "value": {
    "previous": "%Gavf<elided>",
    "author": "@Z87k<elided>",
    "sequence": 6,
    "timestamp": 1556246247428,
    "hash": "sha256",
    "content": {
      "text": "<elided>",
      "type": "post",
      "root": "%XTxv<elided>",
      "mentions": []
    },
    "signature": "<elided>"
  },
  "timestamp": 1556246248190
}
{
  "key": "%Gavf<elided>",
  "value": {
    "previous": "%T1kc<elided>",
    "author": "@Z87k<elided>",
    "sequence": 5,
    "timestamp": 1556246226062,
    "hash": "sha256",
    "content": {
      "text": "<elided>",
      "type": "post",
      "mentions": []
    },
    "signature": "<elided>"
  },
  "timestamp": 1556246226836
}

{
  "key": "%XTxv<elided>",
  "value": {
    "previous": "%WLjE<elided>",
    "author": "@TXRu<elided>",
    "sequence": 4,
    "timestamp": 1556245935669,
    "hash": "sha256",
    "content": {
      "text": "<elided>",
      "type": "post",
      "mentions": []
    },
    "signature": "<elided>"
  },
  "timestamp": 1556245936827
}

FWIW, I'm able to interact with the same server using patchfoo without issue.

@christianbundy
Copy link
Member Author

Oh, totally different issue. I think I've fixed this in the 15.0.1 upgrade, could you confirm that the fix resolves this bug for you?

@christianbundy christianbundy self-assigned this Aug 13, 2019
@christianbundy christianbundy added the bug Something isn't working label Aug 13, 2019
@khimaros
Copy link

@christianbundy -- I couldn't find a 15.0.1 but did try oasis 1.15.1.

$ /srv/export/node_modules/.bin/oasis --version
1.15.1

The symptom with this version seems to be the same.

This is the line where the exception is being raised:

  const referenceStream = await cooler.read(ssb.backlinks.read, {

From a glance it wasn't clear whether cooler or ssb.backlinks was undefined, so I added a few debug statements:

2019-08-13T05:39:50.514206358Z 2019-08-13T05:39:50.514Z oasis:model-post cooler [object Object]
2019-08-13T05:39:50.514281137Z 2019-08-13T05:39:50.514Z oasis:model-post ssb.backlinks undefined

Looks like something is amiss with ssb-backlinks on my system?

@khimaros
Copy link

khimaros commented Aug 13, 2019

This is the output of Object.keys(ssb):

2019-08-13T05:47:51.914664083Z 2019-08-13T05:47:51.914Z oasis:model-post ssb keys _events,_eventsCount,_maxListeners,auth,address,manifest,multiserver,multiserverNet,get,createFeedStream,createLogStream,messagesByType,createHistoryStream,createUserStream,createWriteStream,links,add,publish,getAddress,getLatest,latest,latestSequence,whoami,progress,status,getVectorClock,version,help,seq,usage,clock,plugins,gossip,replicate,friends,blobs,invite,query,links2,ws,ebt,ooo,npmRegistry,patchfoo,_emit,stream,closed,close,id

Adding explicit "ssb-backlinks": {} to plugins section of .ssb/config doesn't seem to have any effect on the list of keys.

@christianbundy
Copy link
Member Author

Are you seeing this bug when running from an external ssb-server or with only oasis running its own server? I see the patchfoo plugin is loaded, which makes me think it's maybe an external server that isn't running ssb-backlinks? If you're running an external server you should be able to install and enable ssb-backlinks with:

sbot plugins.install ssb-backlinks
sbot plugins.enable ssb-backlinks

You'll have to restart your ssb-server, and if you run into an "Error: expected X but had Y" you may have to use this fix.

@khimaros
Copy link

khimaros commented Aug 13, 2019

I can consistently reproduce this behavior with both internal and external server.

Interestingly, patchfoo and npmRegistry are showing up in Object.keys(ssb) even though I've removed them from .ssb/config, moved the node_modules directory, and restarted oasis. Neither plugins are showing up in the output of ssb-server status (see output in #6 (comment))

Here's a bit more context from the running oasis instance to show that it has been started with the internal server:

2019-08-13T05:52:01.551130223Z 2019-08-13T05:52:01.551Z oasis Initial connection attempt failed
2019-08-13T05:52:01.551152978Z 2019-08-13T05:52:01.551Z oasis Starting Scuttlebutt server
2019-08-13T05:52:01.812053414Z 2019-08-13T05:52:01.811Z secret-stack Adding transport net
2019-08-13T05:52:01.812639372Z 2019-08-13T05:52:01.812Z secret-stack Adding transform shs
2019-08-13T05:52:01.827443937Z 2019-08-13T05:52:01.827Z secret-stack Adding transport onion
2019-08-13T05:52:01.827637960Z 2019-08-13T05:52:01.827Z secret-stack Adding transport unix
2019-08-13T05:52:01.828021112Z 2019-08-13T05:52:01.827Z secret-stack Adding transform noauth
2019-08-13T05:52:01.845105396Z 2019-08-13T05:52:01.844Z secret-stack Adding transport ws
2019-08-13T05:52:01.898868580Z 2019-08-13T05:52:01.851Z secret-stack net plugin creating transport host=0.0.0.0 port=8008 scope=public
2019-08-13T05:52:01.898896038Z 2019-08-13T05:52:01.851Z secret-stack creating server net shs host=0.0.0.0 port=8008 scope=public
2019-08-13T05:52:01.898903357Z 2019-08-13T05:52:01.851Z secret-stack net plugin creating transport host=0.0.0.0 port=8008 scope=public
2019-08-13T05:52:01.898909210Z 2019-08-13T05:52:01.851Z secret-stack net plugin creating transport host=undefined port=NaN scope=undefined
2019-08-13T05:52:01.898916069Z 2019-08-13T05:52:01.852Z multiserver:net Listening on 0.0.0.0:8008
2019-08-13T05:52:01.898921921Z ssb-friends: stream legacy api used
2019-08-13T05:52:02.341371872Z 2019-08-13T05:52:02.341Z oasis Retrying connection to own server
<elided>
2019-08-13T15:59:14.845052885Z 2019-08-13T15:59:14.844Z oasis:model-post transforming %XTxv<elided>
2019-08-13T15:59:14.845173688Z 2019-08-13T15:59:14.845Z oasis:model-post cooler [object Object]
2019-08-13T15:59:14.845276546Z 2019-08-13T15:59:14.845Z oasis:model-post ssb keys _events,_eventsCount,_maxListeners,auth,address,manifest,multiserver,multiserverNet,get,createFeedStream,createLogStream,messagesByType,createHistoryStream,createUserStream,createWriteStream,links,add,publish,getAddress,getLatest,latest,latestSequence,whoami,progress,status,getVectorClock,version,help,seq,usage,clock,plugins,gossip,replicate,friends,blobs,invite,query,links2,ws,ebt,ooo,npmRegistry,patchfoo,_emit,stream,closed,close,id
2019-08-13T15:59:14.847242865Z 
2019-08-13T15:59:14.847318966Z   TypeError: Cannot read property 'read' of undefined
2019-08-13T15:59:14.847330776Z       at Promise.all.messages.map (/srv/export/node_modules/@fraction/oasis/src/pages/models/post.js:30:59)

Here's the full process listing of the container running oasis. runsv ssb-server is a no-op, the service is administratively disabled:

root@ssb:/# ps aux
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         1  0.0  0.0   4200  1056 ?        Ss   05:36   0:00 /usr/bin/runsvdir /etc/service
root        46  0.0  0.0   4048   692 ?        S    05:37   0:00 runsv syslog
root        47  0.0  0.0   4048   652 ?        S    05:37   0:00 runsv svcheck
root        48  0.0  0.0   4048   704 ?        S    05:37   0:00 runsv ssb-server
root        49  0.0  0.0   4048   692 ?        S    05:37   0:00 runsv oasis
root        51  0.0  0.0  17952  2880 ?        S    05:37   0:00 /bin/bash /usr/bin/svcheck
root        52  0.0  0.0 178404  2868 ?        Sl   05:37   0:00 /usr/sbin/rsyslogd -n
root       245  0.0  0.0  18192  3360 pts/0    Ss   05:37   0:00 /bin/bash --login
prodsrv   2861  0.1  0.7 920352 64260 ?        Sl   05:51   0:51 node /srv/export/node_modules/.bin/oasis --web-port 8028 --web-host 0.0.0.0 --open false --debug
root     32304  0.0  0.0   4184   672 ?        S    16:03   0:00 sleep 30
root     32305  0.0  0.0  36632  2816 pts/0    R+   16:03   0:00 ps aux

And the full list of listening connections, 8028 is the web-port for oasis:

root@ssb:/# netstat -alpn | grep LISTEN
tcp        0      0 0.0.0.0:8028            0.0.0.0:*               LISTEN      -                   
tcp        0      0 0.0.0.0:8008            0.0.0.0:*               LISTEN      -    

When the patchfoo plugin is enabled, 0.0.0.0:8027 is present.

@christianbundy
Copy link
Member Author

Found the bug, could you replace --open false with --no-open and see if that resolves the problem? I think one of the dependencies is using rc or similar and parsing the command-line options and thinking that --open false means something completely different, but they don't understand the --no-open shorthand so that's a valid workaround for now.

I really wish upstream dependencies weren't parsing our CLI options, that's why I had to use web-host and web-port instead of host and port. 😒

@christianbundy
Copy link
Member Author

Actually, I just published a new version that I'm hoping will resolve this and your other issue. I've hidden the CLI options from upstream modules so they can't attach their own semantics to them. :~)

@khimaros
Copy link

Thank you @christianbundy -- the latest version appears to have fixed my issues! Also, after a bit of fiddling with ssb-server and my config, oasis is working well with both the internal and external server.

@christianbundy
Copy link
Member Author

Woo, thanks for the confirmation!

@cinnamon-bun cinnamon-bun added this to the Barebones SSB client milestone Feb 20, 2020
mplorentz referenced this issue in planetary-social/oasis Mar 31, 2022
…t-info-2.8.9

Bump hosted-git-info from 2.8.8 to 2.8.9
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Development

No branches or pull requests

3 participants