ConvertError Ed25519 public key

TeeVeeEss commented 10 months ago

Bug description

Trying to build a Shimmer chronicle from scratch. After a few days Inx-chronicle crashes complaining about not being able to convert "compressed bytes" to "Ed25519 public key". During that period shutting down and starting again was no problem. The shimmer node used for syncing is also healthy. The last milestone in the mongodb is 6430726:

Rust version

Rust version: from Dockerfile.debug

Chronicle version

Chronicle version (version number, commit, or branch): v1.0.0-rc.2

Hardware specification

Operating system: Arch Linux 6.6.4-arch1-1
RAM: 12 GB
Cores: 8
Device: Bare metal

Steps to reproduce the bug

Start syncing from milestone 0.
Shut down and restart a few times inx-chronicle and the node, that should not lead to problems.
Around milestone 6430726 inx-chronicle crashes and can't sync anymore.

Expected behaviour

Sync up to and including the LMI.

Actual behaviour

Syncing crashes and can't continue

Errors

docker compose logs inx-chronicle
inx-chronicle  | 2023-12-06T19:24:52.595733Z ERROR inx_chronicle::inx: error=Packable(Crypto(ConvertError { from: "compressed bytes", to: "Ed25519 public key" }))
inx-chronicle  | 2023-12-06T19:24:52.595763Z ERROR inx_chronicle::inx: error=Packable(Crypto(ConvertError { from: "compressed bytes", to: "Ed25519 public key" }))
inx-chronicle  | 2023-12-06T19:24:52.595849Z ERROR inx_chronicle: a worker failed with error: Packable(Crypto(ConvertError { from: "compressed bytes", to: "Ed25519 public key" }))
inx-chronicle  | Error: Packable(Crypto(ConvertError { from: "compressed bytes", to: "Ed25519 public key" }))
inx-chronicle  |
inx-chronicle  | Location:
inx-chronicle  |     src/bin/inx-chronicle/inx/mod.rs:347:25

Milestone 6430726 in the Mongo db:

