Odd values from station and timeouts.

[xayide]

I had a few odd problems today. Cumulus said the station was lost and then somehow seemed to get erroneous data. All I did to solve this was to restart cumulusMX. Since I wasn't at home I couldn't see if there were any errors on the WH3080 console. But it looked all fine when I got home and it seems to have logged correct data during the hours Cumulus got erroneous data. Full logs attached.

But this is a snippet of where it all started....:

Code: Select all

2015-04-21 09:00:00.303 Hour changed:9
2015-04-21 09:00:00.303 Sunrise: 05:38:00
2015-04-21 09:00:00.303 Sunset : 20:27:09
2015-04-21 09:00:00.303 Writing log entry for 21/04/2015 09:00:00
2015-04-21 09:00:00.303 Written log entry for 21/04/2015 09:00:00
2015-04-21 09:00:00.303 Writing today.ini, LastUpdateTime = 21/04/2015 09:00:00 raindaystart = 60 rain counter = 60
Latest reading: 5DD0: 00 13 3C 01 38 5A 00 78 27 1F 2C 00 02 C8 00 00
2015-04-21 09:01:00.894 Writing log entry for 21/04/2015 09:01:00
2015-04-21 09:01:00.894 Written log entry for 21/04/2015 09:01:00
2015-04-21 09:01:00.894 Writing today.ini, LastUpdateTime = 21/04/2015 09:01:00 raindaystart = 60 rain counter = 60
Latest reading: 5DE4: 00 13 3C 01 38 5A 00 77 27 22 30 00 00 C8 00 00
2015-04-21 09:02:00.641 Writing log entry for 21/04/2015 09:02:00
2015-04-21 09:02:00.641 Written log entry for 21/04/2015 09:02:00
2015-04-21 09:02:00.641 Writing today.ini, LastUpdateTime = 21/04/2015 09:02:00 raindaystart = 60 rain counter = 60
Latest reading: 5DF8: 00 13 3E 01 38 5A 00 78 27 18 1F 00 02 C8 00 00
2015-04-21 09:02:18.641 Operation timed out.
2015-04-21 09:02:18.641 Error reading data from station - it may need resetting
2015-04-21 09:02:21.641 Operation timed out.
2015-04-21 09:02:21.641 Error reading data from station - it may need resetting
2015-04-21 09:02:24.656 Operation timed out.
2015-04-21 09:02:24.656 Error reading data from station - it may need resetting
2015-04-21 09:02:27.656 Operation timed out.
2015-04-21 09:02:27.656 Error reading data from station - it may need resetting
2015-04-21 09:02:30.656 Operation timed out.
2015-04-21 09:02:30.656 Error reading data from station - it may need resetting
2015-04-21 09:02:33.671 Operation timed out.
2015-04-21 09:02:33.671 Error reading data from station - it may need resetting
2015-04-21 09:02:36.671 Operation timed out.
2015-04-21 09:02:36.671 Error reading data from station - it may need resetting
2015-04-21 09:02:45.936 Ignoring bad data: pressure = 33.2999999999999
2015-04-21 09:02:45.936                    offset = 0
Ignoring bad data: gust = 76.9
2015-04-21 09:02:45.936 Ignoring bad data: outtemp = 463
2015-04-21 09:02:45.936 Warning: large difference in rain gauge tip count: 200
2015-04-21 09:02:45.936 Ignoring reading 1
2015-04-21 09:02:58.686 Operation timed out.
2015-04-21 09:02:58.686 Error reading data from station - it may need resetting
2015-04-21 09:03:00.139 Writing log entry for 21/04/2015 09:03:00
2015-04-21 09:03:00.139 Written log entry for 21/04/2015 09:03:00
2015-04-21 09:03:00.139 Writing today.ini, LastUpdateTime = 21/04/2015 09:03:00 raindaystart = 60 rain counter = 60
Latest reading: 0415: 17 12 27 15 04 16 12 38 01 20 01 33 11 00 00 00
2015-04-21 09:03:08.701 Operation timed out.
2015-04-21 09:03:08.701 Error reading data from station - it may need resetting
2015-04-21 09:03:18.701 Operation timed out.
2015-04-21 09:03:18.701 Error reading data from station - it may need resetting
2015-04-21 09:03:21.700 Operation timed out.
2015-04-21 09:03:21.700 Error reading data from station - it may need resetting
2015-04-21 09:03:35.997 Ignoring bad data: pressure = 2.09999999999991
2015-04-21 09:03:35.997                    offset = 0
New monthly record, month = 4: 2015-04-21 09:03 -4.852 "Low wind chill" 2015-04-05 06:47 -4.000
2015-04-21 09:03:35.997 Warning: large difference in rain gauge tip count: 200
2015-04-21 09:03:35.997 Ignoring reading 2
2015-04-21 09:04:00.324 *** Data input appears to have stopped
2015-04-21 09:04:00.324 Writing log entry for 21/04/2015 09:04:00
2015-04-21 09:04:00.324 Written log entry for 21/04/2015 09:04:00
2015-04-21 09:04:00.324 Writing today.ini, LastUpdateTime = 21/04/2015 09:04:00 raindaystart = 60 rain counter = 60
Latest reading: FF00: FF 00 00 00 00 00 00 00 00 00 00 00 11 00 00 00
2015-04-21 09:04:08.761 Operation timed out.
2015-04-21 09:04:08.761 Error reading data from station - it may need resetting
2015-04-21 09:04:29.041 Operation timed out.
2015-04-21 09:04:29.041 Error reading data from station - it may need resetting
2015-04-21 09:04:32.041 Operation timed out.
2015-04-21 09:04:32.041 Error reading data from station - it may need resetting
2015-04-21 09:04:35.057 Operation timed out.
2015-04-21 09:04:35.057 Error reading data from station - it may need resetting
2015-04-21 09:04:38.072 Operation timed out.
2015-04-21 09:04:38.072 Error reading data from station - it may need resetting
2015-04-21 09:04:38.072 Ignoring bad data: pressure = 2.09999999999991
2015-04-21 09:04:38.072                    offset = 0
2015-04-21 09:04:38.072 Warning: large difference in rain gauge tip count: 200
2015-04-21 09:04:38.072 Ignoring reading 3
2015-04-21 09:04:41.072 Operation timed out.

