This problem also occurs with the sqlite3 backend. Symptoms are identical to Postgresql.

Can you send me a copy of your xml file?  plongstaff@rogers.com.  I will use it only to try to reproduce and diagnose this problem.

Or, please do it again, and look at /tmp/gnucash.trace which will contain the trace file with some debug information.  It is overwritten each time you run gnucash.

On Wed, Feb 10, 2010 at 3:54 PM, GnuCash <bugzilla@gnome.org> wrote:
> https://bugzilla.gnome.org/show_bug.cgi?id=609583
>  GnuCash | SQL Backend | 2.3.8
>
> --- Comment #3 from Phil Longstaff <plongstaff@rogers.com> 2010-02-10 20:54:17 UTC ---
> Or, please do it again, and look at /tmp/gnucash.trace which will contain the
> trace file with some debug information.  It is overwritten each time you run
> gnucash.

Sending you my xml file is out of the question. It contains my
financial records for many, many years, just not something I would
consider sharing. I suspect you'd get the same answer from the vast
majority of people.

Having said that, I'll help you debug this. I'm a recently-retired
computer professional. Wrote my first program (in machine code on an
IBM 1620) in 1960 while in college and worked as an individual
contributor and manager of software projects large and small at places
like BBN, MIT, and Thinking Machines. I know C, Scheme and just about
every programming language you can name, except the really ugly ones,
like Perl. I hope I haven't offended you :-) I've done a fair amount
of programming, even in recent years, so I'm not out of practice.

I'll do what you ask above and if that doesn't get anywhere, we can
work together with gnucash under gdb, perhaps while talking on the
phone.

I'll send you the trace file tonight or tomorrow.

/Don

I said last night that I'd send the gnucash.trace file, but reading
your message again, you just ask me to look at it. Looking at it, I'm
more comfortable with that, since it's got a replay of much of my
financial records, due to the 'save as', so I'd prefer not to send you
the trace file either.

Looking at it, and specifically looking at the end of it, I see a
bunch of inserts into the splits table. The last one with a valid date
in it has a date value of '20060508040000'. This is consistent with
what I am seeing after I restart gnucash, having previously done a
save-as to a sqlite3 file, namely that the data is truncated to
sometime in 2006.

Let me know if you need me to do more. Again, I'm open to a debugging
session over the phone, if need be.

/Don

Email to me from Phil:

Q1: If you search the trace file, are there any messages with "CRIT" which indicate a failure.

Q2: Do you see any saves to the splits table with dates after '20060508040000'?  If so, do they show up when you reopen the file?  If they don't show up, are there any DELETE lines for the splits table which delete those splits?

I'm not offended by your language choices.  Do you know SQL?
 
Phil

On Thu, Feb 11, 2010 at 11:20 AM, Phil Longstaff <plongstaff@rogers.com> wrote:
> Q1: If you search the trace file, are there any messages with "CRIT" which
> indicate a failure.

dca@octavian:/tmp$ fgrep CRIT gnucash.trace.1
* 09:28:57  CRIT <GLib>     g_hash_table_destroy: assertion
`hash_table != NULL' failed
* 09:30:22  CRIT <gnc.backend.sql>     gnc_sql_save_commodity:
assertion `pCommodity != NULL' failed
dca@octavian:/tmp$

>
> Q2: Do you see any saves to the splits table with dates after
> '20060508040000'?  If so, do they show up when you reopen the file?  If they
> don't show up, are there any DELETE lines for the splits table which delete
> those splits?

No, but here is the very end of the trace file for the session where I
did the save-as (the assertion failure after the insert looks like a
major clue to me -- I'm guessing that after the assertion failure, it
threw up its hands and quit inserting?):