{
  "_id": {
    "$binary": {
      "base64": "QoBV7IcY4eliFuV8a4qHYZanTRxy6E28fcnXDxxPvqI=",
      "subType": "00"
    }
  },
  "at": {
    "milestone_index": {
      "$numberLong": "6430726"
    },
    "milestone_timestamp": {
      "$numberLong": "1697593020"
    }
  },
  "payload": {
    "essence": {
      "index": {
        "$numberLong": "6430726"
      },
      "timestamp": {
        "$numberLong": "1697593020"
      },
      "protocol_version": 2,
      "previous_milestone_id": {
        "$binary": {
          "base64": "UZEQEb8x85JqE+kjfD5ezsCUW89IuCE85PqKZdG5SB4=",
          "subType": "00"
        }
      },
      "parents": [
        {
          "$binary": {
            "base64": "j/K3rDuBFDnIQynIYrctF0zQwC97Jyw3U9MZPHFSDv8=",
            "subType": "00"
          }
        },
        {
          "$binary": {
            "base64": "vHpJ4wuc5Lvkuhs7CMLfFbEyXlmHQKCb05iA05J0ZSQ=",
            "subType": "00"
          }
        }
      ],
      "inclusion_merkle_root": {
        "$binary": {
          "base64": "xBmCYtMQoKFFuAlVc9T4p6AELx0hz2zqn7euS2wwqfk=",
          "subType": "00"
        }
      },
      "applied_merkle_root": {
        "$binary": {
          "base64": "DldRwCblQ7Loqy6wYJnaodHl30d3j3eH+qtFzfEv46g=",
          "subType": "00"
        }
      },
      "metadata": {
        "$binary": {
          "base64": "jzfCAAAAAAC8eknjC5zku+S6GzsIwt8VsTJeWYdAoJvTmIDTknRlJA==",
          "subType": "00"
        }
      },
      "options": []
    },
    "signatures": [
      {
        "kind": "ed25519",
        "public_key": {
          "$binary": {
            "base64": "Fu4zVsIeQQoKqrQolgIbGoV+uNl6FKZv7ZsT1jTCExc=",
            "subType": "00"
          }
        },
        "signature": {
          "$binary": {
            "base64": "4qH7datetU74pPcQBaukZN8CJcaps80Ebay1OekSuuRtoDZ3TSVM4whpjfug8Uw8hppg/yoECykdAQ87tVQMAQ==",
            "subType": "00"
          }
        }
      },
      {
        "kind": "ed25519",
        "public_key": {
          "$binary": {
            "base64": "HfJheKeRQSb9jLk0x6dDcHN5TByM6ZMZFyQ2sdSXPro=",
            "subType": "00"
          }
        },
        "signature": {
          "$binary": {
            "base64": "kF2CfH2o59dJqhwUcKR9OGQYEX/BkG15oyBE0wWSuvrpxAmRkxSISxe5D5udHWoySSEVEyEJvX+LUjCLuR/qBw==",
            "subType": "00"
          }
        }
      },
      {
        "kind": "ed25519",
        "public_key": {
          "$binary": {
            "base64": "RUMtfHZ+FlhkAyYjMaclx+qgst156kQvNzyEWuNEOqk=",
            "subType": "00"
          }
        },
        "signature": {
          "$binary": {
            "base64": "r4SU15PaQ18sV8HUZZU6+XTmZ97n7/5o1Q4/S8zTEITlEKbxsnpCMuki59HwzM+pt5QUAV0J0WSfHU49D8cTBg==",
            "subType": "00"
          }
        }
      },
      {
        "kind": "ed25519",
        "public_key": {
          "$binary": {
            "base64": "SvZHkQukcAAQi4fGOr4FRWQ/myA+rO4rcTcpsEUJg/4=",
            "subType": "00"
          }
        },
        "signature": {
          "$binary": {
            "base64": "vb2tH+hgxuJ/2zUq56boBSasb1wRNuIJJbYsVUTkXH5jc4fpDR5AHph/eD1M30KiA4WV8rLQ+H2ehiHhtOBcBA==",
            "subType": "00"
          }
        }
      },
      {
        "kind": "ed25519",
        "public_key": {
          "$binary": {
            "base64": "caCXdESaCBRQpR4CRaHphQGQ+TUI/Y8hu5ucoWl2XzA=",
            "subType": "00"
          }
        },
        "signature": {
          "$binary": {
            "base64": "Fzrf8cYDj6BAh713A1IxCa0dwZGTH2zCfLUIvjsv7oKdQmdgdBbyNqY3T4FMt2unDf6bHqv3wCwh61Tx5deyCA==",
            "subType": "00"
          }
        }
      },
      {
        "kind": "ed25519",
        "public_key": {
          "$binary": {
            "base64": "mcfZdSwpXLVrVQGRAVq1pAIm+2MuiwLsFc/ldOoXz2c=",
            "subType": "00"
          }
        },
        "signature": {
          "$binary": {
            "base64": "lHCQpSpG00GBh3/cLP+0xIEdRA5sQ10eba/5gn2N4KlUb/Y/HfeesIes3Cj9BC8jWa0ognUTfK6mfvb31T6fBw==",
            "subType": "00"
          }
        }
      },
      {
        "kind": "ed25519",
        "public_key": {
          "$binary": {
            "base64": "nYe00lOLEHmbWC4lrORybZLXeY3ftpb/CORQ23kXya0=",
            "subType": "00"
          }
        },
        "signature": {
          "$binary": {
            "base64": "5218g2ePzep0wQ6cIY96OaTaKxHQZVi5tsqFzlr1yXVoKm/NNr08z/KGGEw3TwtyKpNLWuYwnpcpcrTPuXsiAA==",
            "subType": "00"
          }
        }
      },
      {
        "kind": "ed25519",
        "public_key": {
          "$binary": {
            "base64": "o3VRW/5a33/ttk70zr4eYh6FoFawzNXbcrwNR0Mlvzg=",
            "subType": "00"
          }
        },
        "signature": {
          "$binary": {
            "base64": "Qr0JgJbX9LaTbvIOLOJT5UqUtgv4pTge7vkjNmGVDoWI7tQFh5mQWwEFzS6WMQVo7r5OHyTlSE538/w+QgnEAg==",
            "subType": "00"
          }
        }
      },
      {
        "kind": "ed25519",
        "public_key": {
          "$binary": {
            "base64": "pQfSpZKl8EJO2FMGA8CKzr4IiuJiEekLeb/sCXCiOX8=",
            "subType": "00"
          }
        },
        "signature": {
          "$binary": {
            "base64": "mcz0IRkLDX8X6G5d068Wby6Y/J82onBv9CqMGbZZbmRrnR/CCo+HqZ579jVTSPZL7jutjULcWT9Kcq8Nh4CpDw==",
            "subType": "00"
          }
        }
      },
      {
        "kind": "ed25519",
        "public_key": {
          "$binary": {
            "base64": "qSGEFijWTD8IvTRBGLgQat4HLmjHdL7/MBNeA2GUSTo=",
            "subType": "00"
          }
        },
        "signature": {
          "$binary": {
            "base64": "s8J77WqFJvpnZQDfknKcTRHzrR/2JAT2ImZluGFwpL6fTTzOMC+fMeljXAnrDmTX1ikp/uFaUXCEYubGd6CHBg==",
            "subType": "00"
          }
        }
      }
    ]
  }
}