And here is after restart of Cumulus MX. I am running 3024.

Code: Select all

2015-04-21 15:56:25.394 Reading current address 01DC
2015-04-21 15:56:25.654 Number of history entries = 0
2015-04-21 15:56:26.543 Start Timers
2015-04-21 15:56:26.543 Starting 1-minute timer
2015-04-21 15:56:26.543 Starting Realtime timer, interval = 30000ms
2015-04-21 15:56:47.077 Rain total count from station = 200
 ****Rain reset? First chance: raindaystart = 1228.8, Raincounter = 60
Leaving counter at 1228.8
 ****Rain counter reset confirmed: raindaystart = 1228.8, Raincounter = 60
Setting raindaystart to 60
2015-04-21 15:57:00.981 Writing log entry for 21/04/2015 15:57:00
2015-04-21 15:57:00.981 Written log entry for 21/04/2015 15:57:00
2015-04-21 15:57:00.981 Writing today.ini, LastUpdateTime = 21/04/2015 15:57:00 raindaystart = 60 rain counter = 60
Latest reading: 01DC: 19 20 E9 00 30 79 00 6C 27 1F 29 00 02 C8 00 00
2015-04-21 15:58:00.686 Writing log entry for 21/04/2015 15:58:00

[steve]

I've noticed that this can happen when the station moves on to the next memory location. There is code in MX to cater for the address changing (it skips a read to allow the console time to sort itself out) but for some reason it can still get bad data - and those timeouts. As you have the station's logger set to 1 minute (which is not a supported value) you are more likely to see this. Debug logging would have shown a bit more information, but you don't have that turned on. Data logging even more so.

I do have some changes in the pipeline which might help, but at the moment I don't really know why this happens.

[xayide]

I could return it to 5 minutes. But I think I will live on the edge for this beta and stay at 1 minute with debugging on. Just to see what happens and if there can be any more details to this.

Turned on bot datalogging=1 and logging=1 to station section. Is catalogging=! put to mxdiags same as logging=1 ?

[xayide]

I have now set the station to 10 minute logging. But still it seems to be asking the station for data every 10 seconds?

below is the start of mxdiags file. and the next code block is the readings...showing about 10 seconds intervall for my stations 10 minutes logging intervall. I have also set cumulusMX to 10 minutes.

Code: Select all

