ClimateDataCalculation

[Mastiff]

To be honest I have only set it at work and left it to see if it locked up. How do I check that?

[krambriw]

It will be printed with ' Current Q size:' statements if the queue gets larger than 0. Like in this example:

Code: Select all

18:07:56   RFXtrx.Type: THGN122/123, THGN132, THGR122/228/238/268 id: 8194 ' temperature: -5.8 deg C humidity: 71 %RH status: wet signal: 7 battery: 9'
18:08:00   Current Q size:  1
18:08:01   Main.Weather Condition: 'Fair'
18:08:01   Main.ParkEvenNumber
18:08:01   Main.Oregon_THGR238N|Difference to dew point in Ground 'Aktuellt: 9.6  Genomsnitt: 9.6'
18:08:01   Main.DewPointDone
18:08:01   Main.Oregon_THGR238N|Difference to dew point in Attic 'Aktuellt: 4.8  Genomsnitt: 4.8'
18:08:02   Current Q size:  3
18:08:04   Current Q size:  2
18:08:07   Current Q size:  1
18:08:09   RFXtrx.Type: THGN122/123, THGN132, THGR122/228/238/268 id: 56068 ' temperature: -7.2 deg C humidity: 33 %RH status: dry signal: 7 battery: 9'
18:08:28   RFXtrx.Type: THGN122/123, THGN132, THGR122/228/238/268 id: 1796 ' temperature: +5.2 deg C humidity: 47 %RH status: normal signal: 7 battery: 9'
18:08:37   RFXtrx.Type: THGN122/123, THGN132, THGR122/228/238/268 id: 8194 ' temperature: -5.8 deg C humidity: 71 %RH status: wet signal: 7 battery: 9'
18:08:52   RFXtrx.Type: THGN122/123, THGN132, THGR122/228/238/268 id: 56068 ' temperature: -7.2 deg C humidity: 33 %RH status: dry signal: 7 battery: 9'
18:08:53   MQTT./zwave u"Device_6_Instance_3_temperature, 21.1200016"
18:08:54   MQTT./zwave u"Device_6_Instance_4_temperature, 22.43"
18:08:54   MQTT./1wire u"{'sensorId': '20.09F40C000000/volt.B', 'lightlevel': '0.0487507', 'temperature': '-6.625', 'timestamp': '1451927342.65'}"
18:08:54   Main.LightLevelDone

[Mastiff]

I'm not sure if it works. It seems like at the most it goes up to 15, then down to 14 and then up again, and it has stopped logging and probably executing, the last log is at 15.35. You can see yourself here. The last entry in the HTML reports is 16:44.

[krambriw]

Well, I think one thing, your system is getting overloaded

The number of waiting threads is reaching more than 15 (which is the defined numbers you can have running at the same time) and then it just starts to pile up more and more

Here it is first reaching 15 concurrent threads running at the same time

Code: Select all

2016-01-04 11:37:59  EVENT: RFXtrx.Type: Viking 02811 id: 57088 ' temperature: +18.6 deg C signal: 4 battery: 9'
2016-01-04 11:37:59           INFO: Hjørnesoverom.: Temperatur: 18.6, termostattemperatur: 20, tidspunkt: Kl. 11:37, den 04.01.
2016-01-04 11:37:59           INFO: 
2016-01-04 11:37:59  EVENT: OpenNetHome.'Lost contact with sensor: FineOffset|1247'
2016-01-04 11:37:59  EVENT: Tellstick.FineOffset|1247 'Temp|18.6'
2016-01-04 11:37:59  INFO: Current Q size:  15

Then a bit later, the system has managed to handle the waiting threads and we are for a moment down to 14 running, but then again, we get saturated

Code: Select all

2016-01-04 12:05:49  EVENT: RFXtrx.Type: Viking 02811 id: 6144 ' temperature: +4.1 deg C signal: 5 battery: 9'
2016-01-04 12:05:53           INFO: Current Q size:  14
2016-01-04 12:05:53  EVENT: Tellstick.FineOffset|1048 'Temp|4.1'
2016-01-04 12:05:54  EVENT: RFXtrx.Type: Viking 02811 id: 58624 ' temperature: +19.9 deg C signal: 5 battery: 9'
2016-01-04 12:05:54           INFO: Stue.: Temperatur: 19.9, termostattemperatur: 36, tidspunkt: Kl. 12:05, den 04.01.
2016-01-04 12:05:54           INFO: 
2016-01-04 12:05:54           INFO: Current Q size:  15

The system is from this point very busy it seems and then finally, a last attempt to execute waiting threads

Code: Select all

2016-01-04 15:34:41  EVENT: RFXtrx.Type: Viking 02811 id: 58624 ' temperature: +20.0 deg C signal: 5 battery: 9'
2016-01-04 15:34:41           INFO: Stue.: Temperatur: 20.0, termostattemperatur: 36, tidspunkt: Kl. 15:34, den 04.01.
2016-01-04 15:34:41           INFO: 
2016-01-04 15:35:16           INFO: Current Q size:  14
2016-01-04 15:35:16  EVENT: RFXtrx.Type: Viking 02811 id: 26368 ' temperature: +11.4 deg C signal: 5 battery: 9'
2016-01-04 15:35:16           INFO: Biljardrom.: Temperatur: 11.4, termostattemperatur: 5, tidspunkt: Kl. 15:35, den 04.01.
2016-01-04 15:35:16           INFO: 
2016-01-04 15:35:16  EVENT: RFXtrx.Type: Viking 02811 id: 60672 ' temperature: +23.3 deg C signal: 5 battery: 9'
2016-01-04 15:35:16           INFO: WC.: Temperatur: 23.3, termostattemperatur: 22, tidspunkt: Kl. 15:35, den 04.01.
2016-01-04 15:35:16           INFO: 
2016-01-04 15:35:17           INFO: Current Q size:  15

