node icon indicating copy to clipboard operation
node copied to clipboard

Provider creates a bid but never shows up on blockchain

Open hydrogen18 opened this issue 4 years ago • 9 comments

I got one successful deployment on the latest master but can't get anymore it seems.

The provider logs that bids are created, but it never shows up in akash events.

On the validator I found that it records a valid TX followed by an invalid TX while this is going on. I'm still unwrapping what is happening here

Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Signed and pushed vote err=null height=3421 module=consensus round=0 vote={"block_id":{"hash":"AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA","parts":{"hash":"C58A2648899C1E26CE911CA78FDDC3D2AA46202224AF2C69AF28F3856C739ABA","total":1}},"height":3421,"round":0,"signature":"LbdrGKjzvVdxX3n08fHmkHUW/BBBdJlraQBzeJ7g+DkaW0nrf/q+3btGxQ/svDI9Q17KA8sPLPBHDwte06wwBw==","timestamp":"2021-02-15T21:19:52.165946546Z","type":2,"validator_address":"D0CBA5174AD81B78D8392322BC49B27414A1346F","validator_index":2}
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Added to precommit module=consensus precommits="VoteSet{H:3421 R:0 T:SIGNED_MSG_TYPE_PRECOMMIT +2/3:<nil>(0.3333333333333333) BA{3:__x} map[]}" vote={"block_id":{"hash":"AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA","parts":{"hash":"C58A2648899C1E26CE911CA78FDDC3D2AA46202224AF2C69AF28F3856C739ABA","total":1}},"height":3421,"round":0,"signature":"LbdrGKjzvVdxX3n08fHmkHUW/BBBdJlraQBzeJ7g+DkaW0nrf/q+3btGxQ/svDI9Q17KA8sPLPBHDwte06wwBw==","timestamp":"2021-02-15T21:19:52.165946546Z","type":2,"validator_address":"D0CBA5174AD81B78D8392322BC49B27414A1346F","validator_index":2}
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Added to precommit module=consensus precommits="VoteSet{H:3421 R:0 T:SIGNED_MSG_TYPE_PRECOMMIT +2/3:<nil>(0.6666666666666666) BA{3:_xx} map[]}" vote={"block_id":{"hash":"AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA","parts":{"hash":"C58A2648899C1E26CE911CA78FDDC3D2AA46202224AF2C69AF28F3856C739ABA","total":1}},"height":3421,"round":0,"signature":"WSFV2B5ME8QGnN4GKPXzPVrmHNlqO/wbnDGBz8if1QeU0TgDjAnKBiAbgYPD/V9DObvg9ViCjGV25jRJgS2pDg==","timestamp":"2021-02-15T21:19:52.171945152Z","type":2,"validator_address":"50B0870F21DA452CB453A68D41C5289BCC775814","validator_index":1}
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Added to precommit module=consensus precommits="VoteSet{H:3421 R:0 T:SIGNED_MSG_TYPE_PRECOMMIT +2/3:AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA:1:C58A2648899C(1) BA{3:xxx} map[]}" vote={"block_id":{"hash":"AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA","parts":{"hash":"C58A2648899C1E26CE911CA78FDDC3D2AA46202224AF2C69AF28F3856C739ABA","total":1}},"height":3421,"round":0,"signature":"GhzzarnO8k+yGDlFzTY2eXLs62iz19rIquwyB9tiI/IWHceDJzhSz9WIH7Ovf6ZvH0GklUlKvmUOJzxKGAonCQ==","timestamp":"2021-02-15T21:19:52.171084461Z","type":2,"validator_address":"4FF4CBC88D7C6F89A88D9B11F41C8265BDDA32AA","validator_index":0}
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF enterCommit(3421/0). Current: 3421/0/RoundStepPrecommit commitRound=0 height=3421 module=consensus
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Commit is for locked block. Set ProposalBlock=LockedBlock blockHash=AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA commitRound=0 height=3421 module=consensus
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Finalizing commit of block with N txs N=1 hash=AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA height=3421 module=consensus root=003C219900DD7BC553B7F25FC52942C6284030709CAF5FF7884B6DC221669692
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Block{
Feb 15 21:19:52 edu-testnet03 akash[32931]:   Header{
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Version:        {11 0}
Feb 15 21:19:52 edu-testnet03 akash[32931]:     ChainID:        local
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Height:         3421
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Time:           2021-02-15 21:19:46.852651192 +0000 UTC
Feb 15 21:19:52 edu-testnet03 akash[32931]:     LastBlockID:    2579553CF0AC23BF9C02C5279357B66DD92CE39AC665278F24781E57F4A89A01:1:D203FDAC48E1
Feb 15 21:19:52 edu-testnet03 akash[32931]:     LastCommit:     9441B154834E0A1A00A7A1C9F7A3AB1FFC97DB03DD8C2C09F7D8FCB2EE832302
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Data:           3D09CCF38DF3D020D4E8FEE93227D83C4D21581F20351616948A245FF845E6B8
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Validators:     E83D099C3A1884DE160B1CD53A9DAC0AC02483383054A4E7509BFF001CF109C7
Feb 15 21:19:52 edu-testnet03 akash[32931]:     NextValidators: E83D099C3A1884DE160B1CD53A9DAC0AC02483383054A4E7509BFF001CF109C7
Feb 15 21:19:52 edu-testnet03 akash[32931]:     App:            003C219900DD7BC553B7F25FC52942C6284030709CAF5FF7884B6DC221669692
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Consensus:      048091BC7DDC283F77BFBF91D73C44DA58C3DF8A9CBC867405D8B7F3DAADA22F
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Results:        E3B0C44298FC1C149AFBF4C8996FB92427AE41E4649B934CA495991B7852B855
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Evidence:       E3B0C44298FC1C149AFBF4C8996FB92427AE41E4649B934CA495991B7852B855
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Proposer:       50B0870F21DA452CB453A68D41C5289BCC775814
Feb 15 21:19:52 edu-testnet03 akash[32931]:   }#AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA
Feb 15 21:19:52 edu-testnet03 akash[32931]:   Data{
Feb 15 21:19:52 edu-testnet03 akash[32931]:     AAC39CC8FB0E3B4FB6FE4BBD6EBFBE250ECA5EDECEFD0FD0751EA02B554C16DC (391 bytes)
Feb 15 21:19:52 edu-testnet03 akash[32931]:   }#3D09CCF38DF3D020D4E8FEE93227D83C4D21581F20351616948A245FF845E6B8
Feb 15 21:19:52 edu-testnet03 akash[32931]:   EvidenceData{
Feb 15 21:19:52 edu-testnet03 akash[32931]:     
Feb 15 21:19:52 edu-testnet03 akash[32931]:   }#E3B0C44298FC1C149AFBF4C8996FB92427AE41E4649B934CA495991B7852B855
Feb 15 21:19:52 edu-testnet03 akash[32931]:   Commit{
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Height:     3420
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Round:      0
Feb 15 21:19:52 edu-testnet03 akash[32931]:     BlockID:    2579553CF0AC23BF9C02C5279357B66DD92CE39AC665278F24781E57F4A89A01:1:D203FDAC48E1
Feb 15 21:19:52 edu-testnet03 akash[32931]:     Signatures:
Feb 15 21:19:52 edu-testnet03 akash[32931]:       CommitSig{6CE6AF739342 by 4FF4CBC88D7C on 2 @ 2021-02-15T21:19:46.852651192Z}
Feb 15 21:19:52 edu-testnet03 akash[32931]:       CommitSig{DF626A3EA00A by 50B0870F21DA on 2 @ 2021-02-15T21:19:46.848878386Z}
Feb 15 21:19:52 edu-testnet03 akash[32931]:       CommitSig{241113F040D5 by D0CBA5174AD8 on 2 @ 2021-02-15T21:19:46.853184817Z}
Feb 15 21:19:52 edu-testnet03 akash[32931]:   }#9441B154834E0A1A00A7A1C9F7A3AB1FFC97DB03DD8C2C09F7D8FCB2EE832302
Feb 15 21:19:52 edu-testnet03 akash[32931]: }#AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA module=consensus
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF minted coins from module account amount=391459uakt from=mint module=x/bank
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF created order order={"dseq":3419,"gseq":1,"oseq":1,"owner":"akash19dnhammcj3vf9dzgmtgg7pc8ujecn5azlzcu09"}
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Executed block height=3421 invalidTxs=0 module=state validTxs=1
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF commit synced commit=436F6D6D697449447B5B31323220393620343320363220373920313739203132332034372031363520333820323032203438203138352031303320373420323135203134372038312032333220313934203132322031343120313830203230352032323220313033203139342032333820323720313139203437203138385D3A4435447D
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Committed state appHash=7A602B3E4FB37B2FA526CA30B9674AD79351E8C27A8DB4CDDE67C2EE1B772FBC height=3421 module=state txs=1
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Indexed block height=3421 module=txindex
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Added good transaction height=3421 module=mempool res={"check_tx":{"code":0,"codespace":"","data":"","events":[],"gas_used":"49873","gas_wanted":"200000","info":"","log":"[]"}} total=1 tx=EDD6D1A359F4A727C0959FC22B2D2D7E25954C29443BC3EBDB4FC5F99E686061
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Could not check tx err="tx already exists in cache" module=mempool tx=EDD6D1A359F4A727C0959FC22B2D2D7E25954C29443BC3EBDB4FC5F99E686061
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Could not check tx err="tx already exists in cache" module=mempool tx=EDD6D1A359F4A727C0959FC22B2D2D7E25954C29443BC3EBDB4FC5F99E686061
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Could not check tx err="tx already exists in cache" module=mempool tx=EDD6D1A359F4A727C0959FC22B2D2D7E25954C29443BC3EBDB4FC5F99E686061
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Could not check tx err="tx already exists in cache" module=mempool tx=EDD6D1A359F4A727C0959FC22B2D2D7E25954C29443BC3EBDB4FC5F99E686061
Feb 15 21:19:52 edu-testnet03 akash[32931]: 9:19PM INF Could not check tx err="tx already exists in cache" module=mempool tx=EDD6D1A359F4A727C0959FC22B2D2D7E25954C29443BC3EBDB4FC5F99E686061
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Timed out dur=4972.754719 height=3422 module=consensus round=0 step=1
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF enterNewRound(3422/0). Current: 3422/0/RoundStepNewHeight height=3422 module=consensus round=0
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF enterPropose(3422/0). Current: 3422/0/RoundStepNewRound height=3422 module=consensus round=0
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF enterPropose: Our turn to propose height=3422 module=consensus privValidator={"Key":{"address":"D0CBA5174AD81B78D8392322BC49B27414A1346F","priv_key":"smfTKLO2MgK4T4V+Eij2F+MKxqBG+jZK7EZgiVXnplaiUmwZ1qJ8S3x++n8Jc6cRBVOEbAO/g3xltVJW48cl+Q==","pub_key":"olJsGdaifEt8fvp/CXOnEQVThGwDv4N8ZbVSVuPHJfk="},"LastSignState":{"height":3421,"round":0,"signature":"LbdrGKjzvVdxX3n08fHmkHUW/BBBdJlraQBzeJ7g+DkaW0nrf/q+3btGxQ/svDI9Q17KA8sPLPBHDwte06wwBw==","signbytes":"690802115D0D00000000000022480A20AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA122408011220C58A2648899C1E26CE911CA78FDDC3D2AA46202224AF2C69AF28F3856C739ABA2A0B08F8CAAB810610B2C9904F32056C6F63616C","step":3}} proposer=D0CBA5174AD81B78D8392322BC49B27414A1346F round=0
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Signed proposal height=3422 module=consensus proposal={"Type":32,"block_id":{"hash":"8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456","parts":{"hash":"030463EB2E62DE88502A174EC64BE9DB9F96845086CB63FDEF91CA94EAD4F78A","total":1}},"height":3422,"pol_round":-1,"round":0,"signature":"Hcplfr3G7+rgBOOanN/wn9zXVqhJynhH6MWxcZoB2g5+woUHB5dXV264+o8LKC1+pWTteUO7axBZlIrNFieECw==","timestamp":"2021-02-15T21:19:57.271748693Z"} round=0
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456","parts":{"hash":"030463EB2E62DE88502A174EC64BE9DB9F96845086CB63FDEF91CA94EAD4F78A","total":1}},"height":3422,"pol_round":-1,"round":0,"signature":"Hcplfr3G7+rgBOOanN/wn9zXVqhJynhH6MWxcZoB2g5+woUHB5dXV264+o8LKC1+pWTteUO7axBZlIrNFieECw==","timestamp":"2021-02-15T21:19:57.271748693Z"}
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Received complete proposal block hash=8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456 height=3422 module=consensus
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF enterPrevote(3422/0). Current: 3422/0/RoundStepPropose module=consensus
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF enterPrevote: ProposalBlock is valid height=3422 module=consensus round=0
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Signed and pushed vote err=null height=3422 module=consensus round=0 vote={"block_id":{"hash":"8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456","parts":{"hash":"030463EB2E62DE88502A174EC64BE9DB9F96845086CB63FDEF91CA94EAD4F78A","total":1}},"height":3422,"round":0,"signature":"GE3VJRd7J+c7VNvgzpIAF6ri6nHqJx1zxPk9LXwKlpP3ejaaaaRGeMxHzcRSAxFvT3KNvDHiydcB5+0Jb4wdAQ==","timestamp":"2021-02-15T21:19:57.278801671Z","type":1,"validator_address":"D0CBA5174AD81B78D8392322BC49B27414A1346F","validator_index":2}
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Added to prevote module=consensus prevotes="VoteSet{H:3422 R:0 T:SIGNED_MSG_TYPE_PREVOTE +2/3:<nil>(0.3333333333333333) BA{3:__x} map[]}" vote={"block_id":{"hash":"8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456","parts":{"hash":"030463EB2E62DE88502A174EC64BE9DB9F96845086CB63FDEF91CA94EAD4F78A","total":1}},"height":3422,"round":0,"signature":"GE3VJRd7J+c7VNvgzpIAF6ri6nHqJx1zxPk9LXwKlpP3ejaaaaRGeMxHzcRSAxFvT3KNvDHiydcB5+0Jb4wdAQ==","timestamp":"2021-02-15T21:19:57.278801671Z","type":1,"validator_address":"D0CBA5174AD81B78D8392322BC49B27414A1346F","validator_index":2}
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Added to prevote module=consensus prevotes="VoteSet{H:3422 R:0 T:SIGNED_MSG_TYPE_PREVOTE +2/3:<nil>(0.6666666666666666) BA{3:x_x} map[]}" vote={"block_id":{"hash":"8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456","parts":{"hash":"030463EB2E62DE88502A174EC64BE9DB9F96845086CB63FDEF91CA94EAD4F78A","total":1}},"height":3422,"round":0,"signature":"70otInw/eaZyvRCr0yj2bpXZ/D1BSHLOJZKYEqnvJcvOB7RDI/3hIDsKTCHCZDBus2dJt2+qAcNY4B/rPoLdDw==","timestamp":"2021-02-15T21:19:57.379188888Z","type":1,"validator_address":"4FF4CBC88D7C6F89A88D9B11F41C8265BDDA32AA","validator_index":0}
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Added to prevote module=consensus prevotes="VoteSet{H:3422 R:0 T:SIGNED_MSG_TYPE_PREVOTE +2/3:8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456:1:030463EB2E62(1) BA{3:xxx} map[]}" vote={"block_id":{"hash":"8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456","parts":{"hash":"030463EB2E62DE88502A174EC64BE9DB9F96845086CB63FDEF91CA94EAD4F78A","total":1}},"height":3422,"round":0,"signature":"0QhvGoJFJ+tC5xA4312z2LtWpWPvG7haA3dunZo2CTbiDZxhVgQFaUZpivwRcEObfuE12LHpYluShjnoG21RDA==","timestamp":"2021-02-15T21:19:57.380995221Z","type":1,"validator_address":"50B0870F21DA452CB453A68D41C5289BCC775814","validator_index":1}
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Updating ValidBlock because of POL. POLRound=0 module=consensus validRound=-1
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF enterPrecommit(3422/0). Current: 3422/0/RoundStepPrevote height=3422 module=consensus round=0
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF enterPrecommit: +2/3 prevoted proposal block. Locking hash=8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456 height=3422 module=consensus round=0
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Signed and pushed vote err=null height=3422 module=consensus round=0 vote={"block_id":{"hash":"8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456","parts":{"hash":"030463EB2E62DE88502A174EC64BE9DB9F96845086CB63FDEF91CA94EAD4F78A","total":1}},"height":3422,"round":0,"signature":"4q+cvfMgyDVs3IbT7pcfOns+54jeUQEAK9u6IC/7JJV8Qhe7i9gcZ5g8YDGk+CwnZ7UGt4Rc6B7GZ2j7gkD2Cg==","timestamp":"2021-02-15T21:19:57.489375452Z","type":2,"validator_address":"D0CBA5174AD81B78D8392322BC49B27414A1346F","validator_index":2}
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Added to precommit module=consensus precommits="VoteSet{H:3422 R:0 T:SIGNED_MSG_TYPE_PRECOMMIT +2/3:<nil>(0.3333333333333333) BA{3:__x} map[]}" vote={"block_id":{"hash":"8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456","parts":{"hash":"030463EB2E62DE88502A174EC64BE9DB9F96845086CB63FDEF91CA94EAD4F78A","total":1}},"height":3422,"round":0,"signature":"4q+cvfMgyDVs3IbT7pcfOns+54jeUQEAK9u6IC/7JJV8Qhe7i9gcZ5g8YDGk+CwnZ7UGt4Rc6B7GZ2j7gkD2Cg==","timestamp":"2021-02-15T21:19:57.489375452Z","type":2,"validator_address":"D0CBA5174AD81B78D8392322BC49B27414A1346F","validator_index":2}
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Added to precommit module=consensus precommits="VoteSet{H:3422 R:0 T:SIGNED_MSG_TYPE_PRECOMMIT +2/3:<nil>(0.6666666666666666) BA{3:_xx} map[]}" vote={"block_id":{"hash":"8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456","parts":{"hash":"030463EB2E62DE88502A174EC64BE9DB9F96845086CB63FDEF91CA94EAD4F78A","total":1}},"height":3422,"round":0,"signature":"dFKre07rjRLE/H+Flm81+1NuQhhR0HJYQ/NqbQV0XP8bpQXheectpnz+Of34EYCjdmiOepbHbbr28UzDdvNqAQ==","timestamp":"2021-02-15T21:19:57.488992496Z","type":2,"validator_address":"50B0870F21DA452CB453A68D41C5289BCC775814","validator_index":1}
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Added to precommit module=consensus precommits="VoteSet{H:3422 R:0 T:SIGNED_MSG_TYPE_PRECOMMIT +2/3:8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456:1:030463EB2E62(1) BA{3:xxx} map[]}" vote={"block_id":{"hash":"8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456","parts":{"hash":"030463EB2E62DE88502A174EC64BE9DB9F96845086CB63FDEF91CA94EAD4F78A","total":1}},"height":3422,"round":0,"signature":"ObbD/GmIVjExgkUSB7uGNgB5y2PewxFx0QbGQI6xMgOaKE4IdcNLdjm3bfXc+mS1whuU8bdZSq1Qqsc+xyKJAg==","timestamp":"2021-02-15T21:19:57.488396919Z","type":2,"validator_address":"4FF4CBC88D7C6F89A88D9B11F41C8265BDDA32AA","validator_index":0}
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF enterCommit(3422/0). Current: 3422/0/RoundStepPrecommit commitRound=0 height=3422 module=consensus
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Commit is for locked block. Set ProposalBlock=LockedBlock blockHash=8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456 commitRound=0 height=3422 module=consensus
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Finalizing commit of block with N txs N=1 hash=8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456 height=3422 module=consensus root=7A602B3E4FB37B2FA526CA30B9674AD79351E8C27A8DB4CDDE67C2EE1B772FBC
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Block{
Feb 15 21:19:57 edu-testnet03 akash[32931]:   Header{
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Version:        {11 0}
Feb 15 21:19:57 edu-testnet03 akash[32931]:     ChainID:        local
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Height:         3422
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Time:           2021-02-15 21:19:52.171084461 +0000 UTC
Feb 15 21:19:57 edu-testnet03 akash[32931]:     LastBlockID:    AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA:1:C58A2648899C
Feb 15 21:19:57 edu-testnet03 akash[32931]:     LastCommit:     F01F7C3B04FC209BDEA5C3AEA5BDD87B075784C596577F9A6BE269A3DECF48B5
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Data:           4933C52EDCE582C1C2EC6E2200C04180A065DDD95542580A402412D5CD5D441B
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Validators:     E83D099C3A1884DE160B1CD53A9DAC0AC02483383054A4E7509BFF001CF109C7
Feb 15 21:19:57 edu-testnet03 akash[32931]:     NextValidators: E83D099C3A1884DE160B1CD53A9DAC0AC02483383054A4E7509BFF001CF109C7
Feb 15 21:19:57 edu-testnet03 akash[32931]:     App:            7A602B3E4FB37B2FA526CA30B9674AD79351E8C27A8DB4CDDE67C2EE1B772FBC
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Consensus:      048091BC7DDC283F77BFBF91D73C44DA58C3DF8A9CBC867405D8B7F3DAADA22F
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Results:        79E946B1887895762DFB4B6CB6F1DE1867F44A1712BC18485A6214B244087ED8
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Evidence:       E3B0C44298FC1C149AFBF4C8996FB92427AE41E4649B934CA495991B7852B855
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Proposer:       D0CBA5174AD81B78D8392322BC49B27414A1346F
Feb 15 21:19:57 edu-testnet03 akash[32931]:   }#8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456
Feb 15 21:19:57 edu-testnet03 akash[32931]:   Data{
Feb 15 21:19:57 edu-testnet03 akash[32931]:     EDD6D1A359F4A727C0959FC22B2D2D7E25954C29443BC3EBDB4FC5F99E686061 (348 bytes)
Feb 15 21:19:57 edu-testnet03 akash[32931]:   }#4933C52EDCE582C1C2EC6E2200C04180A065DDD95542580A402412D5CD5D441B
Feb 15 21:19:57 edu-testnet03 akash[32931]:   EvidenceData{
Feb 15 21:19:57 edu-testnet03 akash[32931]:     
Feb 15 21:19:57 edu-testnet03 akash[32931]:   }#E3B0C44298FC1C149AFBF4C8996FB92427AE41E4649B934CA495991B7852B855
Feb 15 21:19:57 edu-testnet03 akash[32931]:   Commit{
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Height:     3421
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Round:      0
Feb 15 21:19:57 edu-testnet03 akash[32931]:     BlockID:    AF38B28E7AAB6F3FC13EA21DB9FF59DAFFE701A2D79A389ADEDA6C454C549EBA:1:C58A2648899C
Feb 15 21:19:57 edu-testnet03 akash[32931]:     Signatures:
Feb 15 21:19:57 edu-testnet03 akash[32931]:       CommitSig{1A1CF36AB9CE by 4FF4CBC88D7C on 2 @ 2021-02-15T21:19:52.171084461Z}
Feb 15 21:19:57 edu-testnet03 akash[32931]:       CommitSig{592155D81E4C by 50B0870F21DA on 2 @ 2021-02-15T21:19:52.171945152Z}
Feb 15 21:19:57 edu-testnet03 akash[32931]:       CommitSig{2DB76B18A8F3 by D0CBA5174AD8 on 2 @ 2021-02-15T21:19:52.165946546Z}
Feb 15 21:19:57 edu-testnet03 akash[32931]:   }#F01F7C3B04FC209BDEA5C3AEA5BDD87B075784C596577F9A6BE269A3DECF48B5
Feb 15 21:19:57 edu-testnet03 akash[32931]: }#8C68ED2C8B77CC707A5468840C328D1D3F8F0C8793EAA74D1EFB2D3C0DFC7456 module=consensus
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF minted coins from module account amount=391459uakt from=mint module=x/bank
Feb 15 21:19:57 edu-testnet03 akash[32931]: 9:19PM INF Executed block height=3422 invalidTxs=1 module=state validTxs=0

