Bug in Armory: unusably slow and rescanning everything upon startup

[Christoph]

Hi,

this post belongs into the following place:

Bitcoin Forum > Bitcoin > Development & Technical Discussion > Alternative clients > Armory

However, I'm restricted to this "newbie" area, so I kindly ask a moderator to move my post where it is more likely to be found by the Armory developers and to allow me to post there.

I installed Armory around version 0.88.1, because it has very interesting features. I updated to a new 0.89.99.x beta version, and now I'm experiencing severe problems (upgrading to a later one and now to 0.90 didn't change this).

Every time I start Armory, the databases are rebuilt for a long time, then it rescans the blockchain for an extended period of time, after that it becomes very unresponsive. The following error message is repeated endlessly:

Code:

(ERROR) armoryengine.py:13289 - ErrorOut var over-represented number of errors!
(ERROR) armoryengine.py:12346 - BDM was not ready for your request!  Waited 20 sec.
(ERROR) armoryengine.py:12347 -   getattr   name: hasTxWithHash
(ERROR) armoryengine.py:12348 - BDM currently doing: Passthrough (67464183)
(ERROR) armoryengine.py:12349 - Waiting for completion: ID= 18001343
(ERROR) armoryengine.py:12350 - Direct traceback
  File "/usr/lib/armory/ArmoryQt.py", line 5133, in <module>
    os._exit(QAPP.exec_())
  File "/usr/lib/armory/qt4reactor.py", line 103, in read
    log.callWithLogger(w, _read)
  File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 88, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 73, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 81, in callWithContext
    return func(*args,**kw)
  File "/usr/lib/armory/qt4reactor.py", line 92, in _read
    why = w.doRead()
  File "/usr/lib/python2.7/dist-packages/twisted/internet/tcp.py", line 215, in doRead
    return self._dataReceived(data)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/tcp.py", line 221, in _dataReceived
    rval = self.protocol.dataReceived(data)
  File "/usr/lib/armory/armoryengine.py", line 10592, in dataReceived
    self.processMessage(msg)
  File "/usr/lib/armory/armoryengine.py", line 10620, in processMessage
    TheBDM.hasTxWithHash(inv[1]):
  File "/usr/lib/armory/armoryengine.py", line 12351, in passthruFunc
    traceback.print_stack()
(ERROR) armoryengine.py:12353 - Traceback:
Traceback (most recent call last):
  File "/usr/lib/armory/armoryengine.py", line 12343, in passthruFunc
    out = self.outputQueue.get(True, self.mtWaitSec)
  File "/usr/lib/python2.7/Queue.py", line 176, in get
    raise Empty
Empty
(ERROR) armoryengine.py:12346 - BDM was not ready for your request!  Waited 20 sec.
(ERROR) armoryengine.py:12347 -   getattr   name: hasTxWithHash
(ERROR) armoryengine.py:12348 - BDM currently doing: Passthrough (67464183)
(ERROR) armoryengine.py:12349 - Waiting for completion: ID= 20491075
(ERROR) armoryengine.py:12350 - Direct traceback
  File "/usr/lib/armory/ArmoryQt.py", line 5133, in <module>
    os._exit(QAPP.exec_())
  File "/usr/lib/armory/qt4reactor.py", line 103, in read
    log.callWithLogger(w, _read)
  File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 88, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 73, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 81, in callWithContext
    return func(*args,**kw)
  File "/usr/lib/armory/qt4reactor.py", line 92, in _read
    why = w.doRead()
  File "/usr/lib/python2.7/dist-packages/twisted/internet/tcp.py", line 215, in doRead
    return self._dataReceived(data)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/tcp.py", line 221, in _dataReceived
    rval = self.protocol.dataReceived(data)
  File "/usr/lib/armory/armoryengine.py", line 10592, in dataReceived
    self.processMessage(msg)
  File "/usr/lib/armory/armoryengine.py", line 10620, in processMessage
    TheBDM.hasTxWithHash(inv[1]):
  File "/usr/lib/armory/armoryengine.py", line 12351, in passthruFunc
    traceback.print_stack()
