Startup troubles for 2.4.0 under OS X

[David T.]

--- On Sun, 2/6/11, John Ralls <jralls at ceridwen.us> wrote:

> From: John Ralls <jralls at ceridwen.us>
> Subject: Re: Startup troubles for 2.4.0 under OS X
> To: "David T." <sunfish62 at yahoo.com>
> Cc: gnucash-user at lists.gnucash.org
> Date: Sunday, February 6, 2011, 8:54 PM
> 
> On Feb 6, 2011, at 8:44 PM, David T. wrote:
> 
> > The compressed file is 1.8 MB. XML. Intel Mac running
> 10.5.8. It is the only data file I have.
> > 
> > Typically, this part of start up takes 30 secs. I
> *thought* I put in a bug about the start up running
> thousands of sql transaction checks (or something like it),
> but I can't seem to find that at bugzilla or on the list
> archives. 
> > 
> > I just looked in gnucash.trace, where I see 5MB of
> statements like the following:
> > 
> > * 17:01:28  INFO <gnc.engine>
> [trans_cleanup_commit] get rid of rollback trans=0x11788440
> > * 17:01:28  INFO <gnc.engine>
> [xaccTransSetDateInternal] addr=0x11788220 set date to
> 1061276400.000000000 Tue Aug 19 00:00:00 2003
> > * 17:01:28  INFO <gnc.engine>
> [xaccTransSetDateInternal] addr=0x11788220 set date to
> 1157752805.000000000 Fri Sep  8 15:00:05 2006
> > 
> > I honestly don't understand why the hell it's doing
> this. While it *does* process about 25 of these a second, it
> does enough of them to take 4 minutes and 40 seconds of
> these. Why would xaccTransSetDateInternal run in excess of
> 7000 times on start up?
> > 
> > David
> > 
> > Ps: I will add info to the wiki about how to track
> down gnucash.trace and the console logfile on Mac, since I
> can never remember the steps to locate these files
> > --- On Sun, 2/6/11, John Ralls <jralls at ceridwen.us>
> wrote:
> > 
> >> From: John Ralls <jralls at ceridwen.us>
> >> Subject: Re: Startup troubles for 2.4.0 under OS
> X
> >> To: "David T." <sunfish62 at yahoo.com>
> >> Cc: "Users Gnucash" <gnucash-user at gnucash.org>
> >> Date: Sunday, February 6, 2011, 6:09 PM
> >> 
> >> On Feb 6, 2011, at 5:10 PM, David T. wrote:
> >> 
> >>> And again, I am staring at 4 minutes start up
> at the
> >> "Loading User data" prompt.
> >>> 
> >>> This is REALLY ANNOYING. Can anyone explain
> why this
> >> happens some times but not others?
> >>> 
> >> 
> >> What kind of file? How big? Do you have only the
> one?
> >> Remind me how long it takes when it loads quickly,
> and what
> >> kind of mac you're using.
> 
> If it's an XML file I'm not likely to connect it with a
> SQLite bug unless you hit me over the head with it... which
> the xaccTransDateInternal may have done. Is there a
> correspondingly huge log file? If there is, does it show
> what dates are getting changed?

I am not seeing huge log files today, but I have in the past.

When I look at the log file just now I see:

mod	trans_guid	split_guid	time_now	date_entered	date_posted	acc_guid	acc_name	num	description	notes	memo	action	reconciled	amount	value	date_reconciled
-----------------
===== START
===== END
===== START
===== END
===== START
===== END
===== START
===== END
===== START
===== END
===== START
D	3419d8045ad74cf434e1599f56f18218	6899319eccb9490f9bcc4d5a3d231787	2011-02-06 21:26:40.000000 -0800	2011-02-06 21:26:40.000000 -0800	2011-02-06 00:00:00.000000 -0800								n	0/1	0/100	1969-12-31 16:00:00.000000 -0800
===== END
===== START
D	41f264721f8756903d29115848fb1251	12868df7aa2876419aca8e7787024ffb	2011-02-06 21:26:41.000000 -0800	2011-02-06 21:26:41.000000 -0800	2011-02-06 00:00:00.000000 -0800								n	0/1	0/100	1969-12-31 16:00:00.000000 -0800
===== END
===== START
D	78fd1710a7315da5175ff3317ded6929	d2a5645380b6be5f156282ccff637153	2011-02-06 21:26:41.000000 -0800	2011-02-06 21:26:41.000000 -0800	2011-02-06 00:00:00.000000 -0800								n	0/1	0/100	1969-12-31 16:00:00.000000 -0800
===== END
===== START
D	b8907a54ed5c3576b04c3f86ebd0c703	461bf9d0dd830b76a0b2390792f8d9a8	2011-02-06 21:26:41.000000 -0800	2011-02-06 21:26:41.000000 -0800	2011-02-06 00:00:00.000000 -0800								n	0/1	0/100	1969-12-31 16:00:00.000000 -0800
===== END
===== START
D	783b85f5fa32c4dc4fdc638191c88a6b	06a78d4330e0ba96d3d73a88c7ffff34	2011-02-06 21:26:41.000000 -0800	2011-02-06 21:26:41.000000 -0800	2011-02-06 00:00:00.000000 -0800								n	0/1	0/100	1969-12-31 16:00:00.000000 -0800
===== END

I note the odd timestamps: one with today's date but zero hours, and the other being the unix zero date 1969-12-31...

> 
> BTW, you forgot to cc the list.

Yeah. I caught that just after sending...

David

> 
> Regards,
> John Ralls
> 
>