search

farcasterxyz / hub-monorepo

Implementation of the Farcaster Hub specification and supporting libraries for building applications on Farcaster
https://www.thehubble.xyz
MIT License
708 stars 402 forks source link

bug(replicator): unsupported Unicode escape sequence #1753

Closed saez0pub closed 8 months ago

saez0pub commented 8 months ago

What is the bug? I have logs with unicode problems in the replicator backfill

How can it be reproduced? (optional) Fresh start of a new replicator instance

Additional context (optional) replicator log:

[16:55:56.352] ERROR (1): Job BackfillFidVerifications 783911 failed: unsupported Unicode escape sequence: error: unsupported Unicode escape sequence
    at /home/node/app/node_modules/pg/lib/client.js:526:17
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async PostgresConnection.executeQuery (/home/node/app/node_modules/kysely/dist/cjs/dialect/postgres/postgres-driver.js:72:28)
    at async /home/node/app/node_modules/kysely/dist/cjs/query-executor/query-executor-base.js:37:28
    at async #run (/home/node/app/node_modules/kysely/dist/cjs/driver/single-connection-provider.js:27:16)
    at PostgresConnection.executeQuery (/home/node/app/node_modules/kysely/dist/cjs/dialect/postgres/postgres-driver.js:91:69)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async /home/node/app/node_modules/kysely/dist/cjs/query-executor/query-executor-base.js:37:28
    at async #run (/home/node/app/node_modules/kysely/dist/cjs/driver/single-connection-provider.js:27:16)
    at executeTx (/home/node/app/apps/replicator/build/db.js:161:50)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async Object.run (/home/node/app/apps/replicator/build/jobs/backfillFidVerifications.js:14:17)
    at async /home/node/app/node_modules/bullmq/dist/cjs/classes/child-processor.js:69:33
[16:55:56.349] ERROR (1): Error processing message 0x44f75a015b700a9fc598a6d69cab62a8bd8ec5ae (fid 4215): error: unsupported Unicode escape sequence {"context":"worker","wid":"1:31"}

postgres log:


2024-02-28 16:55:56.347 UTC [79] ERROR:  unsupported Unicode escape sequence
2024-02-28 16:55:56.347 UTC [79] DETAIL:  \u0000 cannot be converted to text.
2024-02-28 16:55:56.347 UTC [79] CONTEXT:  JSON data, line 1: ...e":">\u0019!'��\u0015p��@�#hV}�\u0000...

Do I have a postgres charset problem ?

bitspresso commented 8 months ago

Same here. Any hints, anyone?

image

TecSong commented 8 months ago

I have the same problem, hope it can be fixed as soon as possible

error: unsupported Unicode escape sequence at /home/node/app/node_modules/pg/lib/client.js:526:17 at process.processTicksAndRejections (node:internal/process/task_queues:95:5) at async PostgresConnection.executeQuery (/home/node/app/node_modules/kysely/dist/cjs/dialect/postgres/postgres-driver.js:72:28) at async /home/node/app/node_modules/kysely/dist/cjs/query-executor/query-executor-base.js:37:28 at async #run (/home/node/app/node_modules/kysely/dist/cjs/driver/single-connection-provider.js:27:16) at PostgresConnection.executeQuery (/home/node/app/node_modules/kysely/dist/cjs/dialect/postgres/postgres-driver.js:91:69) at process.processTicksAndRejections (node:internal/process/task_queues:95:5) at async /home/node/app/node_modules/kysely/dist/cjs/query-executor/query-executor-base.js:37:28 at async #run (/home/node/app/node_modules/kysely/dist/cjs/driver/single-connection-provider.js:27:16) at executeTx (/home/node/app/apps/replicator/build/db.js:161:50) at process.processTicksAndRejections (node:internal/process/task_queues:95:5) at async processMergeMessageHubEvent (/home/node/app/apps/replicator/build/processors/index.js:291:5) at async processHubEvent (/home/node/app/apps/replicator/build/processors/index.js:250:13) at async Object.run (/home/node/app/apps/replicator/build/jobs/processHubEvent.js:11:9) at async /home/node/app/node_modules/bullmq/dist/cjs/classes/child-processor.js:69:33 error: unsupported Unicode escape sequence at /home/node/app/node_modules/pg/lib/client.js:526:17 at process.processTicksAndRejections (node:internal/process/task_queues:95:5) at async PostgresConnection.executeQuery (/home/node/app/node_modules/kysely/dist/cjs/dialect/postgres/postgres-driver.js:72:28) at async /home/node/app/node_modules/kysely/dist/cjs/query-executor/query-executor-base.js:37:28 at async #run (/home/node/app/node_modules/kysely/dist/cjs/driver/single-connection-provider.js:27:16) at PostgresConnection.executeQuery (/home/node/app/node_modules/kysely/dist/cjs/dialect/postgres/postgres-driver.js:91:69) at process.processTicksAndRejections (node:internal/process/task_queues:95:5) at async /home/node/app/node_modules/kysely/dist/cjs/query-executor/query-executor-base.js:37:28 at async #run (/home/node/app/node_modules/kysely/dist/cjs/driver/single-connection-provider.js:27:16) at executeTx (/home/node/app/apps/replicator/build/db.js:161:50) at process.processTicksAndRejections (node:internal/process/task_queues:95:5) at async processMergeMessageHubEvent (/home/node/app/apps/replicator/build/processors/index.js:291:5) at async processHubEvent (/home/node/app/apps/replicator/build/processors/index.js:250:13) at async Object.run (/home/node/app/apps/replicator/build/jobs/processHubEvent.js:11:9) at async /home/node/app/node_modules/bullmq/dist/cjs/classes/child-processor.js:69:33
saez0pub commented 8 months ago