hydrogen18 avatar Feb 15 '21 21:02 hydrogen18

OK so actually this happened it looks like on the chain

 ~/ovrclk/akash/akash --chain-id=local --home=$PWD/home --node=tcp://147.75.105.135:26657 query tx EDD6D1A359F4A727C0959FC22B2D2D7E25954C29443BC3EBDB4FC5F99E686061
code: 5
codespace: sdk
data: ""
gas_used: "68162"
gas_wanted: "200000"
height: "3422"
info: ""
logs: []
raw_log: 'failed to execute message; message index: 0: 49948000uakt is smaller than
  50000000uakt: insufficient funds'
timestamp: "2021-02-15T21:19:52Z"
tx:
  '@type': /cosmos.tx.v1beta1.Tx
  auth_info:
    fee:
      amount:
      - amount: "2000"
        denom: uakt
      gas_limit: "200000"
      granter: ""
      payer: ""
    signer_infos:
    - mode_info:
        single:
          mode: SIGN_MODE_DIRECT
      public_key:
        '@type': /cosmos.crypto.secp256k1.PubKey
        key: AhaCM2h5v36n/YBHazj4B8+mmp5/VqBZCC1T0vPgrZ4i
      sequence: "30"
  body:
    extension_options: []
    memo: ""
    messages:
    - '@type': /akash.market.v1beta1.MsgCreateBid
      deposit:
        amount: "50000000"
        denom: uakt
      order:
        dseq: "3419"
        gseq: 1
        oseq: 1
        owner: akash19dnhammcj3vf9dzgmtgg7pc8ujecn5azlzcu09
      price:
        amount: "1788"
        denom: uakt
      provider: akash16gfc7yfktrupn58mv8sjp7pvyd09jsh70whnzq
    non_critical_extension_options: []
    timeout_height: "0"
  signatures:
  - Sk9+QT/DLWmtXzpz/Kr5J54fUGzzyAmgZh1s4pzKTxNRGyxrNd2+2Rh945qiu3KXsVlRS1i2uz9rXjrieXGcDg==