* 09:30:22 DEBUG <gnc.backend.dbi>
[conn_execute_nonselect_statement] SQL: INSERT INTO
splits(guid,tx_guid,account_guid,memo,action,reconcile_state,reconcile_date,value_num,value_denom,quantity_num,quantity_denom,lot_guid)
VALUES('c48a5b74fb9a728b7dcc3ff2b53cbcb3','c6203a47d973697f08858556f44cb81b','75e1a4020da65a350a41031fae57a78c','','','y','20060508040000',-6490,100,-6490,100,NULL)
* 09:30:22  CRIT <gnc.backend.sql>     gnc_sql_save_commodity:
assertion `pCommodity != NULL' failed
* 09:30:22 DEBUG <gnc.backend.dbi>     [conn_commit_transaction] COMMIT
* 09:30:22 DEBUG <gnc.backend.dbi> [leave gnc_dbi_sync_all()] book=0x2a1eb00
* 09:30:28 DEBUG <gnc.backend.dbi> [enter
gnc-backend-dbi.c:gnc_dbi_session_end()]
* 09:30:28 DEBUG <gnc.backend.dbi> [leave gnc_dbi_session_end()]


>
> I'm not offended by your language choices.  Do you know SQL?

Yes. Lots of Oracle and Postgresql experience. I've also written
Python, Scheme (both MIT Scheme and Scheme48 -- for the latter, I
wrote my own interface to libpq), and C apps that talked to Postgresql
and C code that talked to sqlite3.

/Don

Could this be due to a non-printable character in the XML data.  These are allowed in XML (such as line-feed in a text field) but not in SQL.  I have tested line-feed in the Notes field in SQLITE3 with no problem, but other non-printable characters may be trouble.

To check this, I would edit the XML file with a text editor (in Windows, I recommend Textpad from http://www.textpad.com).  Look at the transaction immediately following the most recent transaction that does appear.

Oops.  I meant edit with a hex editor.

I looked at the transaction you suggested with od, and scanning visually, I saw no non-printing characters other than 0xa. I then wrote a little Python program to scan the whole file for characters less than 0x20 and not 0xa. This turned up 5 or 6 transactions with tabs in the number field (I pay my bills with my bank's electronic bill-paying service, and I generally copy-paste the transaction id into the number field when entering the transaction into gnucash; I'm pretty certain that's how they got there). I edited each transaction with gnucash 2.2.9 to eliminate the tabs and re-ran my little Python thing to confirm that there were no longer any non-printing characters other than 0xa. I then repeated the experiment with gnucash 2.3.8 (opening the latest xml file, saving it as a sqlite3 file and restarting gnucash), and the truncation still occurs.

So, good thought, but it appears that's not the issue.

Might I suggest that you build an svn trunk and fire up gdb on it? It will go a lot faster once you know why that assert is firing. Having an svn build will also make it easier for you to test (or write) a patch once the problem is isolated.

Yes, you might :-) I was thinking of trying a gdb session on 2.3.10, which I have installed now, but it makes more sense to do it on a checkout, which will be current and can be kept current, as you suggest. I had suggested to Phil that he and I try a debug session together, since he knows the code and I don't. But he's gone radio-silent for about a week, perhaps busy with other stuff, like earning a living. So I'll take a shot at this myself ....

I did the checkout of the svn trunk, as John suggested, and built and installed that. I then ran it under gdb, opened a copy of my xml file and then set a conditional breakpoint in 

gboolean
gnc_sql_save_commodity( GncSqlBackend* be, gnc_commodity* pCommodity )
{
	gboolean is_ok = TRUE;

	g_return_val_if_fail( be != NULL, FALSE );
-->	g_return_val_if_fail( pCommodity != NULL, FALSE );

on the indicated line if pCommodity == 0.

I then did the 'Save As' to the sqlite3 file and hit the breakpoint. Stack trace:

+ Trace 220670

After going up one frame,

(gdb) print *pTx
$8 = {inst = {object = {g_type_instance = {g_class = 0xdcae10}, ref_count = 1, qdata = 0x0}, 
    e_type = 0xd8cf90 "Trans", kvp_data = 0x155a9e0}, date_entered = {tv_sec = 1146784061, 
    tv_nsec = 0}, date_posted = {tv_sec = 1146715200, tv_nsec = 0}, num = 0xf7b500 "4BABU2XY", 
  description = 0xce44b0 "Heng-Jin Park", common_currency = 0x0, splits = 0xa5e0c0, 
  marker = 42 '*', orig = 0x0}

As you can see from the stack trace, gnc_sql_save_commodity is being called
from this line in save_transaction:

	if( op != OP_DB_DELETE ) {
    	// Ensure the commodity is in the db
-->    	is_ok = gnc_sql_save_commodity( be, xaccTransGetCurrency( pTx ) );
	}

xaccTransGetCurrency:

gnc_commodity *
xaccTransGetCurrency (const Transaction *trans)
{
  return trans ? trans->common_currency : NULL;
}

But common_currency is 0 in the above transaction, causing the assertion failure.

This was a vanilla payment from my checking account for a piano lesson -- nothing fancy. I have never done anything about setting the currency, assuming the defaults were correct (looking at the Accounts preferences in the svn trunk version, the default currency is Locale: USD). This transaction occurred
 
dcatest@octavian:~$ tclsh
% clock format 1146784061
Thu May 04 19:07:41 EDT 2006
% 

and after letting the 'save as' complete and restarting gnucash, which reads the sqlite3 file, the last transaction in my checking account is on 2006-05-04, so this all looks consistent.

Here's what this transaction looks like in the xml file:

<gnc:transaction version="2.0.0">
  <trn:id type="guid">772ffbbe1c3827802f48c736f5cab626</trn:id>
  <trn:num>4BABU2XY</trn:num>
  <trn:date-posted>
    <ts:date>2006-05-04 00:00:00 -0400</ts:date>
  </trn:date-posted>
  <trn:date-entered>
    <ts:date>2006-05-04 19:07:41 -0400</ts:date>
  </trn:date-entered>
  <trn:description>Heng-Jin Park</trn:description>
  <trn:splits>
    <trn:split>
      <split:id type="guid">77b52745c99ab370a04fe2bd80f9060b</split:id>
      <split:reconciled-state>n</split:reconciled-state>
      <split:value>9000000/100000</split:value>
      <split:quantity>9000/100</split:quantity>
      <split:account type="guid">36d228f3ab0b197b19f97ce970dcbecd</split:account>
    </trn:split>
    <trn:split>
      <split:id type="guid">8bd783f30ba32cad82e17ab899f221ba</split:id>
      <split:reconciled-state>y</split:reconciled-state>
      <split:reconcile-date>
        <ts:date>2006-05-08 00:00:00 -0400</ts:date>
      </split:reconcile-date>
      <split:value>-9000000/100000</split:value>
      <split:quantity>-9000/100</split:quantity>
      <split:account type="guid">75e1a4020da65a350a41031fae57a78c</split:account>
    </trn:split>
  </trn:splits>
</gnc:transaction>

Here's the xml of last transaction that appears in my checking account after restarting gnucash:

<gnc:transaction version="2.0.0">
  <trn:id type="guid">c6203a47d973697f08858556f44cb81b</trn:id>
  <trn:currency>
    <cmdty:space>ISO4217</cmdty:space>
    <cmdty:id>USD</cmdty:id>
  </trn:currency>
  <trn:date-posted>
    <ts:date>2006-05-04 00:00:00 -0400</ts:date>
  </trn:date-posted>
  <trn:date-entered>
    <ts:date>2006-05-13 09:22:46 -0400</ts:date>
  </trn:date-entered>
  <trn:description>USPS Money Order</trn:description>
  <trn:splits>
    <trn:split>
      <split:id type="guid">542c0dd4bbb5e162cc687b576348948c</split:id>
      <split:memo>Graflex TLR camera</split:memo>
      <split:reconciled-state>n</split:reconciled-state>
      <split:value>6490/100</split:value>
      <split:quantity>6490/100</split:quantity>
      <split:account type="guid">9615036ff514bf896f3e64f43f2de30d</split:account>
    </trn:split>
    <trn:split>
      <split:id type="guid">c48a5b74fb9a728b7dcc3ff2b53cbcb3</split:id>
      <split:reconciled-state>y</split:reconciled-state>
      <split:reconcile-date>
        <ts:date>2006-05-08 00:00:00 -0400</ts:date>
      </split:reconcile-date>
      <split:value>-6490/100</split:value>
      <split:quantity>-6490/100</split:quantity>
      <split:account type="guid">75e1a4020da65a350a41031fae57a78c</split:account>
    </trn:split>
  </trn:splits>
</gnc:transaction>

Note the trn:currency entry in this transaction, which is missing from the failing transaction. This appears to be the only transaction in my data file that is missing the trn:currency entry. Using the svn trunk version of gnucash, I again opened a copy of my current xml file and changed the piano-lesson transaction amount from $90 to $123 (after dealing with gnucash's warning that I was changing a reconciled transaction), entered it and saved it (I attempted a 'Save As' in xml format and despite selecting xml in the pull-down at the top of the file dialog, it saves the file in sqlite3 format; I will enter a separate bug for this). I then gunzip'ed it and looked at it in emacs, and the transaction *still* has no trn:currency entry (it does have the new amount, so I know this is the modified transaction).

Enough for now. Any ideas for how to proceed are welcome.

Excellent job.

The easy work-around is to open the xml file in your favorite editor and paste the <trn:currency> element from a transaction that has it to the one that's missing it.

Properly fixing the problem would require modifying the check-and-repair routines to notice a missing currency element and insert one. No, I don't know where those routines are. The assert should be replaced with more detailed error reporting and handling so that other users who bump up against it don't have to repeat your work. Neither of those is your job, but if you're interested, the "Add an attachment" link below is where to put your patch. ;-)

Thanks for the compliment. I've been doing this for awhile (46 years professionally), as I noted in an earlier comment, and haven't forgotten how (yet).

I understand how to edit the xml file to work around this issue. That's of interest, but of less interest than why this transaction is being written as it is (without the trn:currency entry) and whether that's a bug (either the transaction is mal-formed without the trn:currency clause, or the sql backend is assuming it's illegal when it's not). I think I will send a message to the gnucash-dev list and inquire about this. I'm sure some of the experienced gnucash people, e.g., Derek, will be able to shed some light on this.

Phil Longstaff is the dev who's done the dbi work, and he's away till mid-March. 

I think that enforcing a currency entry is the right thing to do, particularly in light of the recent discussions about handling multiple currencies. Why that one record from 2006 is missing one is going to be very hard to reconstruct, which is why I think that the corrective action is to detect and repair it when encountered rather than to go on a bug hunt unless it can be shown that the current version of Gnucash also sometimes writes transactions to the xml file without including a currency element.

I did one more experiment. Rather than changing the existing transaction (which did not result in adding the trn:currency clause), I simply deleted it (with the svn trunk version of gnucash) and re-entered it. The new transaction is identical to the old, save for its reconciliation state, but was not necessarily entered with exactly the same UI gestures. The new one appears to have the trn:currency clause. I say 'appears' because I didn't check the xml directly, but instead did a save-as to a sqlite3 file and then restarted gnucash. Now my checking account looks correct -- not truncated.

I don't think this proves that it's impossible to generate such a currency-less transaction again, so I do think we need to know whether such a transaction is mal-formed. I will send a message to gnucash-developers about this. I agree with you that something better needs to be done in the sql backend re handling this. Right now, it fails silently and you only find out that something's amiss when you restart and your numbers look weird. I think it's a waste of my time to try to fix this without some help from somebody, since I don't know enough about gnucash, and probably Phil is the right person. So I'm going to wait until he gets back in March to try to improve this. 

I will comment that it felt like it took significantly longer (I did not measure this, but I will) to open the sqlite3 file than it does the xml file on the same machine. My xml file is over 20 Mb uncompressed, so its a lot of stuff. From this, it feels like he's loading the whole db into memory (I have a vague recollection that this issue got discussed on one of the mailing lists and that Phil said this was the case), a strategy we could argue about, but it may have been imposed on him by the existing structure of gnucash and the history with xml files, which obviously aren't amenable to selective loading and updating. I'll do some real timings and I'll comment on gnucash-developers if I find anything interesting.

I should improve/clarify what I said in the previous comment. I'd *like* to know whether the currency-less transaction is mal-formed, but whether it is or it isn't, and regardless of whether the current version still does this, the sql backend needs to handle this situation better, since, as you said earlier, others could come along with xml files having the same problem as mine.

If it turns out that it *is* mal-formed, and if we can't turn up a prior bug fix for this, then we can decide on whether to go on a "bug hunt". But that's orthogonal to whether we fix the sql backend to do better error reporting in this case.

I am closing this bug. It was not a problem with the SQL backend per se (though some improvement is warranted in reporting assertion failure to the user -- right now it fails silently, noting the error only in the gnucash.trace file); it was caused by a mal-formed transaction written by a 4-year-old version of Gnucash. Version 2.2.9's Check & Repair fixed the transaction (which was missing a trn:currency clause) and the data lossage by the SQL backend went away.

*** This bug has been marked as a duplicate of bug 632166 ***

GnuCash bug tracking has moved to a new Bugzilla host. This bug has been copied to https://bugs.gnucash.org/show_bug.cgi?id=609583. Please update any external references or bookmarks.