Here are some logs (I extracted between 08:47:24.544 and 09:02:33.491 UTC time)

  15290 Error processing message 0xNNNN (fid XXX): error: unsupported Unicode escape sequence
  15201 Job BackfillFidVerifications XXXXXX failed: unsupported Unicode escape sequence: error: unsupported Unicode escape sequence
   1358 Job ProcessHubEvent XXXXXX failed: or update on table "messages" violates foreign key constraint "messages_fid_foreign": error: insert or update on table "messages" violates foreign key constraint "messages_fid_foreign"
     89 Job ProcessHubEvent XXXXXX failed: unsupported Unicode escape sequence: error: unsupported Unicode escape sequence
      5 Job ProcessHubEvent XXXXXX failed: or update on table "signers" violates foreign key constraint "signers_fid_foreign": error: insert or update on table "signers" violates foreign key constraint "signers_fid_foreign"
      4 Job BackfillFidCasts XXXXXX failed: insert or update on table "messages" violates foreign key constraint "messages_signer_fid_foreign": error: insert or update on table "messages" violates foreign key constraint "messages_signer_fid_foreign"
      2 Job BackfillFidReactions XXXXXX failed: insert or update on table "messages" violates foreign key constraint "messages_signer_fid_foreign": error: insert or update on table "messages" violates foreign key constraint "messages_signer_fid_foreign"
      1 StatsD Error
      1 Job BackfillFidUserData XXXXXX failed: insert or update on table "messages" violates foreign key constraint "messages_signer_fid_foreign": error: insert or update on table "messages" violates foreign key constraint "messages_signer_fid_foreign"
chetankashetti commented 8 months ago

we are missing solana connected addresses due to the above error.

and mostly failing in backfillVerifications.

saez0pub commented 8 months ago

The error \u0000 cannot be converted to text.seems problematic.

Here is a thread about it: https://www.postgresql.org/message-id/CAGem3qDepjdfXjWUSb7gx%3D8E9TYU_BW_dd%3DJkgfpnUbsrHE2Nw%40mail.gmail.com

From a network capture, I can see that a lot of the problematic insert are on the table message, the only field of type json is body. looking at the values, I can see lot of message type '7' which is VERIFICATION_ADD_ETH_ADDRESS

An example is on these values (guessing from Ascii output of tcpdump):

"created_at" 2024-03-02T08:46:12.987+00:00
"updated_at" 2024-03-02T08:46:12.987+00:00
"fid" 3824
"type" 7
"timestamp" 2024-02-23T00:10:37.000+00:00
....
"body"  {"address":".........\u001b...)......d\u001d.....\\\u0017............s\u0018]\u0014\u001c.........L..","claimSignature":"9......K...Fd...\u0010d......\u0016...\u0012$......\u0015e......\u0006>.....\u0006'Pim*{c...\u00067L\n...W...0\u0002........\"......j\u0005..(.........[\u0000","blockHash":"...n@0...\b...\u001c........CZ\u0013......(...!...\"......a...\u0017......\u00116","protocol":1}

