Patchwork: Infinite Scuttling on startup with Unexpected token in JSON

Created on 5 Oct 2019 · 22Comments · Source: ssbc/patchwork

When starting patchwork
aur/ssb-patchwork 3.16.2-1 (15, 0.366735) [installed: 3.16.2-1]
on archlinux it get's stuck scuttling forever and never shows any content.

from the terminal:
after printing the configuration json

{ path: '/home/arthur/.ssb',
  party: true,
  timeout: 0,
  pub: true,
  local: true,
  friends: { dunbar: 150, hops: 2 },
  gossip: { connections: 3, autoPopulate: false },
  connections: .... lots of connection stuff ....
  timers:
  caps: ...
  master: [],
  logging: { level: 'notice' },
  port: 8008,
  blobsPort: 8989,
  server: true,
  _: [],
  host: 'elided',
  ws: ... elided ...
  keys: ... elided ...
  remote: ... elided ... }

then it prints this warning and blows up on what looks like malformed json

git-ssb is not installed, or not available in path
SyntaxError: Unexpected token  in JSON at position 82
    at Object.parse [as decode] (<anonymous>)
    at /opt/ssb-patchwork/node_modules/flumelog-offset/inject.js:93:24
    at /opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:48:11
    at /opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:75:11
    at get (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:29:7)
    at next (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:53:7)
    at Object.read (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:78:7)
    at next (/opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:47:16)
    at /opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:43:11
    at /opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:96:11
SyntaxError: Unexpected token  in JSON at position 82
    at Object.parse [as decode] (<anonymous>)
    at /opt/ssb-patchwork/node_modules/flumelog-offset/inject.js:93:24
    at /opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:48:11
    at /opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:75:11
    at get (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:29:7)
    at next (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:53:7)
    at Object.read (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:78:7)
    at next (/opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:47:16)
    at /opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:43:11
    at /opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:96:11
SyntaxError: Unexpected token  in JSON at position 86
    at Object.parse [as decode] (<anonymous>)
    at /opt/ssb-patchwork/node_modules/flumelog-offset/inject.js:93:24
    at /opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:48:11
    at /opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:75:11
    at get (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:29:7)
    at next (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:53:7)
    at Object.read (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:78:7)
    at next (/opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:47:16)
    at /opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:43:11
    at /opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:96:11
SyntaxError: Unexpected token  in JSON at position 77
    at Object.parse [as decode] (<anonymous>)
    at /opt/ssb-patchwork/node_modules/flumelog-offset/inject.js:93:24
    at /opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:48:11
    at /opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:75:11
    at get (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:29:7)
    at next (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:53:7)
    at Object.read (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:78:7)
    at next (/opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:47:16)
    at /opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:43:11
    at /opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:96:11
SyntaxError: Unexpected token  in JSON at position 171

then a lot more of that and a couple that are different (stack traces removed, if you want them a can add them)

SyntaxError: Unexpected token � in JSON at position 0
Error: when trying to retrive:TDT,about,@LVL4qjvmws3Cxavfi4iCQI6dSOqWqOyq5/5CHImILA8=.ed25519,1569946207231,636332474at since:638494618
Error: past end:636332478-2702185763 < 638495144
Error: not a valid address:{"port":8008,"key":"@J+0DGLgRn8H5tVLCcRUfN7NfUcTGEZKqML3krEOJjDY=.ed25519"}

and then it's back to printing the
SyntaxError: Unexpected token in JSON at position 82 messages every few seconds forever.

stale bug

Source

thearthur

All 22 comments

Hey @thearthur, sorry to hear that you're having problems with this right now. It sounds to me like you might have a corrupt flumelog (~/.ssb/flume/log.offset). I'd recommend making a copy of your log.offset somewhere, stopping Patchwork, then deleting all of the files in ~/.ssb/flume except for log.offset. Then I'd run fix-flumelog-offset and then restarting Patchwork.

Happy to chat more about this if you'd like more info!

christianbundy on 5 Oct 2019

is there more i can do to track down the cause before clearing the data?