txhash: EDD6D1A359F4A727C0959FC22B2D2D7E25954C29443BC3EBDB4FC5F99E686061

Apparently the provider doesn't have enough AKT to place the bid

$ ~/ovrclk/akash/akash --chain-id=local --home=$PWD/home --node=tcp://147.75.105.135:26657 query bank balances akash16gfc7yfktrupn58mv8sjp7pvyd09jsh70whnzq
balances:
- amount: "49948000"
  denom: uakt
pagination:
  next_key: null
  total: "0"

hydrogen18 avatar Feb 15 '21 21:02 hydrogen18

OK this makes sense now

Bidding on an order should not be free (for various reasons,
including performance and security).  Akash requires a deposit for every bid.
The deposit is returned to the bidder when the bid is closed.

So I need to make the provider actually check that the TX is committed when it creates a bid. Right now it thinks it is when in fact it never goes on chain.

hydrogen18 avatar Feb 15 '21 21:02 hydrogen18

It looks like the provider uses the SerialClient

https://github.com/ovrclk/akash/blob/master/provider/cmd/run.go#L356

It's kind of convoluted but I think it confirms the response code is something acceptable and turns it into an error if it isn't ??

https://github.com/ovrclk/akash/blob/master/client/broadcaster/serial.go#L190

hydrogen18 avatar Feb 15 '21 22:02 hydrogen18