(ERROR) armoryengine.py:12353 - Traceback:
Traceback (most recent call last):
  File "/usr/lib/armory/armoryengine.py", line 12343, in passthruFunc
    out = self.outputQueue.get(True, self.mtWaitSec)
  File "/usr/lib/python2.7/Queue.py", line 176, in get
    raise Empty
Empty

There were also reported errors in calculating my wallets' bitcoin sums, but they showed up after the rescans. CPU usage is always very high and the window is not redrawn frequently any more as soon as the messages above begin to occur (after the rebuild and rescan processes). While scanning the blockchain, the connection to Bitcoin-QT is often lost and established again immediately. I'm using Debian Jessie/Sid i386/AMD64 with the i386 version of Armory 0.90.

Regards, Christoph

[Christoph]

Hi,

I found that this looks like the following issue 113:

https://github.com/etotheipi/BitcoinArmory/issues/113

Is this the same, somehow related, and if so, is there a solution or workaround available?

I've started with a fresh installation, and got the same results. As soon as Armory has finished building its databases and scanning the bloclchain, it will inevitably almost stop working, printing such messages on the console repeatedly.

Christoph

[etotheipi]

Does your wallet have lots of addresses?   Are you on a slow system?  The error basically indicates that the interthread communication timed out... which can happen when you have 10k+ addresses.  Also, when your mempool.bin file gets too big (there's a fix for the mempool thing in the next version).  In the meantime, you can use "Help"->"Clear all unconfirmed" to clear the mempool.bin file and then restart.  That may make a difference.  Until this fix is in, you may have to do that periodically if your system is slow.

Can you use "File"->"Export Log File" and email to support@bitcoinarmory.com so we can double-check?

[Christoph]

Hi,

I've got few addresses, and a Core2 Duo E4500, 2.20GHz (2x4416.83 "Bogomips"), which I really hope not to be too slow.

Code:

-rw-r--r--   1 christoph christoph 1317983 Jan  8 08:10 mempool.bin

I will try to do what you suggested, but I'm not sure whether I'll succeed, because the programme is almost unusable.

Is it sufficent to send "~/.armory/armorylog.txt"?

Thanks for your answer,

Christoph

[Christoph]

Hi,

I tried to follow your advice, but that doesn't work as expected:

mempool.bin changes its size and is pretty small when I restart, but grows afterwards, having a size of a bit more than 1 MB now, when it's in the buggy state of slowness again:

Code:

ls -l mempool.bin 
-rw-r--r-- 1 christoph christoph 1249793 Jan 10 15:00 mempool.bin

Because it seems to be rebuilt anyway here, there's no point to trigger that via the UI, I think.

About the logs:

Code:

ls -l *log*
-rw-r--r-- 1 christoph christoph  514486 Jan 10 06:39 armorycpplog.txt
-rw-r--r-- 1 christoph christoph 1408612 Jan 10 14:59 armorylog.txt
-rw-r--r-- 1 christoph christoph 1078697 Nov 17 00:02 ArmoryQt.py.log.txt

As you can see, the last one hasn't changed since november, is that due to a change of the filename between versions, or are there configuration options for different types of logs, and which one do you need in this case?

I cannot do anything productive in the GUI as soon as the buggy behaviour is triggered, because there is no reaction to mouse clicks and keypresses for minutes, so exporting the log for you won't work, I need to copy the right file, or the relevant section from it.

I tried to rule out that other stuff interferes by elevating the priority of the python processes, but that doesn't help. Armory consumes about 100% of the CPU cycles on the core it is running on, but still has those timeouts.

Christoph

[Christoph]

About the logs:

Code:

ls -l *log*
-rw-r--r-- 1 christoph christoph  514486 Jan 10 06:39 armorycpplog.txt
-rw-r--r-- 1 christoph christoph 1408612 Jan 10 14:59 armorylog.txt
-rw-r--r-- 1 christoph christoph 1078697 Nov 17 00:02 ArmoryQt.py.log.txt

As you can see, the last one hasn't changed since november, is that due to a change of the filename between versions, or are there configuration options for different types of logs, and which one do you need in this case?

I cannot do anything productive in the GUI as soon as the buggy behaviour is triggered, …

I've managed to open the export window, and found there that the middle log file should be the correct one, so I've sent this one via email.

Christoph