unsupported Unicode escape sequence.D\u0000 cannot be converted to text..WJSON data, line 1: ...0\u0002........\"......j\u0005..(.........[\u0000....Fjsonfuncs.c.L625.Rjson_ereport_error

looking at the fid 3824:

curl -s "hubble/v1/verificationsByFid?fid=3824" | jq
{
  "messages": [
    {
      "data": {
        "type": "MESSAGE_TYPE_VERIFICATION_ADD_ETH_ADDRESS",
        "fid": 3824,
        "timestamp": 83194105,
        "network": "FARCASTER_NETWORK_MAINNET",
        "verificationAddAddressBody": {
          "address": "0x5b551558f370d245334ecdce667d18f2739b937c",
          "claimSignature": "REbZTRHkwc7VWNce+FdTNdCZejvDWlsT+xgxYseQh9JTSLHjQWC2R4xpgfvYrLVtm8mRpBOp9xiIEJnJPhibiBs=",
          "blockHash": "0xb08d03c5e087417429b20754c0bad877a2a2cfb595270f07ea2fd1cad2a00e37",
          "verificationType": 0,
          "chainId": 0,
          "protocol": "PROTOCOL_ETHEREUM",
          "ethSignature": "REbZTRHkwc7VWNce+FdTNdCZejvDWlsT+xgxYseQh9JTSLHjQWC2R4xpgfvYrLVtm8mRpBOp9xiIEJnJPhibiBs="
        },
        "verificationAddEthAddressBody": {
          "address": "0x5b551558f370d245334ecdce667d18f2739b937c",
          "claimSignature": "REbZTRHkwc7VWNce+FdTNdCZejvDWlsT+xgxYseQh9JTSLHjQWC2R4xpgfvYrLVtm8mRpBOp9xiIEJnJPhibiBs=",
          "blockHash": "0xb08d03c5e087417429b20754c0bad877a2a2cfb595270f07ea2fd1cad2a00e37",
          "verificationType": 0,
          "chainId": 0,
          "protocol": "PROTOCOL_ETHEREUM",
          "ethSignature": "REbZTRHkwc7VWNce+FdTNdCZejvDWlsT+xgxYseQh9JTSLHjQWC2R4xpgfvYrLVtm8mRpBOp9xiIEJnJPhibiBs="
        }
      },
      "hash": "0x299ee600b1e7b5cfd6055956d4119a135c20dc7d",
      "hashScheme": "HASH_SCHEME_BLAKE3",
      "signature": "FuWeVh9rH01mgQOHjqiPWVhZOzouQpqVp0zCEy9mHkykbcIhffOSCdsNfcxpi7rtIGJHth0VQX8atzB2dkqxBA==",
      "signatureScheme": "SIGNATURE_SCHEME_ED25519",
      "signer": "0x0ab9bc023d15e25697928225f95f98669df9609b8b20a643c03f9d71a963b606"
    },
    {
      "data": {
        "type": "MESSAGE_TYPE_VERIFICATION_ADD_ETH_ADDRESS",
        "fid": 3824,
        "timestamp": 99187837,
        "network": "FARCASTER_NETWORK_MAINNET",
        "verificationAddAddressBody": {
          "address": "GYLkraPfvT3UtUbdxcHiVWV2EShBoZtqW1Bcq4VazUCt",
          "claimSignature": "ObDgS85GZMkQZO3DFuwSJIr5FWXo3gY+1LnDBidQaW0qe2OuBjdMCtFXpTAC4byyidKGIq7pagXJvSidm5BbAA==",
          "blockHash": "BoFjoVJCvfD5Z1xTDhzCLQrJUXvJJ9fPgXVbKUTHt6Vs",
          "verificationType": 0,
          "chainId": 0,
          "protocol": "PROTOCOL_SOLANA",
          "ethSignature": "ObDgS85GZMkQZO3DFuwSJIr5FWXo3gY+1LnDBidQaW0qe2OuBjdMCtFXpTAC4byyidKGIq7pagXJvSidm5BbAA=="
        },
        "verificationAddEthAddressBody": {
          "address": "GYLkraPfvT3UtUbdxcHiVWV2EShBoZtqW1Bcq4VazUCt",
          "claimSignature": "ObDgS85GZMkQZO3DFuwSJIr5FWXo3gY+1LnDBidQaW0qe2OuBjdMCtFXpTAC4byyidKGIq7pagXJvSidm5BbAA==",
          "blockHash": "BoFjoVJCvfD5Z1xTDhzCLQrJUXvJJ9fPgXVbKUTHt6Vs",
          "verificationType": 0,
          "chainId": 0,
          "protocol": "PROTOCOL_SOLANA",
          "ethSignature": "ObDgS85GZMkQZO3DFuwSJIr5FWXo3gY+1LnDBidQaW0qe2OuBjdMCtFXpTAC4byyidKGIq7pagXJvSidm5BbAA=="
        }
      },
      "hash": "0x074547cae76087f144676ddeb923a298c8007311",
      "hashScheme": "HASH_SCHEME_BLAKE3",
      "signature": "aHLxD7PqE9x8pD2sEDz4ss+49YqyQb82e2OUZeQob3XRH/1myJOTtRi7mfSUgPvJedhipHPDKoYfbsYdtEgDAQ==",
      "signatureScheme": "SIGNATURE_SCHEME_ED25519",
      "signer": "0x0ab9bc023d15e25697928225f95f98669df9609b8b20a643c03f9d71a963b606"
    }
  ],
  "nextPageToken": ""
}
curl hubble/v1/verificationsByFid?fid=3824" | jq '.messages[].data.verificationAddEthAddressBody.claimSignature' -r | while read line
do
echo $line | base64 -d | od -c
done
0000000    D   F 331   M 021 344 301 316 325   X 327 036 370   W   S   5
0000020    Й  **   z   ; 303   Z   [ 023 373 030   1   b   ǐ  ** 207 322
0000040    S   H 261 343   A   ` 266   G 214   i 201 373   ج  ** 265   m
0000060  233   ɑ  ** 244 023 251 367 030 210 020 231 311   > 030 233 210
0000100  033
0000101
0000000    9 260 340   K 316   F   d 311 020   d 355 303 026 354 022   $
0000020  212 371 025   e 350 336 006   >   Թ  ** 303 006   '   P   i   m
0000040    *   {   c 256 006   7   L  \n 321   W 245   0 002   ἲ  **  **
0000060  211    ҆  **   " 256 351   j 005   ɽ  **   ( 235 233 220   [  \0
0000100
curl hubble/v1/verificationsByFid?fid=3824" | jq '.messages[].data.verificationAddEthAddressBody.claimSignature' -r | while read line
do
echo $line | base64 -d | od -c
done
0000000    D   F 331   M 021 344 301 316 325   X 327 036 370   W   S   5
0000020    Й  **   z   ; 303   Z   [ 023 373 030   1   b   ǐ  ** 207 322
0000040    S   H 261 343   A   ` 266   G 214   i 201 373   ج  ** 265   m
0000060  233   ɑ  ** 244 023 251 367 030 210 020 231 311   > 030 233 210
0000100  033
0000101
0000000    9 260 340   K 316   F   d 311 020   d 355 303 026 354 022   $
0000020  212 371 025   e 350 336 006   >   Թ  ** 303 006   '   P   i   m
0000040    *   {   c 256 006   7   L  \n 321   W 245   0 002   ἲ  **  **
0000060  211    ҆  **   " 256 351   j 005   ɽ  **   ( 235 233 220   [  \0
0000100

@chetankashetti is right, these solana claim signatures are not compatible with the replicator because they ends with a null byte.

hrbustor commented 8 months ago

I have the same problem, too.

image
saez0pub commented 8 months ago

There are two main effects because of this issue:

It needs a decision about the fields containing null characters, they can't be in a json field as is.

saez0pub commented 8 months ago

Maybe solved by #1770

Wazzymandias commented 8 months ago

We released replicator 0.3.5 that hopefully fixes this issue: https://github.com/farcasterxyz/hub-monorepo/tree/%40farcaster/replicator%400.3.5

Please upgrade to the latest replicator version and let us know if you're still facing issues

saez0pub commented 8 months ago

I've upgraded on this version, and doing a full replication to check this.

chetankashetti commented 8 months ago

upgraded to v0.3.5 which resolved this issue, Thanks team :)

sds commented 8 months ago

Closing as resolved! Thanks for the report @saez0pub, and @Wazzymandias for the fix.

saez0pub commented 8 months ago

I confirm it's resolved.