Ok, this shows up in the provider logs

Feb 15 22:52:20 dfw0 akash[257098]: I[2021-02-15|22:52:20.909] broadcast response                           cmp=client/broadcaster response="Response:\n  TxHash: 329A5399FE8BAA0C9DDC81E918761C6D941E3C287AC2441FCE083CD81ABD1A4F\n  Raw Log: []\n  Logs: []" err=null

but its obviously a failure

code: 5
codespace: sdk
data: ""
gas_used: "68162"
gas_wanted: "200000"
height: "4464"
info: ""
logs: []
raw_log: 'failed to execute message; message index: 0: 49932000uakt is smaller than
  50000000uakt: insufficient funds'
timestamp: "2021-02-15T22:52:20Z"
tx:
  '@type': /cosmos.tx.v1beta1.Tx
  auth_info:
    fee:
      amount:
      - amount: "2000"
        denom: uakt
      gas_limit: "200000"
      granter: ""
      payer: ""
    signer_infos:
    - mode_info:
        single:
          mode: SIGN_MODE_DIRECT
      public_key:
        '@type': /cosmos.crypto.secp256k1.PubKey
        key: AhaCM2h5v36n/YBHazj4B8+mmp5/VqBZCC1T0vPgrZ4i
      sequence: "38"
  body:
    extension_options: []
    memo: ""
    messages:
    - '@type': /akash.market.v1beta1.MsgCreateBid
      deposit:
        amount: "50000000"
        denom: uakt
      order:
        dseq: "4462"
        gseq: 1
        oseq: 1
        owner: akash19dnhammcj3vf9dzgmtgg7pc8ujecn5azlzcu09
      price:
        amount: "1788"
        denom: uakt
      provider: akash16gfc7yfktrupn58mv8sjp7pvyd09jsh70whnzq
    non_critical_extension_options: []
    timeout_height: "0"
  signatures:
  - tbL/DkH0s43okbP2e+AeQuIsOEEC7d6eY0E5Vn0ExHVd3gkcVGUpasOA9nHwQR3z856kOE1gPuZuA8kXCKBGYw=