2015-05-07 17:19:57.826  ========================== Cumulus MX starting ==========================
2015-05-07 17:19:57.826 Command line: "C:\CumulusMX\CumulusMX.exe" 
2015-05-07 17:19:57.826 Cumulus MX v.3.0.0 build 3024
2015-05-07 17:19:57.830 Platform: Win32NT
2015-05-07 17:19:57.830 OS version: Microsoft Windows NT 6.2.9200.0
2015-05-07 17:19:57.830 Current culture: English (United Kingdom)
2015-05-07 17:19:57.830 Standard time zone name:   W. Europe Standard Time
2015-05-07 17:19:57.830 Daylight saving time name: W. Europe Daylight Time
2015-05-07 17:19:57.830 Daylight saving time? True
2015-05-07 17:19:57.830 07/05/2015 17:19:57
2015-05-07 17:19:57.830 Data path = data\
2015-05-07 17:19:57.830 Creating backup folder backup\20150507171957\
2015-05-07 17:19:57.845 Reading Cumulus.ini file
2015-05-07 17:19:57.849 ASM=10 AST=00:10:00
2015-05-07 17:19:57.849 Cumulus start date: 2015-02-24
2015-05-07 17:19:57.853 Debug logging is enabled
2015-05-07 17:19:57.853 Logging interval = 10
2015-05-07 17:19:57.860 Sunrise: 04:58:00
2015-05-07 17:19:57.860 Sunset : 21:02:45
2015-05-07 17:19:57.860 Tomorrow Sunrise: 04:56:00
2015-05-07 17:19:57.860 Tomorrow Sunset : 21:04:57
2015-05-07 17:19:57.860 Tomorrow length diff: 252
2015-05-07 17:19:57.868 Station type: Fine Offset with Solar
2015-05-07 17:19:57.868 WindUnit=m/s RainUnit=mm TempUnit=°C PressureUnit=mb
2015-05-07 17:19:57.868 YTDRain=0.000 Year=0
2015-05-07 17:19:57.868 RainDayThreshold=-1.000
2015-05-07 17:19:57.868 Offsets and Multipliers:
2015-05-07 17:19:57.868 PO=0.000 TO=-1.200 HO=0 WDO=0 ITO=0.000 UVO=0.000
2015-05-07 17:19:57.868 WSM=1.000 WGM=1.000 TM=1.000 TM2=1.000 HM=1.100 RM=1.000 UVM=0.330
2015-05-07 17:19:57.868 Spike removal:
2015-05-07 17:19:57.868 TD=10.000 GD=40.000 WD=20.000 HD=50.000 PD=20.000
2015-05-07 17:19:57.868 MR=300.000 MH=150.000
2015-05-07 17:19:57.868 Cumulus Starting
2015-05-07 17:19:57.868 Opening station
2015-05-07 17:19:57.875 Last update time from today.ini: 07/05/2015 17:15:00
2015-05-07 17:19:57.875 Read today file: Date = 07/05/2015, LastUpdateTime = 07/05/2015 17:15:00, Month = 5
2015-05-07 17:19:57.875 Sensor clock  00:24:39
2015-05-07 17:19:57.875 Station clock 00:24:51
2015-05-07 17:19:57.879 ReadTodayfile: set notraininit false
C:\CumulusMX\data\alltime.ini
Alltime.ini file read
MonthlyAlltime.ini file read
Month.ini file read
Year.ini file read
2015-05-07 17:19:57.890 Finding raintoday from logfile data\May15log.txt
2015-05-07 17:19:57.890 Expecting listsep=; decimal=.
Midnight rain found in the following entry:
07/05/15;00:00;9.4;83;6.7;1.2;2.7;196;0.0;0.0;1008.0;111.0;23.1;43;1.7;9.4;9.4;0.0;0;0.00;0.00;7.8;0;0.0;202;0.0;0.0
Setting raintoday from logfile = 111
Calculating rain counter = 111
Midnight rain found = 111
Getting rain totals, rain season start = 1
2015-05-07 17:19:57.980 Rainthismonth from dayfile.txt: 41.4
2015-05-07 17:19:57.980 Rainthisyear from dayfile.txt: 99.3
2015-05-07 17:19:57.999 Looking for Fine Offset station
2015-05-07 17:19:58.018 Fine Offset station found
2015-05-07 17:19:58.022 Stream opened
2015-05-07 17:19:58.022 Reading pressure offset
2015-05-07 17:19:58.266 Rel pressure = 1013.9
2015-05-07 17:19:58.266 Abs pressure = 993.7
2015-05-07 17:19:58.266 Offset       = 20.1999999999999
2015-05-07 17:19:58.266 Loading last N hour data from data logs: 07/05/2015 17:15:00
2015-05-07 17:19:58.352 Loaded 8 entries to last hour data list
2015-05-07 17:19:58.431 Loaded 8 entries to last 3 hour data list
2015-05-07 17:19:58.509 Loaded 906 entries to last 24 hour data list
2015-05-07 17:19:58.708 Error at line 23135 of data\Apr15log.txt : Input string was not in a correct format.
2015-05-07 17:19:58.708 Please edit the file to correct the error
2015-05-07 17:19:58.840 Error at line 3620 of data\May15log.txt : Constraint
2015-05-07 17:19:58.840 Please edit the file to correct the error
2015-05-07 17:19:58.840 Loaded 3619 entries to recent data list
2015-05-07 17:19:58.840 Loaded 31 entries to daily data list
2015-05-07 17:19:58.840 Current culture: English (United Kingdom)
2015-05-07 17:19:58.840 07/05/2015 17:19:58
2015-05-07 17:19:58.840 Reading history data
Last Update = 07/05/2015 17:15:00
2015-05-07 17:19:58.858 624 web tags initialised
2015-05-07 17:19:58.862 HTML root path = C:\CumulusMX\interface
2015-05-07 17:19:58.881 Starting web socket server on port 8002
2015-05-07 17:19:59.121 Reading current address 0128