thearthur on 6 Oct 2019

I'd recommend keeping a copy of the log.offset, but in my experience this can happen when running multiple clients at the same time. I can change fix-flumelog-offset so that it exports the corrupt data for us to look at, if you'd like, but if you'd like to get back on the network ASAP I'd just make a copy that we can look at later.

christianbundy on 6 Oct 2019

clearing out everything except the log.offset file leaves it stuck "indexing database" with this output in the terminal:

```git-ssb is not installed, or not available in path
SyntaxError: Unexpected token in JSON at position 520
at Object.parse [as decode] ()
at /opt/ssb-patchwork/node_modules/flumelog-offset/inject.js:47:22
at /opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:48:11
at /opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:75:11
at get (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:29:7)
at next (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:53:7)
at Object.read (/opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:78:7)
at next (/opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:47:16)
at /opt/ssb-patchwork/node_modules/flumelog-offset/frame/recoverable.js:43:11
at /opt/ssb-patchwork/node_modules/aligned-block-file/blocks.js:96:11

<--- Last few GCs --->

[35:0xb85f8737000] 671246 ms: Mark-sweep 1820.4 (2114.8) -> 1809.5 (2114.8) MB, 1231.8 / 0.0 ms (average mu = 0.130, current mu = 0.039) allocation failure scavenge might not succeed
[35:0xb85f8737000] 672412 ms: Mark-sweep 1809.5 (2114.8) -> 1809.4 (2114.8) MB, 1165.2 / 0.0 ms (average mu = 0.067, current mu = 0.001) allocation failure GC in old space requested

<--- JS stacktrace --->

==== JS stack trace =========================================

0: ExitFrame [pc: 0x55622b6e2b2e]

Security context: 0x208346047411
1: /* anonymous */ [0x26b304086b71] [/opt/ssb-patchwork/node_modules/pull-inactivity/node_modules/pull-abortable/index.js:~20] pc=0x227f13f3f19b
2: more(aka more) [0x26b304086c31] [/opt/ssb-patchwork/node_modules/pull-reader/ind...

TypeError: _read is not a function
at read (/opt/ssb-patchwork/node_modules/pull-defer/source.js:14:10)
at /opt/ssb-patchwork/node_modules/pull-abortable/index.js:34:7
at next (/opt/ssb-patchwork/node_modules/pull-stream/sinks/drain.js:16:11)
at sink (/opt/ssb-patchwork/node_modules/pull-stream/sinks/drain.js:37:9)
at pull (/opt/ssb-patchwork/node_modules/pull-stream/pull.js:41:14)
at Object.listen (/opt/ssb-patchwork/lib/mutant-pull-value.js:44:3)
at Object.addListener (/opt/ssb-patchwork/node_modules/mutant/lib/lazy-watcher.js:85:16)
at Object.MutantPullValue (/opt/ssb-patchwork/lib/mutant-pull-value.js:33:22)
at ProtoComputed.listen (/opt/ssb-patchwork/node_modules/mutant/computed.js:82:49)
at ProtoComputed.getValue (/opt/ssb-patchwork/node_modules/mutant/computed.js:196:12)
Error {}
```

thearthur on 8 Oct 2019

Yeah, the log.offset looks like it's corrupt, You'll now need to run npx fix-flumelog-offset and it should remove any corrupt entries for you.

christianbundy on 8 Oct 2019

It seems I have also infinite scuttling problem but for different reason I suppose.

Look at this log!

Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
RangeError: Maximum call stack size exceeded
    at validateNumber (internal/validators.js:128:24)
    at checkNumberType (internal/buffer.js:41:3)
    at Buffer.readUInt32BE (internal/buffer.js:192:3)
    at /tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/aligned-block-file/blocks.js:112:16
    at /tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/aligned-block-file/blocks.js:95:23
    at get (/tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/aligned-block-file/blocks.js:29:7)
    at Object.readUInt32BE (/tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/aligned-block-file/blocks.js:93:9)
    at Object.getMeta (/tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/flumelog-offset/frame/recoverable.js:31:12)
    at getMeta (/tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/flumelog-offset/inject.js:42:11)
    at next (/tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/pull-cursor/cursor.js:26:11)