DaughterOfMars commented 9 months ago

This appears to be an issue with the data itself, as this occurs while unpacking a Block that we receive as a raw byte representation from the node. Alternatively, there could be a bug in the unpack logic, though I suspect this would have caused issues long before this milestone. Are you able to export the blocks within the erroneous milestone from the node?

TeeVeeEss commented 9 months ago

Exporting those blocks should be doable If you can assist me with building the curl command ;)

TeeVeeEss commented 9 months ago

curl -L -X GET 'http://127.0.0.1:14265/api/core/v2/milestones/by-index/6430726' -H 'Accept: application/json'|jq

{
  "type": 7,
  "index": 6430726,
  "timestamp": 1697593020,
  "protocolVersion": 2,
  "previousMilestoneId": "0x51911011bf31f3926a13e9237c3e5ecec0945bcf48b8213ce4fa8a65d1b9481e",
  "parents": [
    "0x8ff2b7ac3b811439c84329c862b72d174cd0c02f7b272c3753d3193c71520eff",
    "0xbc7a49e30b9ce4bbe4ba1b3b08c2df15b1325e598740a09bd39880d392746524"
  ],
  "inclusionMerkleRoot": "0xc4198262d310a0a145b8095573d4f8a7a0042f1d21cf6cea9fb7ae4b6c30a9f9",
  "appliedMerkleRoot": "0x0e5751c026e543b2e8ab2eb06099daa1d1e5df47778f7787faab45cdf12fe3a8",
  "metadata": "0x8f37c20000000000bc7a49e30b9ce4bbe4ba1b3b08c2df15b1325e598740a09bd39880d392746524",
  "signatures": [
    {
      "type": 0,
      "publicKey": "0x16ee3356c21e410a0aaab42896021b1a857eb8d97a14a66fed9b13d634c21317",
      "signature": "0xe2a1fb75ab5eb54ef8a4f71005aba464df0225c6a9b3cd046dacb539e912bae46da036774d254ce308698dfba0f14c3c869a60ff2a040b291d010f3bb5540c01"
    },
    {
      "type": 0,
      "publicKey": "0x1df26178a7914126fd8cb934c7a7437073794c1c8ce99319172436b1d4973eba",
      "signature": "0x905d827c7da8e7d749aa1c1470a47d386418117fc1906d79a32044d30592bafae9c409919314884b17b90f9b9d1d6a32492115132109bd7f8b52308bb91fea07"
    },
    {
      "type": 0,
      "publicKey": "0x45432d7c767e16586403262331a725c7eaa0b2dd79ea442f373c845ae3443aa9",
      "signature": "0xaf8494d793da435f2c57c1d465953af974e667dee7effe68d50e3f4bccd31084e510a6f1b27a4232e922e7d1f0cccfa9b79414015d09d1649f1d4e3d0fc71306"
    },
    {
      "type": 0,
      "publicKey": "0x4af647910ba47000108b87c63abe0545643f9b203eacee2b713729b0450983fe",
      "signature": "0xbdbdad1fe860c6e27fdb352ae7a6e80526ac6f5c1136e20925b62c5544e45c7e637387e90d1e401e987f783d4cdf42a2038595f2b2d0f87d9e8621e1b4e05c04"
    },
    {
      "type": 0,
      "publicKey": "0x71a09774449a081450a51e0245a1e9850190f93508fd8f21bb9b9ca169765f30",
      "signature": "0x173adff1c6038fa04087bd7703523109ad1dc191931f6cc27cb508be3b2fee829d4267607416f236a6374f814cb76ba70dfe9b1eabf7c02c21eb54f1e5d7b208"
    },
    {
      "type": 0,
      "publicKey": "0x99c7d9752c295cb56b550191015ab5a40226fb632e8b02ec15cfe574ea17cf67",
      "signature": "0x947090a52a46d34181877fdc2cffb4c4811d440e6c435d1e6daff9827d8de0a9546ff63f1df79eb087acdc28fd042f2359ad288275137caea67ef6f7d53e9f07"
    },
    {
      "type": 0,
      "publicKey": "0x9d87b4d2538b10799b582e25ace4726d92d7798ddfb696ff08e450db7917c9ad",
      "signature": "0xe76d7c83678fcdea74c10e9c218f7a39a4da2b11d06558b9b6ca85ce5af5c975682a6fcd36bd3ccff286184c374f0b722a934b5ae6309e972972b4cfb97b2200"
    },
    {
      "type": 0,
      "publicKey": "0xa375515bfe5adf7fedb64ef4cebe1e621e85a056b0ccd5db72bc0d474325bf38",
      "signature": "0x42bd098096d7f4b6936ef20e2ce253e54a94b60bf8a5381eeef9233661950e8588eed4058799905b0105cd2e96310568eebe4e1f24e5484e77f3fc3e4209c402"
    },
    {
      "type": 0,
      "publicKey": "0xa507d2a592a5f0424ed8530603c08acebe088ae26211e90b79bfec0970a2397f",
      "signature": "0x99ccf421190b0d7f17e86e5dd3af166f2e98fc9f36a2706ff42a8c19b6596e646b9d1fc20a8f87a99e7bf6355348f64bee3bad8d42dc593f4a72af0d8780a90f"
    },
    {
      "type": 0,
      "publicKey": "0xa921841628d64c3f08bd344118b8106ade072e68c774beff30135e036194493a",
      "signature": "0xb3c27bed6a8526fa676500df92729c4d11f3ad1ff62404f6226665b86170a4be9f4d3cce302f9f31e9635c09eb0e64d7d62929fee15a51708462e6c677a08706"
    }
  ]
}