hydrogen18 avatar Feb 15 '21 22:02 hydrogen18

It's kind of convoluted but I think it confirms the response code is something acceptable and turns it into an error if it isn't ??

Serial client tries to ensure that we're signing & broadcasting messages with the correct account sequence number. The account sequence number is increased by one for every transaction. If we sign and broadcast with the wrong sequence we get an error back immediately, which we parse to try to determine the correct sequence number to use.

We're using broadcast mode sync, which waits until the transaction is in the "mempool" - a queue of transactions waiting to be included in a block. There is some validation done before being accepted into the mempool, including sequence number and signature.

So we're mostly doing a "fire and forget" with the transactions. We used to ues broadcat mode block, which waited until the transaction is in a block, but this can time out very easily.

Most of the time it is okay to just fire and forget in sync mode - the bidengine will react when a lease is won, for instance. That being said, we obviously need to eventually get the final result of the transaction. We can use our current event bus in /events/publish.go to publish results, we should be careful about publishing too many extraneous events locally, tho.

boz avatar Feb 16 '21 03:02 boz

Most of the time it is okay to just fire and forget in sync mode - the bidengine will react when a lease is won, for instance.

Ok the only corner case then is if no bids make it into the block chain (for whatever reason). In that case the provider has inventory reserved that it won't be able to actually earn AKT from anytime soon.

