Missing blocks but unsure why

Hello -

I initially posted yesterday that my pool was expecting a block but never displayed an outcome (either confirmed or missed), however, since then it is now appearing the block was missed AND a second block was missed now, so two in a row. I have searched everywhere and cannot find why. Here is what I have checked:

  1. Two relays are synced and running great. Both are connected to 10+ peers.
  2. BP is synced with both relays.
  3. KES is not expired, and rotated several times in the past 12 hours just in case.
  4. TX data is incrementing on all three nodes.

Here’s a picture of gliveview. Any ideas what could be wrong or how I can investigate further?!

image

1 Like

Hello,

do you see your Producer IP to IN peers in your Relays?

Cheers,

Hello Alex, yes, I do. Both relays show my BP IP address beneath the IN section.

Then, I am sure it was about badluck and other pool won the slot “battle”;

When is the next one schedueled?

This one should be ok…

Cheers,

Thanks Alex, but unfortunately I believe something must be wrong as we just missed another. That’s three in a row now (and have never actually minted a block before). This is very frustrating as everything appears to be correct and working as it should. I am out of ideas.

What is ur ticker?

It’s TYGAR

Looks fine,

Is it possible that CNCLI is wrong about which blocks it believes we should receive? I tried looking in the nod0.json log and finding that block but it doesn’t look like there’s anything special to me that indicated we were supposed to mint it? The block was: 23538172

{"at":"2021-03-07T08:07:42.00Z","env":"1.25.1:9a733","ns":["cardano.node.ForgeTime"],"data":{},"app":[ ],"msg":"","pid":"1068","loc":null,"host":"[MY_HOST_NAME]","sev":"Info","thread":"73"}
> {"at":"2021-03-07T08:07:43.00Z","env":"1.25.1:9a733","ns":["cardano.node.LeadershipCheck"],"data":{"credentials":"Cardano","kind":"TraceStartLeadershipCheck","delegMapSize":321821,"slot":23538172,"chainDensity":4.8512492e-2,"utxoSize":1443591},"app":[],"msg":"","pid":"1068","loc":null,"host":"[MY_HOST_NAME]","sev":"Info","thread":"73"}
> {"at":"2021-03-07T08:07:43.00Z","env":"1.25.1:9a733","ns":["cardano.node.ForgeTime"],"data":{},"app":[],"msg":"","pid":"1068","loc":null,"host":"[MY_HOST_NAME]":"Info","thread":"73"}
> {"at":"2021-03-07T08:07:43.00Z","env":"1.25.1:9a733","ns":["cardano.node.ForgeTime"],"data":{},"app":[],"msg":"","pid":"1068","loc":null,"host":"[MY_HOST_NAME]","sev":"Info","thread":"73"}
> {"at":"2021-03-07T08:07:43.00Z","env":"1.25.1:9a733","ns":["cardano.node.ForgeTime"],"data":{},"app":[],"msg":"","pid":"1068","loc":null,"host":"[MY_HOST_NAME]","sev":"Info","thread":"73"}
> {"at":"2021-03-07T08:07:43.00Z","env":"1.25.1:9a733","ns":["cardano.node.ForgeTime"],"data":{},"app":[],"msg":"","pid":"1068","loc":null,"host":"[MY_HOST_NAME]","sev":"Info","thread":"73"}
> {"at":"2021-03-07T08:07:43.00Z","env":"1.25.1:9a733","ns":["cardano.node.Forge"],"data":{"credentials":"Cardano","val":{"kind":"TraceNodeNotLeader","slot":23538172}},"app":[],"msg":"","pid":"1068","loc":null,"host":"[MY_HOST_NAME]","sev":"Info","thread":"73"}
> {"at":"2021-03-07T08:07:43.00Z","env":"1.25.1:9a733","ns":["cardano.node.ForgeTime"],"data":{},"app":[],"msg":"","pid":"1068","loc":null,"host":"[MY_HOST_NAME]","sev":"Info","thread":"73"}

Is there a different log I should check?

Hello,

Cheers,

I mean I’m not seeing the phrase “TraceAdoptedBlock” anywhere in my logs at all… So what does that indicate?

@Alexd1985, When I first start my node, I see the following message in journalctl:

cnode-logmonitor[135736]: Node socket not set in env file and automatic detection failed! [source: logMonitor.sh]
cnode[135735]: WARN: A prior running Cardano node was not cleanly shutdown, socket file still exists. Cleaning up.
cnode[135863]: Listening on http://127.0.0.1:12798
cnode-cncli-sync[135871]: Looks like cardano-node is running with socket-path as /opt/cardano/cnode/sockets/node0.socket, but the actual socket file does not exist.
cnode-logmonitor[136777]: This could occur if the node hasnt completed startup or if a second instance of node startup was attempted!
cnode-logmonitor[136777]: If this does not resolve automatically in a few minutes, you might want to restart your node and try again.
cnode-cncli-validate[136038]: ~ CNCLI Block Validation started ~

Is the bolded line normal? What’s strange is that if I uncomment the socket line in the env file, my node never starts, even though the path looks to be right in there as well:

SOCKET=“${CNODE_HOME}/sockets/node0.socket”

Should be normal, as long ur node start it is fine;

@Alexd1985, I am starting to think my BP log files don’t look quite right. They don’t match at all the log snippet from the post you provided above.

Do you have a portion of your logs you could provide without any sensitive data so that I can compare?

Those logs are not from mine… and there are from another era (I think Allegra) so it is possible to be different…

When is it scheduled the next slot?
Don’t need to tell me the exact time :wink:
Cheers,

| 3 | leader | 2021-03-11 2X:XX:14 UTC

When did u checked the slots assigned… before epoch start?

Can u check again?

Try ./cncli.sh leaderlog force

I just checked moments ago:

{
  "status": "ok",
  "epoch": 252,
  "epochNonce": "e3d399802317e4b8077f962007340c69f45a841f76723af6591705552e28c17e",
  "epochSlots": 3,
  "epochSlotsIdeal": 1.16,
  "maxPerformance": 258.62,
  "poolId": "f8e64037e3917cd7cb94969a5374e11b9e6c939b4b69118a8eb4509f",
  "sigma": 0.00005949902209317627,
  "activeStake": 1349199357104,
  "totalActiveStake": 22675992136326807,
  "d": 0.1,
  "f": 0.05,
  "assignedSlots": [
    {
      "no": 1,
      "slot": 23512812,
      "slotInEpoch": 12012,
      "at": "2021-03-06T20:05:03-05:00"
    },
    {
      "no": 2,
      "slot": 23538172,
      "slotInEpoch": 37372,
      "at": "2021-03-07T03:07:43-05:00"
    },
    {
      "no": 3,
      "slot": XXXXXX,
      "slotInEpoch": XXXXX,
      "at": "2021-03-11T2X:XX:14-05:00"
    }
  ]
}

none of them were created… are u using chrony? For a better time synchronization?

image

image

Cheers,

@Alexd1985, no, I am not, but can look into that. Thank you for the suggestion. What is strange to me is that in my block producer logs for one of those expected slots (23538172 for example), I do not see anything like it even attempted or was aware of making a block. Shouldn’t there be some type of error or alert?

{“at”:“2021-03-07T08:07:42.00Z”,“env”:“1.25.1:9a733”,“ns”:[“cardano.node.ForgeTime”],“data”:{},“app”:,“msg”:"",“pid”:“1068”,“loc”:null,“host”:"[MY_HOST_NAME]",“sev”:“Info”,“thread”:“73”}
{“at”:“2021-03-07T08:07:43.00Z”,“env”:“1.25.1:9a733”,“ns”:[“cardano.node.LeadershipCheck”],“data”:{“credentials”:“Cardano”,“kind”:“TraceStartLeadershipCheck”,“delegMapSize”:321821,“slot”:**23538172**,“chainDensity”:4.8512492e-2,“utxoSize”:1443591},“app”:,“msg”:"",“pid”:“1068”,“loc”:null,“host”:"[MY_HOST_NAME]",“sev”:“Info”,“thread”:“73”}
{“at”:“2021-03-07T08:07:43.00Z”,“env”:“1.25.1:9a733”,“ns”:[“cardano.node.ForgeTime”],“data”:{},“app”:,“msg”:"",“pid”:“1068”,“loc”:null,“host”:"[MY_HOST_NAME]":“Info”,“thread”:“73”}
{“at”:“2021-03-07T08:07:43.00Z”,“env”:“1.25.1:9a733”,“ns”:[“cardano.node.ForgeTime”],“data”:{},“app”:,“msg”:"",“pid”:“1068”,“loc”:null,“host”:"[MY_HOST_NAME]",“sev”:“Info”,“thread”:“73”}
{“at”:“2021-03-07T08:07:43.00Z”,“env”:“1.25.1:9a733”,“ns”:[“cardano.node.ForgeTime”],“data”:{},“app”:,“msg”:"",“pid”:“1068”,“loc”:null,“host”:"[MY_HOST_NAME]",“sev”:“Info”,“thread”:“73”}
{“at”:“2021-03-07T08:07:43.00Z”,“env”:“1.25.1:9a733”,“ns”:[“cardano.node.ForgeTime”],“data”:{},“app”:,“msg”:"",“pid”:“1068”,“loc”:null,“host”:"[MY_HOST_NAME]",“sev”:“Info”,“thread”:“73”}
{“at”:“2021-03-07T08:07:43.00Z”,“env”:“1.25.1:9a733”,“ns”:[“cardano.node.Forge”],“data”:{“credentials”:“Cardano”,“val”:{“kind”:“TraceNodeNotLeader”,“slot”:**23538172**}},“app”:,“msg”:"",“pid”:“1068”,“loc”:null,“host”:"[MY_HOST_NAME]",“sev”:“Info”,“thread”:“73”}
{“at”:“2021-03-07T08:07:43.00Z”,“env”:“1.25.1:9a733”,“ns”:[“cardano.node.ForgeTime”],“data”:{},“app”:,“msg”:"",“pid”:“1068”,“loc”:null,“host”:"[MY_HOST_NAME]",“sev”:“Info”,“thread”:“73”}