TeeVeeEss commented 9 months ago

@DaughterOfMars is this enough? Not sure which route I should use to export the blocks you want.

DaughterOfMars commented 9 months ago

If I recall correctly, the URI would be http://127.0.0.1:14265/api/core/v2/milestones/by-index/6430726/blocks, which will return a list of block IDs. You would then need to get all of the blocks using http://127.0.0.1:14265/api/core/v2/blocks/{blockId}.

If you are able to run a small rust program, you could use iota-sdk to create a client, connect to your node, and call the API requests in a loop. I can write the program for you if this is something you want to do.

TeeVeeEss commented 9 months ago

curl -L -X GET 'http://127.0.0.1:14265/api/core/v2/milestones/by-index/6430726/blocks' -H 'Accept: application/json'|jq

gives a 404. I can run the a rust program, but not write it ;)

DaughterOfMars commented 9 months ago

No problem. @Thoralf-M found the offending block! We're investigating now, but I would guess there is a bug in the iota-crypto library.

Thoralf-M commented 9 months ago

Just leaving this here in case it's needed again in the future

use std::{collections::HashMap, pin::Pin};

use futures::FutureExt;
use iota_sdk::{
    client::{Client, Result},
    types::block::{Block, BlockId},
};

#[tokio::main]
async fn main() -> Result<()> {
    let milestone_index = 6430727;

    let client = Client::builder()
        .with_node("https://chronicle.shimmer.network")?
        .with_ignore_node_health()
        .finish()
        .await?;

    let milestone = client.get_milestone_by_index(milestone_index).await?;
    println!("{milestone:#?}");

    let mut milestone_blocks = HashMap::new();
    get_parents_in_milestone_index(
        &client,
        milestone.essence().parents().to_vec(),
        milestone_index,
        &mut milestone_blocks,
    )
    .await?;

    println!("milestone {milestone_index} blocks: {milestone_blocks:#?}");
    Ok(())
}