kaotisk-hund on 11 Oct 2019

👍1

After resetting the log I get the exact same output that kaotisk posted
above. I have not gotten it working
since then.

On Thu, Oct 10, 2019 at 4:35 PM kaotisk notifications@github.com wrote:

It seems I have also infinite scuttling problem but for different reason I
suppose.

Look at this log!

Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
RangeError: Maximum call stack size exceeded
at validateNumber (internal/validators.js:128:24)
at checkNumberType (internal/buffer.js:41:3)
at Buffer.readUInt32BE (internal/buffer.js:192:3)
at /tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/aligned-block-file/blocks.js:112:16
at /tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/aligned-block-file/blocks.js:95:23
at get (/tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/aligned-block-file/blocks.js:29:7)
at Object.readUInt32BE (/tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/aligned-block-file/blocks.js:93:9)
at Object.getMeta (/tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/flumelog-offset/frame/recoverable.js:31:12)
at getMeta (/tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/flumelog-offset/inject.js:42:11)
at next (/tmp/.mount_ssb-paThd5Xc/resources/app.asar/node_modules/pull-cursor/cursor.js:26:11)

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/ssbc/patchwork/issues/1192?email_source=notifications&email_token=AAAXCHIIL2DZFU27OQXTDI3QN634NA5CNFSM4I5WAGQKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEA6JFOQ#issuecomment-540840634,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AAAXCHIINRAKD3UBVLFVNSTQN634NANCNFSM4I5WAGQA
.

thearthur on 11 Oct 2019

Really sorry to hear that you're having this problem. I suppose the next thing I'd try would to be slightly more aggressive about what you delete, but _really_ it's super concerning that you're getting corrupt logs in the first place.

If it were me, I'd do this:

Turn off all SSB servers and such

Kill Patchwork, Patchbay, ssb-server, Oasis, whatever.

Delete all views and non-essential files

find ~/.ssb/ \
  -type f \
  -not -name config \
  -not -name secret \
  -not -name 'log.offset' \
  -not -name conn.json \
  -not -name gossip.json \
  -not -name manifest.json \
  -not -path '*/.ssb/blobs/*' \
  -exec rm -f {} \;

Fix the log

npx fix-flumelog-offset

Start one (!) client

I'd recommend Patchwork, ssb-server, or Oasis, since currently Patchbay isn't up-to-date with the latest database modules.

Wait a bunch for the indexing to finish

Keep an eye on the console output for any errors, but assuming you've done the above it _should_ be fine? :/ Again, super sorry to hear you've got to deal with this, I'll keep trying to investigate why this is happening.

(@kaotisk-hund, is Oasis broken for you as well? Or just Patchwork?)

christianbundy on 11 Oct 2019

Also, if either or both of you would like to do a brief audio or video call I'd be happy to chat and walk through this bug. I'm sure it's super frustrating and I'd like to help however I can.

christianbundy on 11 Oct 2019

👍1

@christianbundy no! it works okay! and patchbay too.

Now, what I 've done so far was:

backup .ssb/ folder
create new one with a copy of secret in it and let it do it over again. It was working, but no followers or something was missing anyway.

Now, I got the instructions but I got on fixing a crypto.randomByte is not a function :-S

kaotisk-hund on 13 Oct 2019

Okay, sent PR for typo, I am about to start Patchwork now to test it out. And ... it started indexing!

kaotisk-hund on 13 Oct 2019

Fixed! Thank you very much!

kaotisk-hund on 13 Oct 2019

🎉1

I have to do this about every other day.

I suspect there are two different bugs here. the JSON data validation errors and the RangeError: Maximum call stack size exceeded

I'm also running it in firejail with this command if that makes a difference:

XDG_CURRENT_DESKTOP=Unity firejail  --profile=chromium --private=/home/arthur/ssb/ bash -c "XDG_CONFIG_HOME=/home/arthur/ ssb-patchwork"