hydrogen18 avatar Feb 16 '21 03:02 hydrogen18

Seeing this again here, the provider thinks this TX is committed but it is not

https://www.mintscan.io/akash/txs/1CB9F6F782920F8337F101CC365C9C767AC4DE5A04B6EEA9D00B8E4672A92ACC

meaning the provider can't actually bid

hydrogen18 avatar Jun 16 '21 22:06 hydrogen18

The easiest thing to do here is to manually confirm each TX makes it into a block (or is rejected) and then graph it in prometheus.

We can alert on the failure label in prometheus

hydrogen18 avatar Jun 16 '21 23:06 hydrogen18

Out of gas TXs seem to be un-indexed (not sure why, maybe preventing the blockchain spam?), hence can't be queried with akash events.

$ akash query tx E498D98D1B89E0EB3A606FE6A9ED42F38259096BFD0E46B728B3C0C3515F1CDF | grep -C6 events
code: 11
codespace: sdk
data: ""
events:
- attributes:
  - index: false
    key: c3BlbmRlcg==
    value: YWthc2gxZGVmOGZqanpnNnBnbDVhNTI0ejR4dXduY2tmZ3B2bnptM2F3ZGw=
  - index: false
    key: YW1vdW50

$ echo YWthc2gxZGVmOGZqanpnNnBnbDVhNTI0ejR4dXduY2tmZ3B2bnptM2F3ZGw= | openssl base64 -A -d ; echo
akash1def8fjjzg6pgl5a524z4xuwnckfgpvnzm3awdl

$ echo c3BlbmRlcg== | openssl base64 -A -d ; echo
spender

andy108369 avatar Jun 15 '22 16:06 andy108369