Code: Select all

New monthly record, month = 5: 2015-05-07 17:43 3677.645 "High daily windrun" 2015-05-07 17:42 3677.525
2015-05-07 17:43:00.267 Within 3 seconds of sensor data change, skipping read
2015-05-07 17:43:10.791 0164: 01 2A E7 00 46 6F 00 D1 26 29 3A 00 0A 72 01 00
2015-05-07 17:43:20.788 0164: 01 2A E7 00 46 6F 00 D1 26 29 3A 00 0A 72 01 00
2015-05-07 17:43:30.789 0164: 01 2A E7 00 46 6F 00 D1 26 29 3A 00 0A 72 01 00
2015-05-07 17:43:40.800 0164: 01 2A E7 00 46 6F 00 D1 26 29 3A 00 0A 72 01 00
2015-05-07 17:43:50.300 Within 3 seconds of sensor data change, skipping read
2015-05-07 17:43:50.300 Within 3 seconds of station clock minute change, skipping read
2015-05-07 17:44:00.816 0164: 02 2A E7 00 46 6F 00 D2 26 29 3A 00 0A 72 01 00
New monthly record, month = 5: 2015-05-07 17:44 3677.767 "High daily windrun" 2015-05-07 17:43 3677.645
2015-05-07 17:44:10.828 0164: 02 2A E7 00 46 6F 00 D2 26 29 3A 00 0A 72 01 00
2015-05-07 17:44:20.843 0164: 02 2A E7 00 46 6F 00 D2 26 29 3A 00 0A 72 01 00
2015-05-07 17:44:30.847 0164: 02 2A E7 00 46 6F 00 D2 26 29 3A 00 0A 72 01 00
2015-05-07 17:44:40.347 Within 3 seconds of sensor data change, skipping read
2015-05-07 17:44:50.351 Within 3 seconds of station clock minute change, skipping read
New monthly record, month = 5: 2015-05-07 17:45 3677.900 "High daily windrun" 2015-05-07 17:44 3677.767
2015-05-07 17:45:00.871 0164: 03 2B E7 00 45 6E 00 D1 26 0E 14 00 0A 72 01 00
2015-05-07 17:45:10.874 0164: 03 2B E7 00 45 6E 00 D1 26 0E 14 00 0A 72 01 00
2015-05-07 17:45:20.886 0164: 03 2B E7 00 45 6E 00 D1 26 0E 14 00 0A 72 01 00
2015-05-07 17:45:30.890 0164: 04 2B E7 00 45 6E 00 D0 26 11 22 00 08 72 01 00
2015-05-07 17:45:40.902 0164: 04 2B E7 00 45 6E 00 D0 26 11 22 00 08 72 01 00
2015-05-07 17:45:50.406 Within 3 seconds of station clock minute change, skipping read
New monthly record, month = 5: 2015-05-07 17:46 3678.030 "High daily windrun" 2015-05-07 17:45 3677.900
2015-05-07 17:46:00.912 0164: 04 2B E7 00 45 6E 00 D0 26 11 22 00 08 72 01 00