firejail gives it it's own persistent isolated home directory

thearthur on 16 Oct 2019

sometimes the error is a little different, perhaps that is a clue?
```Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
Error {}
/opt/ssb-patchwork/node_modules/pull-looper/index.js:8
return function (abort, cb) {
^

RangeError: Maximum call stack size exceeded
at /opt/ssb-patchwork/node_modules/pull-looper/index.js:8:19
at next (/opt/ssb-patchwork/node_modules/pull-stream/throughs/filter.js:14:9)
at next (/opt/ssb-patchwork/node_modules/pull-stream/throughs/async-map.js:27:9)
at /opt/ssb-patchwork/node_modules/pull-looper/index.js:6:5
at /opt/ssb-patchwork/node_modules/looper/index.js:11:9
at /opt/ssb-patchwork/node_modules/pull-looper/index.js:11:5
at /opt/ssb-patchwork/node_modules/pull-looper/index.js:6:5
at /opt/ssb-patchwork/node_modules/looper/index.js:11:9
at /opt/ssb-patchwork/node_modules/pull-looper/index.js:11:5
at /opt/ssb-patchwork/node_modules/pull-write/index.js:29:9
```

thearthur on 16 Oct 2019

Just to clarify though, are the above fixes working (at least temporarily)? Also, could you give any more info on which other clients you might be using? That RangeError looks different than the other errors, is there any more context? I'mhaving a hard time figuring out what's breaking here.

christianbundy on 16 Oct 2019

Yes, i just run the delete and fix-clumelog commands and it fixes it every time.
I have exactly one ssb thing on my computer, patchwork. only one copy of it gets started, and it's started in an isolated environment using firejail so it is the only program creating or manipulating files in it's entire OS. I've tried to reduce the interactions as much as i can.
The errors usually happen after the laptop runs out of battery, or is rebooted. cases where patchwork is unceremoniously stopped. I still haven't figured out a pattern yet. I'll keep watching and since it's random when it happens this may take some time and patience.

is there a more verbose mode I can be logging this with?
i'll change it so the logging is saved all the time and maybe we can see what happened just before it's stopped?

thearthur on 16 Oct 2019

I got into a similar problematic situation, probably from trying to run Patchbay and Patchwork at the same time.

I kept seeing this in the console, and my Patchwork wouldn't download any new messages:

Error: not a valid address:{"port":8008,"key":"@J+0DGLgRn8H5tVLCcRUfN7NfUcTGEZKqML3krEOJjDY=.ed25519"}
    at Object.<anonymous> (/tmp/.mount_ssb-paEYaVgr/resources/app.asar/node_modules/ssb-legacy-conn/lib/index.js:287:31)
    at apply (/tmp/.mount_ssb-paEYaVgr/resources/app.asar/node_modules/muxrpc-validation/index.js:197:15)
    at Object.<anonymous> (/tmp/.mount_ssb-paEYaVgr/resources/app.asar/node_modules/muxrpc-validation/index.js:62:14)
    at Object.<anonymous> (/tmp/.mount_ssb-paEYaVgr/resources/app.asar/node_modules/secret-stack/util.js:80:17)
    at Object.<anonymous> (/tmp/.mount_ssb-paEYaVgr/resources/app.asar/node_modules/hoox/index.js:3:17)
    at Object.hooked [as add] (/tmp/.mount_ssb-paEYaVgr/resources/app.asar/node_modules/hoox/index.js:10:15)
    at /tmp/.mount_ssb-paEYaVgr/resources/app.asar/lib/plugins/index.js:145:26
    at /tmp/.mount_ssb-paEYaVgr/resources/app.asar/node_modules/pull-stream/sinks/drain.js:24:37
    at /tmp/.mount_ssb-paEYaVgr/resources/app.asar/node_modules/pull-stream/throughs/through.js:19:9
    at /tmp/.mount_ssb-paEYaVgr/resources/app.asar/node_modules/pull-stream/throughs/map.js:19:9