fn get_parents_in_milestone_index<'a>(
    client: &'a Client,
    parents: Vec<BlockId>,
    milestone_index: u32,
    milestone_blocks: &'a mut HashMap<BlockId, Block>,
) -> Pin<Box<dyn futures::Future<Output = Result<()>> + std::marker::Send + 'a>> {
    async move {
        for parent in parents {
            if milestone_blocks.contains_key(&parent) {
                continue;
            }
            let metadata = client.get_block_metadata(&parent).await?;
            if metadata.referenced_by_milestone_index.unwrap() == milestone_index {
                println!("Requesting block {parent}");
                let block = client.get_block(&parent).await?;
                milestone_blocks.insert(parent, block.clone());
                get_parents_in_milestone_index(client, block.parents().to_vec(), milestone_index, milestone_blocks)
                    .await?;
            }
        }
        Ok(())
    }
    .boxed()
}

with https://github.com/iotaledger/iota-sdk/commit/2b44b886538b3c5dbbaf55a8ace38e8f44273bfe

TeeVeeEss commented 9 months ago

Thanks, I will try to run the code with my internal node !

TeeVeeEss commented 9 months ago

I'm getting a compile error for the code from @Thoralf-M

PS D:\temp\iota_sdk_test\block-test> cargo build
   Compiling iota-sdk v1.1.3 (https://github.com/iotaledger/iota-sdk?branch=develop#2b44b886)
   Compiling block-test v0.1.0 (D:\temp\iota_sdk_test\block-test)
error[E0432]: unresolved import `futures`
 --> src\main.rs:3:5
  |
3 | use futures::FutureExt;
  |     ^^^^^^^ use of undeclared crate or module `futures`

error[E0433]: failed to resolve: use of undeclared crate or module `tokio`
 --> src\main.rs:9:3
  |
9 | #[tokio::main]
  |   ^^^^^ use of undeclared crate or module `tokio`

error[E0433]: failed to resolve: use of undeclared crate or module `futures`
  --> src\main.rs:40:18
   |
40 | ) -> Pin<Box<dyn futures::Future<Output = Result<()>> + std::marker::Send + 'a>> {
   |                  ^^^^^^^ use of undeclared crate or module `futures`

Some errors have detailed explanations: E0432, E0433.
For more information about an error, try `rustc --explain E0432`.
error: could not compile `block-test` (bin "block-test") due to 3 previous errors

rustup update stable
info: syncing channel updates for 'stable-x86_64-pc-windows-msvc'

  stable-x86_64-pc-windows-msvc unchanged - rustc 1.75.0 (82e1608df 2023-12-21)

info: checking for self-update

[package]
name = "block-test"
version = "0.1.0"
edition = "2021"

# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html

[dependencies]
iota-sdk = { git = "https://github.com/iotaledger/iota-sdk", branch = "develop" }

DaughterOfMars commented 9 months ago

You need to add the dependency to the Cargo manifest. The simplest way is like this:

futures = "*"

TeeVeeEss commented 9 months ago

.....
Requesting block 0x70fbccfa2b968ef39e7e222a718e6abd94d47fcc64873f09196c1ece94cb33a7
Requesting block 0x530ff700606bf496754e9176a206c7ec6c48529f4440ca5a09f2e4a66399552a
Requesting block 0x9b41be3155019465385148b2b46d13ab14b10eff0666d9ca522006982655159d
Requesting block 0x1227b05634468b57ee9431cc309d9d0bf98d90ae8cf69231d9215e079c0be42a
Requesting block 0xb7e1c5885e4f4b8bb09aa96727469bf5647d2aec48db39a10d8f91237e0462b9
Requesting block 0x4b21ca29d2c51fd8c05e985437989fb3e7c7f674da34a068668367167367459c
Error: Block(Crypto(ConvertError { from: "compressed bytes", to: "Ed25519 public key" }))

