Errors are logged when deposit or vote was already seen

[Ruteri]

When a deposit or a vote (and possibly other commits) is processed and the transaction was already seen, the node logs it as ERROR:
2019-03-26 16:29:09 [finalization] ERROR: IsVotable: validator=c8c07f4cd9697c3ee59caa53daf27b4f1f6f5d68 has already voted for target_epoch=6.
2019-03-26 15:34:05 [finalization] ERROR: ValidateDeposit: validator=f9e3d58a3c4214e1d973a942e65a2c7766004a9e with the deposit already exists.

The node also logs the mempool rejection (which is expected):
2019-03-26 15:34:06 [ net] Reject tx code 16: bad-deposit-duplicate: hash eb823d92d5eb9ddf65dddbef1b6e83999723c9f22b76b8fb36da2378b3e5be81

Receiving deposits or votes multiple times is expected, as the deposits and votes are broadcasted. The errors in the logs look as if something isn't working (that is usually the meaning of "ERROR", all capital letters). I think the node should log that the deposit or the vote was already seen (deposit-already-known), as it does with regular transactions: 2019-03-26 16:42:41 [ net] Reject tx code 18: txn-already-known: hash 8e890a835ee43a641def2fecea64f6ce4bea022de2a160cddede66dbf3af439e.

[frolosofsky]

There's also a lot of false ERROR messages happens during commits-full-sync. In the commits handler, we record the vote which makes a check against the current activeChain.Tip. In my opinion, such a check must be performed against the tip only in case of ATMP. In any other case, it must be finalization state stored for the previous block index. The reason is that during commits-full-sync, the tip could be:
a) in the future in case of forks
b) in the past in case of initial sync: we process commits much faster rather than connecting corresponding blocks to the main chain. Moreover, in case of fast-sync Tip=Genesis always.

We had such a conversation with @Gnappuraz a couple of times but I don't finally understand why we stand with the current approach.

[Gnappuraz]

@Ruteri I agree that ERROR is misplaced and we should just mention that we already saw that deposit or that vote.

[Ruteri]

@frolosofsky this also happens in normal circumstances

[Ruteri]

Fixed in #990

[Ruteri]

The issue is still there

[spiritlcx]

I find that it is not very convenient to locate the file name, function name, and the line number when reading debug log. Do you think it is a good idea to add these parts?

[Ruteri]

I find that it is not very convenient to locate the file name, function name, and the line number when reading debug log. Do you think it is a good idea to add these parts?

Hi,
We actually do log the function name. You can see it after the severity (IsVotable, ValidateDeposit), it comes from the __func__ identifier. Usually it's enough to pin down where the error is coming from. If you have something specific in mind maybe post it here.