Long Startup on Davis VP2+

[aussiewmr]

Yep - I know what you are all thinking, did you read the Wiki, readme, search and all that - and the answer is yes

All of this may be pertinent to this discussion:
Computer 2.8 GHz P4, 760 MB Ram (400 MB Free), 55 GB C Drive Partition (50 GB Free), Clock is time syncd to Internet source
WS is a VP2 Plus - Firmware 1.90
Cumulus AND VP2+ logging interval is 1 minute

This is not a new issue, its been happening ever since I have had my VP2.

When ever I shut down Cumulus and restart again within say a minute (I do this when changing the Graph interval as this setting does not seem to take unless Cumulus is restarted), Cumulus can take a very long time to become fully operational again. By fully operational I mean the main window has updates with current values and the clock is ticking over.

Where it visually hangs is at the "Please Wait Downloading Data" dialogue box stage. I read the info that this can happen if Cumulus and Davis logging intervals are different - mine are the same (1 minute) and from the log below it seems my issue is not related as the "lag" seems to be after data-log download. If I were to quantify the problem, in 1 start out of 10 it may start quickly, in 2 starts out of 10 it may take 30 to 60 secs and in 7 starts out of 10 it takes longer than a minute. IE most starts take longer than 1 minute, usually a couple of minutes and the odd occasion up to 3 minutes.

While its at this stage the CPU is at 100% and its the Cumulus process using it 98% 0f it (see screen shot attached).

Below is part of my diags file for a start up:

9/03/2012 20:26:54.458 : Firmware Version: 1.90
9/03/2012 20:26:54.458 : Discon period: 0
9/03/2012 20:26:54.458 : VP2: Setting station clock
9/03/2012 20:26:54.458 : y=2012 m=3 d=9 h=20 m=26
9/03/2012 20:26:55.067 : VP2: SetStationTime_V res = 0
9/03/2012 20:26:55.067 : Loading last N hour data from data logs: 9/03/2012 8:26:00 PM
9/03/2012 20:26:56.161 : Last update time = 20:26
9/03/2012 20:26:56.161 : Log interval = 1
9/03/2012 20:26:56.161 : After rounding = 20:26
9/03/2012 20:26:56.177 : VP2: Downloading history from 9/03/2012 8:26:00 PM
9/03/2012 20:26:56.177 : y=2012 m=3 d=9 h=20 m=26
9/03/2012 20:27:00.099 : VP2: DownloadData_V = 0
9/03/2012 20:27:00.099 : VP2: GetNumberOfArchiveRecords_V = -1
9/03/2012 20:27:00.099 : VP2: No history records to process
9/03/2012 20:27:01.036 : VP2: Setting raintotal from current station value: 543.599975585938
9/03/2012 20:27:31.521 : 8:27:31 PM Starting Timers
9/03/2012 20:27:31.974 : VP2: End of history download
9/03/2012 20:27:31.974 : PleaseWaitForm.Close executed
9/03/2012 20:30:00.614 : Writing today.ini, LastUpdateTime = 9/03/2012 8:30:00 PM raindaystart = 543.600036621094 rain counter = 543.600036621094
9/03/2012 20:30:49.067 : Writing cumulus.ini file
9/03/2012 20:30:54.208 : MainForm can close
9/03/2012 20:30:54.208 : Showing splash screen
9/03/2012 20:30:55.036 : Exit FormCloseQuery

I have highlighted the part that seems to take a long time - these three lines represent about a 3 min 20 sec delay from what seems a wait form and splash screen display.

I have attached the diag file where this info came from.

Any ideas?

Thanks
Phil

[steve]

Stopping and starting very soon after, with a Davis station, can cause a slow start up, but this is normally because it causes another situation where the station sends the entire contents of the logger, and that doesn't seem to be the case here.

If you turn on the debug log by default, by putting

logging=1

into the [Station] section in cumulus.ini, and then try to reproduce the problem, the debug.log file might give some clues. But it could be that it's inside the Davis DLL somewhere.

[aussiewmr]

Hi Steve,

As usual when you try to force a fault it never happens as bad when you don't try

I did get a log of a start-up that took about a minute, I did not manage anything worse than this when the logging was on. I only captured one of the 5 attempts I made (each attempt was with a new debug.log to keep the content clean and easy to spot passwords etc).

At the end of the day its not a big issue as now my other Davis problems are sorted I wont have to restart Cumulus anywhere near as often.

I did wait 5 minutes on one attempt to see if accumulation of logs in the Davis helped. When I started Cumulus it downloaded the 5 mins of data real quick then it hung after (high CPU like the others) for about 30 odd secs.

I guess the next thing you will want is a debug.log of all this stuff - so long as there is no sensitive info like passwords etc then I will be happy to do that.

Anyway file attached.

Cheers
Phil

[steve]

If I've understood you correctly, and the 'please wait' form is still on screen during the delay, then what Cumulus is doing between that entry in the diags log which says 'PleaseWaitForm.Close executed' and the form actually disappearing is calculating the 'trend' values. But there are no loops in that code, so it's hard to see how it could actually be spending several minutes in there.

I'm going to be releasing an update with a few minor changes fairly soon, I'll add more trace points to the code in this area so we can perhaps narrow it down a bit.

[aussiewmr]

OK Steve,
Thanks.

And just to help when you do that, is it safe for me to do a long debugging session without the worry of any sensitive info like passwords etc being recorded in the debug.log file?

Cheers
Phil

[steve]

I try to make sure I strip any passwords out of the logging, and I'm not aware of any that are currently logged.

I suspect we won't find a solution anyway; it's hard to fix problems that only one person is having, and I'm not aware of anyone else having reported it. I've been trying to reproduce it myself without success.

[aussiewmr]

Thanks Steve,

Like I said earlier its not a big issue anymore as the restarts of Cumulus are going to be few and far between not my Davis issues all seem resolved.

BTW - the reason I restarted Cumulus was only because the Graph span (not select-a-graph) would not take until the restart - is this easily changed?

Phil

[steve]

BTW - the reason I restarted Cumulus was only because the Graph span (not select-a-graph) would not take until the restart - is this easily changed

It's intentional (for an increased period). I don't want to force a redraw as that would involve using log file data and hence less detailed graphs for most people. It could be a future option, but as the option to restart already exists, I wouldn't regard it as high priority.

[aussiewmr]

Understand fully

[aussiewmr]

Just an update.

This issue has gone away.

What I did was move cumulus to a VM and since then this has not been an issue. I cannot understand why - the laptop was a 2.2 GHz, 2 GB mem, the VM is one of 4 cores at 2.8 GHz and 1 GM. Same OS (XP SP2) and both were / are untainted clean builds.

Cheers
Phil