hledger uses too much memory with large files [1mo]

MarkusTeufelberger commented 9 years ago

I have a ledger of about 40 MB worth of files, hledger 0.26 now suddenly chokes on them, the previous version worked fine (well it also took waaay to long to calculate balances, but at least it worked):

hledger bal -f ./output/full.ledger
hledger: out of memory

full.ledger just imports a couple of other files (I have a collection of scripts that generate them from CSV files) that total to 37 MB. My machine has 16 GB of RAM, so this is not very likely an issue.

--- Want to back this issue? **[Post a bounty on it!](https://www.bountysource.com/issues/24719851-hledger-uses-too-much-memory-with-large-files-1mo?utm_campaign=plugin&utm_content=tracker%2F536505&utm_medium=issues&utm_source=github)** We accept bounties via [Bountysource](https://www.bountysource.com/?utm_campaign=plugin&utm_content=tracker%2F536505&utm_medium=issues&utm_source=github).

simonmichael commented 9 years ago

Very interesting, thanks for the report. (I'd be interested to see as much of the stats output as you'd care to show for that..)

MarkusTeufelberger commented 9 years ago

Well, the stats command runs out of memory too... maybe I'll find a way to build a 64 bit binary on Windows.

On Linux I get the following error (same for stats and bal): [me@mycomputer foldername]$ ~/.cabal/bin/hledger bal -f ./output/full.ledger hledger: /path/to/foldername/./output/paypal_com.ledger: hGetContents: invalid argument (invalid byte sequence)

I suspect there is some issue with Unicode in Linux (the file contains some japanese charaters as PayPal username), not necessarily related to the OOM issue. Maybe it could be my script that is not properly flagging the file encoding?

After manually saving the file as UTF-8 in a text editor it worked (both stats and bal), even though it takes a LONG time (a couple seconds at least) to produce the output:

[me@mycomputer foldername]$ ~/.cabal/bin/hledger stats -f ./output/full.ledger 
Main journal file        : /path/to/foldername/./output/full.ledger
Included journal files   : /path/to/foldername/./output/XXX.ledger           
                           /path/to/foldername/./output/YYY.ledger
                           etc. etc. etc.
Transactions span        : 2000-01-01 to 2015-07-22 (5681 days)
Last transaction         : 2015-07-21 (1 days ago)
Transactions             : 295923 (52.1 per day)
Transactions last 30 days: 176881 (5896.0 per day)
Transactions last 7 days : 38687 (5526.7 per day)
Payees/descriptions      : 411
Accounts                 : 218 (depth 5)
Commodities              : 8 (AAA, BBB, CCC, DDD, EEE, FFF, GGG, HHH)

A few things are censored, the numbers are accurate though. Real transactions don't really start in 2000, more like in 2010 or so - the few ones in 2000 are moving "Equity" amounts into place for having correct opening balances. Most of this stuff is auto-generated from CSV files and some of them are relatively verbose/microtransaction heavy.

simonmichael commented 9 years ago

A quarter million transactions - very cool! Now I'm motivated to test with some larger data sets.

The unicode thing can probably be fixed by setting LANG to an appropriate locale (cf http://hledger.org/manual.html#run-time-problems). GHC-compiled software tends to fail this way when it encounters non-ascii data and the system locale is not set. We should give a better error message (#73).

simonmichael commented 9 years ago

Hmm. I didn't see this in pre-release testing, and I don't see it now with the simple test journals. Time is the same:

$ time tools/simplebench -n1 hledger-0.24 hledger-0.25 hledger-0.26
Using bench.tests
Running 6 tests 1 times with 3 executables at 2015-07-22 13:53:31.42249 UTC:

Summary (best iteration):

+------------------------------------++--------------+--------------+--------------+
|                                    || hledger-0.24 | hledger-0.25 | hledger-0.26 |
+====================================++==============+==============+==============+
| bal -f data/100x100x10.journal     ||         0.04 |         0.04 |         0.04 |
| bal -f data/1000x1000x10.journal   ||         0.21 |         0.25 |         0.24 |
| bal -f data/1000x10000x10.journal  ||         0.31 |         0.32 |         0.35 |
| bal -f data/10000x1000x10.journal  ||         1.76 |         1.72 |         1.85 |
| bal -f data/10000x10000x10.journal ||         3.18 |         3.38 |         3.58 |
| bal -f data/100000x1000x10.journal ||        18.69 |        20.74 |        19.79 |
+------------------------------------++--------------+--------------+--------------+

real    1m16.674s
user    1m10.822s
sys 0m3.867s

and more importantly, the heap profile looks the same:

0.25.1: hledgerprof 0 25 1

0.26: hledgerprof 0 26

What special features does your data have ? Maybe an unusually high number of aliases, accounts, includes, or something else ? Would it be possible to simplify it until you see the problem go away ?

simonmichael commented 9 years ago

Actually, I meant to show profiles with 100k transactions, not 10k. But the main point is I see no change since 0.25, so I'm not sure why you would see it suddenly break with 0.26, unless it's borderline.

Here's one with 100k transactions: hledgerprof-0 26-100k I'm still learning about heap profiles - this one goes up to 600M, but I observed the process using 2.1G in activity monitor. So indeed, it might be that your 32-bit build is hitting its 2G limit.

MarkusTeufelberger commented 9 years ago

Maybe it was/is borderline? After all most transactions were added recently and that might have tipped it over the edge no matter what? hledger.exe uses about 2 GiB of RAM and then dies OOM. I highly suspect that it is compiled to a 64bit binary in Linux...

There are about a dozen files alltogether (so about a dozen includes), nearly all transactions are very simple (I don't duplicate amounts though, so I generally only have one line with the amount and the second line has to auto-balance). As you can see there are a few hundred accounts and a few of the transactions (e.g. PayPal ones) have payment IDs added as tags ("date (payment_id) description").

While it might be possible to simplify it (e.g. process data for one day, write it out, let (h)ledger/beancount process it and only store a single total transaction instead of one transaction per line), this would make the process much slower, the resulting file potentially more error prone and also potentially more incorrect. I'd prefer if it were possible to just take a CSV file, run my parser and have a text file ready for *ledger without adding "intelligence".

By the way, using >2 GB of memory on a <40 MB input consisting only of dates, amounts, descriptions and accounts seems a bit excessive...?

simonmichael commented 9 years ago

Yes that seems to be it. hledger installed with the 32-bit windows version of stack dies with "out of memory" as soon as it gets near 2G. hledger installed with the 64-bit windows stack works though (at least it has been using 3G on this 4G machine for 20m on a million-transaction file and I assume it would finish eventually). I recommend installing that way for now.

And yes, it's using much more memory than it should. We haven't paid attention to that until now, thanks for highlighting it.

simonmichael commented 9 years ago

I tried strictifying and unpacking fields in the main types (at last), just to see if there's any cheap improvement, but not really. (It's a small improvement, worth keeping I think even though I don't know what other effects this change could have):

Strictified: hledgerprof-0 26-strictified Unpacked: hledgerprof-0 26-unpacked