Indeed, last line shows the error!

TeeVeeEss commented 8 months ago

Any progress on this bug? Would like to finish my own synced chronicle...

Thoralf-M commented 8 months ago

@TeeVeeEss I think it's fixed in v1.0.0-rc.3, but there is already a newer release https://github.com/iotaledger/inx-chronicle/releases/tag/v1.0.0-rc.4 with more other fixes, please try that

TeeVeeEss commented 8 months ago

Just updated to rc.4 but there is now another error:

inx-chronicle  | 2024-02-03T15:13:56.118528Z ERROR chronicle::db::mongodb::collections::ledger_update: error=Kind: An invalid argument was provided: No documents provided to insert_many, labels: {}
inx-chronicle  | 2024-02-03T15:13:56.123680Z ERROR chronicle::db::mongodb::collections::ledger_update: error=Kind: An invalid argument was provided: No documents provided to insert_many, labels: {}
inx-chronicle  | 2024-02-03T15:13:56.128983Z ERROR chronicle::db::mongodb::collections::ledger_update: error=Kind: An invalid argument was provided: No documents provided to insert_many, labels: {}
inx-chronicle  | 2024-02-03T15:13:56.134137Z ERROR chronicle::db::mongodb::collections::ledger_update: error=Kind: An invalid argument was provided: No documents provided to insert_many, labels: {}
inx-chronicle  | 2024-02-03T15:13:56.139417Z ERROR chronicle::db::mongodb::collections::ledger_update: error=Kind: An invalid argument was provided: No documents provided to insert_many, labels: {}
inx-chronicle  | 2024-02-03T15:13:56.144480Z ERROR chronicle::db::mongodb::collections::ledger_update: error=Kind: An invalid argument was provided: No documents provided to insert_many, labels: {}
inx-chronicle  | 2024-02-03T15:13:56.149640Z ERROR chronicle::db::mongodb::collections::ledger_update: error=Kind: An invalid argument was provided: No documents provided to insert_many, labels: {}
inx-chronicle  | 2024-02-03T15:13:56.154840Z ERROR chronicle::db::mongodb::collections::ledger_update: error=Kind: An invalid argument was provided: No documents provided to insert_many, labels: {}
inx-chronicle  | 2024-02-03T15:13:56.159911Z ERROR chronicle::db::mongodb::collections::ledger_update: error=Kind: An invalid argument was provided: No documents provided to insert_many, labels: {}
inx-chronicle  | 2024-02-03T15:13:56.165419Z ERROR chronicle::db::mongodb::collections::ledger_update: error=Kind: An invalid argument was provided: No documents provided to insert_many, labels: {}
inx-chronicle  | Error: Kind: An invalid argument was provided: No documents provided to insert_many, labels: {}
inx-chronicle  |
inx-chronicle  | Location:
inx-chronicle  |     src/bin/inx-chronicle/migrations/migrate_2.rs:51:21

TeeVeeEss commented 8 months ago

My chronicle.application_state in the Mongo db has only 1 record:

{
  "_id": {
    "$oid": "655ddffc9561feacddca56b1"
  },
  "last_migration": {
    "id": {
      "$numberLong": "1"
    },
    "app_version": "1.0.0-beta.37",
    "date": [
      2023,
      73
    ]
  },
  "starting_index": {
    "milestone_index": {
      "$numberLong": "7008862"
    },
    "milestone_timestamp": {
      "$numberLong": "1700650996"
    }
  }
}

TeeVeeEss commented 8 months ago

In the end I decided to start from scratch again. The application state is now:

{
  "_id": {
    "$oid": "65bfa4e6677b1fced39f0215"
  },
  "last_migration": {
    "id": {
      "$numberLong": "2"
    },
    "app_version": "1.0.0-rc.3",
    "date": [
      2024,
      12
    ]
  },
  "starting_index": {
    "milestone_index": {
      "$numberLong": "8227219"
    },
    "milestone_timestamp": {
      "$numberLong": "1707058401"
    }
  }
}

Closing the issue, but not being able to migrate is maybe another bug.

iotaledger / inx-chronicle