I made a new ~/.ssb and copied the secret over, and now I am trying to redownload my state of the world from a Manyverse LAN peer. It seems to be downloading messages; I will report back as to whether it starts connecting to the usual pubs and gets me up to date with whatever I last posted.

interfect on 26 Oct 2019

OK, what I tried didn't work at all. I somehow ended up running under a different key than I expected (@+wHIXfU3/VzcbarXf5128gOtWM9slqWnRow+lNXVtCQ=.ed25519 instead of @3wl2IivU+ghWlZj4psiRMQlcOKV9iLbXbNIb1wv+0/M=.ed25519), and moreover I'm back to seeing this in the console:

Error: not a valid address:{"port":8008,"key":"@J+0DGLgRn8H5tVLCcRUfN7NfUcTGEZKqML3krEOJjDY=.ed25519"}
    at Object.<anonymous> (/tmp/.mount_ssb-pacxn7gw/resources/app.asar/node_modules/ssb-legacy-conn/lib/index.js:287:31)
    at apply (/tmp/.mount_ssb-pacxn7gw/resources/app.asar/node_modules/muxrpc-validation/index.js:197:15)
    at Object.<anonymous> (/tmp/.mount_ssb-pacxn7gw/resources/app.asar/node_modules/muxrpc-validation/index.js:62:14)
    at Object.<anonymous> (/tmp/.mount_ssb-pacxn7gw/resources/app.asar/node_modules/secret-stack/util.js:80:17)
    at Object.<anonymous> (/tmp/.mount_ssb-pacxn7gw/resources/app.asar/node_modules/hoox/index.js:3:17)
    at Object.hooked [as add] (/tmp/.mount_ssb-pacxn7gw/resources/app.asar/node_modules/hoox/index.js:10:15)
    at /tmp/.mount_ssb-pacxn7gw/resources/app.asar/lib/plugins/index.js:145:26
    at /tmp/.mount_ssb-pacxn7gw/resources/app.asar/node_modules/pull-stream/sinks/drain.js:24:37
    at /tmp/.mount_ssb-pacxn7gw/resources/app.asar/node_modules/pull-stream/throughs/through.js:19:9
    at /tmp/.mount_ssb-pacxn7gw/resources/app.asar/node_modules/pull-stream/throughs/map.js:19:9

I can apparently sync new messages, however, so I think that's an improvement.

interfect on 26 Oct 2019

OK, I figured it out; I'm incompetent.

I happened to have an old secret file from that other identity laying around, and I restored from that. I'm restoring from the one I meant to use now.

So I think if you don't want to mess around with running fixup scripts but you have another machine, you can:

Rename ~/.ssb to something else
Make a new ~/.ssb
Copy over secret
Restore messages from another working machine you already have

interfect on 26 Oct 2019

Could this be detected as long as it is in need of getting fixed that way, redownloading messages, as a reset button or it would be better to reach the specified bug? Anonymous reporting of the bug while this option is provided?

kaotisk-hund on 27 Oct 2019

Is this still relevant? If so, what is blocking it? Is there anything you can do to help move it forward?

stale[bot] on 25 Jan 2020

Hi @christianbundy,

I just replicated this issue. Infinite Scuttling. I read this issue's comments out of order, so first I did your find to delete cache files etc., which didn't fix things on its own, and when starting Patchwork, saw the following console output:

/Applications/Patchwork.app/Contents/Resources/app.asar/node_modules/flumelog-offset/inject.js:47
        value: codec.decode(codec.buffer ? value : value.toString()),
                     ^

SyntaxError: Unexpected token

Eventually I took a backup of ~/.ssb, deleted the contents of the flume directory (except for log.offset), and ran fix-flume-log, which showed:

Ignored error: SyntaxError: Unexpected token  in JSON at position 68

Is there any data I can send to help pin down this issue (I still have my old log.offset)? It's likely I had two clients running at once at some point and this might've broken things. I'm running Patchwork 3.17.7.767 and Patchbay 8.1.0 on MacOS 10.15.4.