I could not find any crash but if logging stopped, Eventhost has runned out of resources (I believe due to that more and more threads are being put on the waiting list).

Some further things to try:

- increase the queue size from 15 to 25 an see if it also gets fully consumed

Otherwise, I cannot see any other solution that you have to reduce how frequently you are saving data to the database

You also have a lot of "OpenNetHome.'Lost contact with sensor:" but I guess this has no impact on this problem

Thanks for testing,
Walter

[Mastiff]

Increased it now, so we'll see tomorrow morning what happens. And it's only the CDC stuff that stops logging, the rest logs and functions as it should. At statup it goes queue up and down, with 6-7-8. But the sensors come in quite fast (and furious...ha-ha), so it never goes below 5 as far as I can see.

Btw if it matters I'm running this in a VMWare VM that runs on an SSD, with 4 gig ram (I think all of it is in physical memory, not virtual memory on the host, which has 32 gig and 20 gigs reserved for VMWare) and four processor cores.

Edit: But I see now on the generated reports that it has still saved the values, it just hasn't generated reports or logged.

Edit again: Now it went down to 1 q size, so I guess it varies. Maybe the problem comes when reports are generated, once every hour?

[krambriw]

Maybe the problem comes when reports are generated, once every hour?

How many reports? Also report generating is using threads to not block EG itself. Eventually, distribute the generating a bit with some minutes spread around the hour.

[Mastiff]

I have five reports every hour, consecutive in one macro. I could of course split them in separate macros and make them trigger each other after 1 minute. But I now woke up to a running system, with 1, 2 and 3 as the current q size! So I'm guessing that changing the max threads may have fixed it! I see that around 40 minutes ago the size was 19, so I'm guessing that was when the reports were made. I didn't have macros logged, only info. I'll run it with macros logged as well and see if that's what's going on.

[Mastiff]

Yep, it's the reports. It spikes then, and takes around 10 minutes to get down to 4-5 again. Do you think it would be wise to split the reports a bit?

[krambriw]

Allowing more consecutive running threads is the best since it means the system is able to process them instead of putting execution on hold. You can try to increase the limit even higher if needed and see how this works.
Also splitting the report creation could be the next change, but first, increase the limit if you see that it peaks at 25 (or the limit you have defined)

[Mastiff]

OK, thanks! I see that it has been up to 25 at least once, so I'm bumping it to 35. At the moment it's down to 1 and 2 again. Which sounds pretty good!

[krambriw]

1 and 2

is VERY good! Also your hw seems very powerful enough

[Mastiff]

Great! And yeah, when I bought it two years ago, and I went totally overboard. I have never paid as much for any computer equipment in my life as the identical Xenon home and cabin servers! I never told my wife the price of the stuff. Luckily I work from home and the cabin, so I could at least get some back as tax back money!

[krambriw]

Still working OK?

[Mastiff]

You shouldn't have asked, you jinxed it...

Code: Select all

11:32:34   Current Q size:  34
11:32:36   RFXtrx.Type: Viking 02811 id: 43776 ' temperature: +14.8 deg C signal: 5 battery: 9'
11:32:36            Midtsoverom.: Temperatur: 14.8, termostattemperatur: Av, tidspunkt: Kl. 11:32, den 07.01.
11:32:36            
11:32:36   Tellstick.FineOffset|1195 'Temp|14.8'
11:32:36   Current Q size:  35
11:32:36   OpenNetHome.'Lost contact with sensor: FineOffset|1195'
11:32:39   RFXtrx.Type: Viking 02811 id: 13312 ' temperature: +13.8 deg C signal: 5 battery: 9'
11:32:39            Hovedsoverom.: Temperatur: 13.8, termostattemperatur: 14, tidspunkt: Kl. 11:32, den 07.01.
11:32:39            
11:32:43   RFXtrx.Type: Viking 02811 id: 32768 ' temperature: +9.2 deg C signal: 4 battery: 9'
11:32:43            Gjesterom.: Temperatur: 9.2, termostattemperatur: 5, tidspunkt: Kl. 11:32, den 07.01.
11:32:43            
11:32:48   OpenNetHome.'Lost contact with sensor: FineOffset|1152'
11:32:48   Tellstick.FineOffset|1152 'Temp|9.2'
11:32:48   RFXtrx.Type: Viking 02811 id: 28416 ' temperature: +7.6 deg C signal: 4 battery: 9'
11:32:48            Kjellerkontor.: Temperatur: 7.6, termostattemperatur: 5, tidspunkt: Kl. 11:32, den 07.01.
11:32:48            

It had been 25-30 for a while, and then tipping 30 for a while. I have no idea why that just happened!

[Mastiff]

Oh, btw, when that happens EG takes a lot of CPU (around 40 % and I have to kill the process, it doesn't die when I exit EG normally. I raised the limit to 45 now, let's see what happens. But I guess I may have to go down on the frequency of logging in the end.