[token transfer] Output already spent by transaction in the pool

[Jerick26]

INFO[0042] wait for token balance of sender b1WaqHihvrEi4MGvY8CACTvVLoBPLFmeAbH equal to 100000000, timeout 30s  source="integration_tests/test_token.go:121" tag=integration
INFO[0042] before token transfer, sender b1WaqHihvrEi4MGvY8CACTvVLoBPLFmeAbH has 100000000 token, receiver b1fqkUg45iS1DgEZrDkq64hL2h2SrCxdFrC has 0 token  source="integration_tests/test_token.go:129" tag=integration
INFO[0042] sender b1WaqHihvrEi4MGvY8CACTvVLoBPLFmeAbH transfer 3117760 token to receiver b1fqkUg45iS1DgEZrDkq64hL2h2SrCxdFrC  source="integration_tests/test_token.go:151" tag=integration
INFO[0042] sender b1WaqHihvrEi4MGvY8CACTvVLoBPLFmeAbH transfer 4940786 token to receiver b1fqkUg45iS1DgEZrDkq64hL2h2SrCxdFrC  source="integration_tests/test_token.go:151" tag=integration
INFO[0042] sender b1WaqHihvrEi4MGvY8CACTvVLoBPLFmeAbH transfer 2849113 token to receiver b1fqkUg45iS1DgEZrDkq64hL2h2SrCxdFrC  source="integration_tests/test_token.go:151" tag=integration
INFO[0042] sender b1WaqHihvrEi4MGvY8CACTvVLoBPLFmeAbH transfer 3743330 token to receiver b1fqkUg45iS1DgEZrDkq64hL2h2SrCxdFrC  source="integration_tests/test_token.go:151" tag=integration
PANI[0042] rpc error: code = Unknown desc = Output already spent by transaction in the pool  source="integration_tests/test_token.go:237" tag=integration
PANI[0042] rpc error: code = Unknown desc = Output already spent by transaction in the pool  source="integration_tests/test_token.go:237" tag=integration
PANI[0042] rpc error: code = Unknown desc = Output already spent by transaction in the pool  source="integration_tests/test_token.go:237" tag=integration
PANI[0042] &{0xc0000ec820 map[tag:integration source:integration_tests/test_token.go:237] 2018-11-30 10:51:35.954987 +0800 CST m=+42.587367299 panic rpc error: code = Unknown desc = Output already spent by transaction in the pool <nil> }  source="integration_tests/test_token.go:161" tag=integration
INFO[0042] done TokenTest doTx                           source="integration_tests/test_token.go:57" tag=integration
INFO[0042] done token test                               source="integration_tests/main.go:283" tag=integration
INFO[0042] remove 3 keystore files                       source="utils/util.go:215" tag=integration_utils

code:

        logger.Infof("wait for token balance of sender %s equal to %d, timeout %v",
            sender, totalSupply, timeoutToChain)
        blcSenderPre, err := utils.WaitTokenBalanceEnough(sender, totalSupply, issueTx,
            peerAddr, timeoutToChain)
        if err != nil {
            logger.Panic(err)
        }
        blcRcvPre := utils.TokenBalanceFor(receiver, issueTx, peerAddr)
        logger.Infof("before token transfer, sender %s has %d token, receiver %s"+
            " has %d token", sender, blcSenderPre, receiver, blcRcvPre)

        // transfer token
        base := txTotalAmount / uint64(times) / 5 * 2
        txAmount := uint64(0)
        var wg sync.WaitGroup
        workers := 4
        partLen := (times + workers - 1) / workers
        errChans := make(chan error, workers)
        for i := 0; i < workers; i++ {
            wg.Add(1)
            start := i * partLen
            go func(start, partLen int) {
                defer func() {
                    wg.Done()
                    if x := recover(); x != nil {
                        errChans <- fmt.Errorf("%v", x)
                    }
                }()
                for j := 0; j < partLen && start+j < times; j++ {
                    amount := base + uint64(rand.Int63n(int64(base)))
                    logger.Infof("sender %s transfer %d token to receiver %s", sender,
                        amount, receiver)
                    transferToken(sender, receiver, amount, issueTx, peerAddr)
                    atomic.AddUint64(&t.txCnt, 1)
                    atomic.AddUint64(&txAmount, amount)
                }
            }(start, partLen)
        }
        wg.Wait()
        if len(errChans) > 0 {
            logger.Panic(<-errChans)
        }
        logger.Infof("%s sent %d times total %d token tx to %s", sender, times,
            txAmount, receiver)

[Jerick26]

Is not allowed to transfer token concurrently just as transfer box?

[xhliu]

Is not allowed to transfer token concurrently just as transfer box?

Yes, you are allowed, just like box.

You are sending token transfer txs back to back. This error can only happen when you try to send a tx, but the previous tx has not been accepted into mempool. So the utxos u get back still contain ones the previous tx spends. I'm guessing this happens rarely, e.g., when the node is under heavy load. I tried transferring tokens back to back locally, and never had this issue, probably because it's not heavily loaded.

Two solutions:

1. Do not panic when this error happens since it's not fatal. We just send as fast as possible.

   newTx, err := client.CreateTokenTransferTx(conn, fromAddress, targets,
       AddrToAcc[fromAddr].PublicKey(), txHash, 0, AddrToAcc[fromAddr])
   if err != nil {
                // ----> Do NOT panic here
       logger.Panic(err)
   }

2. Wait till the previous tx makes into the mempool before sending the next tx. We can sleep/wait some time or query the mempool.

   for j := 0; j < partLen && start+j < times; j++ {
                   amount := base + uint64(rand.Int63n(int64(base)))
                   logger.Debugf("sender %s transfer %d token to receiver %s", sender,
                       amount, receiver)
                   transferToken(sender, receiver, amount, issueTx, peerAddr)
                                        // ---> WAIT till the tx made into mempool
                   atomic.AddUint64(&t.txCnt, 1)
                   atomic.AddUint64(&txAmount, amount)
               }

I prefer solution 1. And the above applies to box transfer as well.

[Jerick26]

Now I do it via a new method to send batch transactions, no error and in a high speed to send transaction which is used in tx tests.