search

lightninglabs / taproot-assets

A layer 1 daemon, for the Taproot Assets Protocol specification, written in Go (golang)
MIT License
460 stars 110 forks source link

received critical error from subsystem: error fetching asset proof: sql: no rows in result set #227

Closed snow884 closed 1 year ago

snow884 commented 1 year ago

My tarod keeps crashing with the error:

received critical error from subsystem: error fetching asset proof: sql: no rows in result set

This happened after I tried minting an multiple assets in a row using commands that looked like this:

tarocli assets mint --type normal --name "minted currency" --supply 100000 --enable_emission false --meta "test minted" --skip_batch

My LND commit hash is: c03de26dc My Taro commit hash is: ddb0e0d

I have built LND using the command:

git checkout master && make && make install tags="autopilotrpc chainkit chainrpc invoicesrpc peersrpc routerrpc signrpc walletrpc watchtowerrpc wtclientrpc"

Executing the commands:

lnd --bitcoin.active --bitcoin.testnet --debuglevel=debug --bitcoin.node=neutrino --neutrino.addpeer=faucet.lightning.community --rpclisten=0.0.0.0:10009

tarod --network=testnet --debuglevel=debug --lnd.host=localhost:10009 --lnd.macaroonpath=/home/ec2-user/.lnd/data/chain/bitcoin/testnet/admin.macaroon --lnd.tlspath=/home/ec2-user/.lnd/tls.cert --tarodir=/home/ec2-user/.taro --rpclisten=127.0.0.1:10029 --restlisten=127.0.0.1:8089

Produces the log:

2023-01-04 10:49:59.749 [WRN] CONF: open /home/ec2-user/.taro/taro.conf: no such file or directory
2023-01-04 10:49:59.750 [INF] CONF: Opening sqlite3 database at: /home/ec2-user/.taro/data/testnet/taro.db
2023-01-04 10:49:59.752 [INF] CONF: Attempting to establish connection to lnd...
2023-01-04 10:49:59.764 [INF] CONF: lnd connection initialized
2023-01-04 10:49:59.765 [INF] SRVR: Version: 0.1.99-alpha commit=v0.1.1-alpha-93-gddb0e0d, build=production, logging=default, debuglevel=debug
2023-01-04 10:49:59.765 [INF] SRVR: Active network: testnet3
2023-01-04 10:49:59.765 [INF] RPCS: Validating RPC requests based on macaroon at: /home/ec2-user/.taro/data/testnet/admin.macaroon
2023-01-04 10:49:59.765 [INF] RPCS: RPC server listening on 127.0.0.1:10029
2023-01-04 10:49:59.765 [INF] RPCS: gRPC proxy started at 127.0.0.1:8089
2023-01-04 10:49:59.766 [INF] GRDN: Starting ChainPlanter
2023-01-04 10:49:59.785 [INF] GRDN: Retrieved 3 non-finalized batches from DB
2023-01-04 10:49:59.786 [INF] GRDN: Launching ChainCaretaker(0327308cd3ab6eb3d3796fd9e8549c6cbf6584261314818f1600347580b1a5f2b0)
2023-01-04 10:49:59.786 [INF] GRDN: Launching ChainCaretaker(03186e54abfec586bad5a9fc5501b892e5df488eef32373cf505f20803560c79df)
2023-01-04 10:49:59.787 [INF] GRDN: Launching ChainCaretaker(02b993a1d1a92f2c2de89192e758cf52d17cb83d9be1be7f6066d20143b10dfcfa)
2023-01-04 10:49:59.787 [INF] GRDN: Starting asset custodian
2023-01-04 10:49:59.787 [INF] FRTR: Starting ChainPorter
2023-01-04 10:49:59.787 [INF] FRTR: Resuming delivery of 0 pending asset parcels
2023-01-04 10:49:59.787 [INF] RPCS: Starting RPC Server
2023-01-04 10:49:59.787 [INF] SRVR: Taro Daemon fully active!
2023-01-04 10:49:59.788 [INF] GRDN: BatchCaretaker(0327308cd3ab6eb3d3796fd9e8549c6cbf6584261314818f1600347580b1a5f2b0), advancing from state=BatchStateFrozen to state=BatchStateBroadcast
2023-01-04 10:49:59.788 [INF] GRDN: BatchCaretaker(0327308cd3ab6eb3d3796fd9e8549c6cbf6584261314818f1600347580b1a5f2b0): attempting to fund GenesisPacket
2023-01-04 10:49:59.788 [INF] GRDN: BatchCaretaker(0327308cd3ab6eb3d3796fd9e8549c6cbf6584261314818f1600347580b1a5f2b0): creating skeleton PSBT: (*psbt.Packet)(0xc000476500)({
 UnsignedTx: (*wire.MsgTx)(0xc000451b00)({
  Version: (int32) 2,
  TxIn: ([]*wire.TxIn) (cap=15) {
  },
  TxOut: ([]*wire.TxOut) (len=1 cap=15) {
   (*wire.TxOut)(0x2348e00)({
    Value: (int64) 1000,
    PkScript: ([]uint8) (len=34 cap=34) {
     00000000  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
     00000010  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
     00000020  00 00                                             |..|
    }
   })
  },
  LockTime: (uint32) 0
 }),
 Inputs: ([]psbt.PInput) {
 },
 Outputs: ([]psbt.POutput) (len=1 cap=1) {
  (psbt.POutput) {
   RedeemScript: ([]uint8) <nil>,
   WitnessScript: ([]uint8) <nil>,
   Bip32Derivation: ([]*psbt.Bip32Derivation) <nil>,
   TaprootInternalKey: ([]uint8) <nil>,
   TaprootTapTree: ([]uint8) <nil>,
   TaprootBip32Derivation: ([]*psbt.TaprootBip32Derivation) <nil>
  }
 },
 Unknowns: ([]psbt.Unknown) {
 }
})