[steve]

I have now set the station to 10 minute logging. But still it seems to be asking the station for data every 10 seconds?

That's how it works. The data reading interval is not related to the logging interval. If it only read the data every 10 minutes, a lot of data would be missed. The data updates every 48 seconds; Cumulus reads it every 10 seconds rather than trying to work out when it's actually changed. This is how Cumulus has always worked.

[xayide]

Aha that clarifies a lot for me. Then settings it to 10 minutes wouldn't really be of any change to realtime data upload to my web server except for when it stops reading and I have to read the log from the console. But the benefit should be less of these damned lockups.

Anyways. I tried the easyweather station type in MX it seems not to work. Is that by any chance I am the first to see that?

[steve]

Anyways. I tried the easyweather station type in MX it seems not to work. Is that by any chance I am the first to see that?

It's possible that you're the first to try it with MX, yes, I can't remember at the moment. What happens exactly? Does it not display the data at all? Does it display one set of data and then not update? Something else?

Does your easyweather.dat file use spaces for a delimiter? Cumulus 1 delimits on commas and spaces, as a side effect of the way the system routine works. I suspect that MX is only delimiting on commas. It's almost certainly broken, I'll see if I can work out a fix.

[xayide]

Seems to be booth comma and space. Its an EasyWeatherPlus.dat file. Since I have the one with solar-sensor. I know this is an unsupported option. But I wanted to give you heads up since its already in there. Since there was no place to put in the filename I used the cumulus.ini file and specified the file on the ewfile-variable. "EWFile=C:\EasyWeatherPlus\EasyWeatherPlus.dat". When I look in the MXdiagsfiles. nothing happens not even a message about no sensor data, or same data received. Just nothing. It's like it doesn't even try to open/import anything from the EW-file. Maybe it just misses the timer-hook?

I should note that I am running beta 3024 and using UK-brittish decimal commas even though I am in sweden.

Below is an exact copy of a snippet from the file.

Code: Select all

     1, 2015-05-07 18:47:36, 2015-05-07 17:12:35,  30,   42,  23.5,   71,  11.3,   6.2,  11.3,   993.5,  1013.7,  1.4,   1,  2.7,   2,   8,   S, 		  370,   111.0,     0.0,     0.0,     0.0,     0.0,     0.0,      0.0,   6019.4,   1, 0, 0, 0, 0, 0, 0, 0, 0, 000100,    1, 1E 2A EB 00 47 71 00 CF 26 0E 1B 00 08 72 01 00 22 EB 00 01 , 000204
     2, 2015-05-07 18:47:36, 2015-05-07 17:17:35,   5,   43,  23.3,   72,  11.1,   6.3,   5.7,   993.4,  1013.6,  4.8,   3,  7.1,   4,  10,  SW, 		  370,   111.0,     0.0,     0.0,     0.0,     0.0,     0.0,      0.0,   7341.8,   1, 0, 0, 0, 0, 0, 0, 0, 0, 000114,    2, 05 2B E9 00 48 6F 00 CE 26 30 47 00 0A 72 01 00 CA 1E 01 01 , 000204
     3, 2015-05-07 18:47:36, 2015-05-07 17:22:35,   5,   43,  23.2,   74,  10.9,   6.5,   6.8,   993.7,  1013.9,  3.7,   3,  6.1,   4,  10,  SW, 		  370,   111.0,     0.0,     0.0,     0.0,     0.0,     0.0,      0.0,  15018.4,   1, 0, 0, 0, 0, 0, 0, 0, 0, 000128,    3, 05 2B E8 00 4A 6D 00 D1 26 25 3D 00 0A 72 01 00 A8 4A 02 01 , 000204

[steve]

Thanks - should be fixed in the next build.

[xayide]

Superfast!


Thanks. I will keep eyes open and try it....

[xayide]

I do not know where to post this, but reading easyweather.dat logfile now works...

[steve]

OK - thanks.