2023-01-04 10:49:59.789 [INF] GRDN: BatchCaretaker(03186e54abfec586bad5a9fc5501b892e5df488eef32373cf505f20803560c79df), advancing from state=BatchStateBroadcast to state=BatchStateBroadcast
2023-01-04 10:49:59.789 [INF] GRDN: BatchCaretaker(03186e54abfec586bad5a9fc5501b892e5df488eef32373cf505f20803560c79df): extracted finalized GenesisTx: (*wire.MsgTx)(0xc00047e000)({
 Version: (int32) 2,
 TxIn: ([]*wire.TxIn) (len=1 cap=1) {
  (*wire.TxIn)(0xc0006fb860)({
   PreviousOutPoint: (wire.OutPoint) bb982a58ff3bebe8f9e3b993793112755fe393f45c9c42187a533e65f93fbe6b:1,
   SignatureScript: ([]uint8) <nil>,
   Witness: (wire.TxWitness) (len=1 cap=1) {
    ([]uint8) (len=64 cap=64) {
     00000000  47 3b 49 64 e8 c0 65 13  62 f8 ab e6 f4 6e 91 b8  |G;Id..e.b....n..|
     00000010  e1 36 8b 53 d2 6e c6 66  c2 53 34 c5 8a 88 ee 17  |.6.S.n.f.S4.....|
     00000020  23 8d 74 30 b5 a9 dd 6a  62 37 23 1f 14 15 cf 85  |#.t0...jb7#.....|
     00000030  4f 51 05 00 f8 86 30 03  e5 9c 85 91 d0 78 2e 32  |OQ....0......x.2|
    }
   },
   Sequence: (uint32) 4294967295
  })
 },
 TxOut: ([]*wire.TxOut) (len=2 cap=2) {
  (*wire.TxOut)(0xc0006e39c0)({
   Value: (int64) 1000,
   PkScript: ([]uint8) (len=34 cap=34) {
    00000000  51 20 d1 3d 9e 19 f5 0a  20 b3 75 79 42 a8 27 70  |Q .=.... .uyB.'p|
    00000010  57 d5 7e 8d ff b5 99 7d  0f 14 41 c9 32 aa c5 48  |W.~....}..A.2..H|
    00000020  85 2c                                             |.,|
   }
  }),
  (*wire.TxOut)(0xc0006e39e0)({
   Value: (int64) 3114466,
   PkScript: ([]uint8) (len=34 cap=34) {
    00000000  51 20 87 d8 c6 4d a9 0f  1e f6 c1 ba b1 ad e2 3b  |Q ...M.........;|
    00000010  d3 63 d2 f4 69 6b d4 50  44 e5 85 d1 33 0e 72 e4  |.c..ik.PD...3.r.|
    00000020  12 9d                                             |..|
   }
  })
 },
 LockTime: (uint32) 0
})

2023-01-04 10:49:59.789 [INF] GRDN: BatchCaretaker(02b993a1d1a92f2c2de89192e758cf52d17cb83d9be1be7f6066d20143b10dfcfa), advancing from state=BatchStateFrozen to state=BatchStateBroadcast
2023-01-04 10:49:59.789 [INF] GRDN: BatchCaretaker(02b993a1d1a92f2c2de89192e758cf52d17cb83d9be1be7f6066d20143b10dfcfa): attempting to fund GenesisPacket
2023-01-04 10:49:59.789 [INF] GRDN: BatchCaretaker(02b993a1d1a92f2c2de89192e758cf52d17cb83d9be1be7f6066d20143b10dfcfa): creating skeleton PSBT: (*psbt.Packet)(0xc000476c80)({
 UnsignedTx: (*wire.MsgTx)(0xc00047e1c0)({
  Version: (int32) 2,
  TxIn: ([]*wire.TxIn) (cap=15) {
  },
  TxOut: ([]*wire.TxOut) (len=1 cap=15) {
   (*wire.TxOut)(0x2348e00)({
    Value: (int64) 1000,
    PkScript: ([]uint8) (len=34 cap=34) {
     00000000  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
     00000010  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
     00000020  00 00                                             |..|
    }
   })
  },
  LockTime: (uint32) 0
 }),
 Inputs: ([]psbt.PInput) {
 },
 Outputs: ([]psbt.POutput) (len=1 cap=1) {
  (psbt.POutput) {
   RedeemScript: ([]uint8) <nil>,
   WitnessScript: ([]uint8) <nil>,
   Bip32Derivation: ([]*psbt.Bip32Derivation) <nil>,
   TaprootInternalKey: ([]uint8) <nil>,
   TaprootTapTree: ([]uint8) <nil>,
   TaprootBip32Derivation: ([]*psbt.TaprootBip32Derivation) <nil>
  }
 },
 Unknowns: ([]psbt.Unknown) {
 }
})

2023-01-04 10:49:59.789 [INF] GRDN: Gardener for ChainPlanter now active!
2023-01-04 10:49:59.790 [DBG] GRDN: Subscribing to new on-chain transactions
2023-01-04 10:49:59.790 [INF] GRDN: Loading pending inbound asset events
2023-01-04 10:49:59.792 [INF] GRDN: Resuming 4 pending inbound asset events
2023-01-04 10:49:59.795 [ERR] SRVR: Shutting down because error in main method: received critical error from subsystem: error fetching asset proof: sql: no rows in result set
2023-01-04 10:49:59.795 [INF] RPCS: Stopping RPC Server
2023-01-04 10:49:59.796 [INF] SRVR: Shutdown complete

received critical error from subsystem: error fetching asset proof: sql: no rows in result set
Roasbeef commented 1 year ago

Are you able to reproduce this on master w/ a clean install?

snow884 commented 1 year ago

Hi @Roasbeef , no this error is not reproducible.

snow884 commented 1 year ago

This error seems to occur when I am running tarod for a long time after I send myself an asset.

I almost always get this when I let tarod running over night.

Here is a new log:

[ec2-user@ip-172-31-85-57 ~]$ tarod --network=testnet --debuglevel=debug --lnd.host=localhost:10009 --lnd.macaroonpath=/home/ec2-user/.lnd/data/chain/bitcoin/testnet/admin.macaroon --lnd.tlspath=/home/ec2-user/.lnd/tls.cert --tarodir=/home/ec2-user/.taro --rpclisten=127.0.0.1:10029 --restlisten=127.0.0.1:8089 --batch-minting-interval=1m 
2023-01-06 09:26:07.573 [WRN] CONF: open /home/ec2-user/.taro/taro.conf: no such file or directory
2023-01-06 09:26:07.574 [INF] CONF: Opening sqlite3 database at: /home/ec2-user/.taro/data/testnet/taro.db
2023-01-06 09:26:07.578 [INF] CONF: Attempting to establish connection to lnd...
2023-01-06 09:26:07.588 [INF] CONF: lnd connection initialized
2023-01-06 09:26:07.588 [INF] SRVR: Version: 0.1.99-alpha commit=v0.1.1-alpha-93-gddb0e0d, build=production, logging=default, debuglevel=debug
2023-01-06 09:26:07.588 [INF] SRVR: Active network: testnet3
2023-01-06 09:26:07.589 [INF] RPCS: Validating RPC requests based on macaroon at: /home/ec2-user/.taro/data/testnet/admin.macaroon
2023-01-06 09:26:07.589 [INF] RPCS: RPC server listening on 127.0.0.1:10029
2023-01-06 09:26:07.589 [INF] RPCS: gRPC proxy started at 127.0.0.1:8089
2023-01-06 09:26:07.589 [INF] GRDN: Starting ChainPlanter
2023-01-06 09:26:07.589 [INF] GRDN: Retrieved 0 non-finalized batches from DB
2023-01-06 09:26:07.589 [INF] GRDN: Starting asset custodian
2023-01-06 09:26:07.590 [INF] FRTR: Starting ChainPorter
2023-01-06 09:26:07.590 [INF] FRTR: Resuming delivery of 0 pending asset parcels
2023-01-06 09:26:07.590 [INF] RPCS: Starting RPC Server
2023-01-06 09:26:07.590 [INF] SRVR: Taro Daemon fully active!
2023-01-06 09:26:07.591 [INF] GRDN: Gardener for ChainPlanter now active!
2023-01-06 09:26:07.591 [DBG] GRDN: Subscribing to new on-chain transactions
2023-01-06 09:26:07.591 [INF] GRDN: Loading pending inbound asset events
2023-01-06 09:26:07.592 [INF] GRDN: Resuming 1 pending inbound asset events
2023-01-06 09:26:07.593 [ERR] SRVR: Shutting down because error in main method: received critical error from subsystem: error fetching asset proof: sql: no rows in result set
2023-01-06 09:26:07.593 [INF] RPCS: Stopping RPC Server
2023-01-06 09:26:07.593 [INF] SRVR: Shutdown complete

received critical error from subsystem: error fetching asset proof: sql: no rows in result set
jharveyb commented 1 year ago

Hi @snow884 , do you see any proof files on disk?

dstadulis commented 1 year ago

@snow884 we're taking a look at this, can you provide the requested info?

snow884 commented 1 year ago

Hi @jharveyb ,

Thanks a lot for picking this up.

I am sorry I no longer have access to the environment where the issue occurred.

@dstadulis I cannot provide the info.

The issue seems to be related to neutrino . When I use bitcoind I do not get this error anymore.

guggero commented 1 year ago

Could have been a follow-up error after https://github.com/lightninglabs/taro/issues/228 left the DB in an incomplete state. Or something around Neutrino (which I don't believe we are currently prioritizing to support). So going to close this with the intent to re-open if more people run into this.