MantisBT

View Issue Details Jump to Notes ] Related Changesets ] Issue History ] Print ]
IDProjectCategoryView StatusDate SubmittedLast Update
0000231WebSolarLogDevicespublic2014-03-19 23:392014-03-27 08:43
ReporterPaolo 
Assigned Tomfrijmann 
PrioritynormalSeveritymajorReproducibilityalways
StatusresolvedResolutionfixed 
PlatformRaspberry PI - AuroraOSRaspbianOS Version
Product VersionRelease 1.0.0 
Target VersionRelease 1.1.0Fixed in VersionRelease 1.1.0 
Summary0000231: Solar devices fast polling always on
DescriptionNormally solar devices should slow down or stop polling during night until few min before sunrise.

I know this is an intended behavior that should be only implemented.

See https://groups.google.com/d/msg/websolarlog/8-o3uCDKHRA/Q1mwbEiRTxMJ [^]
TagsNo tags attached.
Attached Files

- Relationships

-  Notes
(0000380)
mfrijmann (administrator)
2014-03-20 20:25

It looks like i have successful test a solution for preventing nighttime polling to inverters. Tomorrow morning i will check if my WSL start on time with polling the inverter i will add the code to the online codebase.
(0000381)
mfrijmann (administrator)
2014-03-21 08:34

Last night I checked around 20:00 if my WSL was polling my inverter and i saw no data request. Sunset time was about 18:50

This morning the sunrise time of my location is: 6:41
About 6:30 my WSL was already polling my inverter.

Based on this test it looks like the fix is working.
(0000386)
sparky (reporter)
2014-03-22 05:55

Can this be disabled for debug? I find it extremely useful when I was initially setting up the system and even now when I upgrade to see the periodic pings to the inverter (that never answers of course).
(0000394)
mdiphoorn (administrator)
2014-03-22 07:23

I am almost always running in debug mode. So im against this. Also i think that an communication test can be used for this.
(0000395)
mfrijmann (administrator)
2014-03-22 15:41

I added a new "testMode" option to all devices.
When you run a test, the device is put in testMode and the test will run even when the sun is down.
(0000399)
Paolo (reporter)
2014-03-24 22:05

/*
 * prevent polling on sunset
 * This stops polling 30 min. after sunset and start polling again 30 min before sunrise
 */

// Retrieve the device data
$live = (Util::isSunDown(-1800)==false || $device->testMode==true) ? $api->getLiveData() : null;


This stops device polling (serial, IP, wathever) but keeps Device Handler queueitem fast requeueing. Is it possible to slow down queue handling for device too?

I see a lot of db updates (average every 1,5s) during sunset/night time too, probably due to queueserving logic db based and Device handler fast retrigger.
(0000401)
mfrijmann (administrator)
2014-03-25 07:55

Its should be possible to slow down the request on sunset. But as in all cases we need to code more lines and check to do this.
The queue is a "in memory" piece of WSL and should not effect the database and only CPU cycles. So i do not believe that the requeueing of this queue item is the cause of the 1,5 sec updates.

How did you measured the 1,5 sec updates average on the database?
(0000402)
Paolo (reporter)
2014-03-25 09:58
edited on: 2014-03-25 10:28

For my measures I used iotop, inotifywatch, time, sqlite3 and ls -l showing the wsl.sdb last modification date.

See also my latest post in wsl group with some more ideas, I think that Queue is not really "in memory" as intended: https://groups.google.com/d/msg/websolarlog/8-o3uCDKHRA/Z7sLDgFTCtEJ [^]

Here are my measures and corresponging log (30 min sample, evening):

root@raspberrypi:/usr/share/nginx/www/websolarlog/database# date && time inotifywatch -t 1800 -r *

Sun Mar 23 22:58:08 CET 2014

Establishing watches...
Finished establishing watches, now collecting statistics.
total access modify attrib close_write delete_self filename
5255 4090 1165 0 0 0 wsl.sdb
4 0 0 1 1 1 wsl.sdb-journal

real 30m0.015s
user 0m0.180s
sys 0m0.460s

As you see: 1800 seconds / 1165 writes (modify) = 1,55 second average every write

BTW, during same time we have 4090 access request (read) on the same db. Quite a lot.

Corresponding wsl.log (during sampling), nothing strange there:

20140323 225846 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 225846 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 225846 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 230001 info onInfo - Janitor starts cleaning.
20140323 230003 debug onDebug - QueueServer: current memory usage = 2.24mb queue size: 20
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleInfo time=1395658800 requeueTime=86400 requeue=1 dbsync= arguments=[{id:1,name:Aurora1}]
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleDeviceHistory time=1395660600 requeueTime=86400 requeue=1 dbsync= arguments=[{id:1,name:Aurora1}]
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleInfo time=1395658800 requeueTime=86400 requeue=1 dbsync= arguments=[{id:3,name:GrisuCave}]
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleDeviceHistory time=1395660600 requeueTime=86400 requeue=1 dbsync= arguments=[{id:3,name:GrisuCave}]
20140323 230003 debug onDebug - QueueServer item: PvOutputAddon.joinAllDevicesToTeam time=1395616500 requeueTime=21600 requeue=1 dbsync= arguments=
20140323 230003 debug onDebug - QueueServer item: JanitorRest.DbCheck time=1395619200 requeueTime=86400 requeue=1 dbsync= arguments=
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleAlarm time=1395612000 requeueTime=900 requeue=1 dbsync= arguments=[{id:1,name:Aurora1}]
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleAlarm time=1395612000 requeueTime=900 requeue=1 dbsync= arguments=[{id:3,name:GrisuCave}]
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleEnergy time=1395612000 requeueTime=600 requeue=1 dbsync= arguments=[{id:1,name:Aurora1}]
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleHistory time=1395612000 requeueTime=600 requeue=1 dbsync= arguments=[{id:3,name:GrisuCave}]
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleEnergy time=1395612000 requeueTime=600 requeue=1 dbsync= arguments=[{id:3,name:GrisuCave}]
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleLive time=1395612200 requeueTime=600 requeue=1 dbsync= arguments=[{id:3,name:GrisuCave}]
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleHistory time=1395612000 requeueTime=300 requeue=1 dbsync= arguments=[{id:1,name:Aurora1}]
20140323 230003 debug onDebug - QueueServer item: Common.checkRestart time=1395612000 requeueTime=300 requeue=1 dbsync= arguments=
20140323 230003 debug onDebug - QueueServer item: Common.refreshConfig time=1395612000 requeueTime=120 requeue=1 dbsync= arguments=
20140323 230003 debug onDebug - QueueServer item: PvOutputAddon.onJob time=1395612000 requeueTime=75 requeue=1 dbsync= arguments=
20140323 230003 debug onDebug - QueueServer item: HookHandler.fireFromQueue time=1395612000 requeueTime=60 requeue=1 dbsync= arguments=[]
20140323 230003 debug onDebug - QueueServer item: DeviceHandler.handleLive time=1395612000 requeueTime=5 requeue=1 dbsync= arguments=[{id:1,name:Aurora1}]
20140323 230003 debug onDebug - QueueServer item: HookHandler.fireFromQueue time=1395615600 requeueTime=3600 requeue=1 dbsync= arguments=[]
20140323 230003 debug onDebug - QueueServer item: JanitorRest.clean time=1395615600 requeueTime=3600 requeue=1 dbsync= arguments=
20140323 230013 debug onDebug - WeatherOWM::getData::Lets start with gathering weather data from OWM
20140323 230014 debug onDebug - WeatherOWM::getData::Looks like we didn't receive useful weather data::stdClass Object ( [message] => accurate [cod] => 200 [count] => 0 [list] => Array ( ) )
20140323 230023 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 230023 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 230023 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 230115 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 230115 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 230115 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 230245 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 230245 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 230245 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 230346 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 230346 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 230346 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 230503 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 230503 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 230503 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 230646 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 230646 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 230646 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 230744 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 230744 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 230744 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 230847 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 230847 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 230847 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 231004 debug onDebug - WeatherOWM::getData::Lets start with gathering weather data from OWM
20140323 231005 debug onDebug - OTHER error (8) in /usr/share/nginx/www/websolarlog/classes/devices/WeatherOWM.php [47] :: Trying to get property of non-object
20140323 231005 debug onDebug - WeatherOWM::getData::Looks like we didn't receive useful weather data::
20140323 231013 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 231013 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 231013 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 231144 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 231144 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 231144 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 231247 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 231247 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 231247 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 231346 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 231346 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 231346 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 231507 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 231507 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 231507 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 231647 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 231647 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 231647 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 231745 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 231745 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 231745 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 231848 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 231848 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 231848 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 232004 debug onDebug - WeatherOWM::getData::Lets start with gathering weather data from OWM
20140323 232018 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 232018 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 232018 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 232115 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 232115 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 232115 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 232246 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 232246 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 232246 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 232345 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 232345 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 232345 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 232504 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 232504 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 232504 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 232646 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 232646 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 232646 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 232746 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 232746 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 232746 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave
20140323 232846 debug onDebug - PvOutputAddon::onJob::Let do some PVoutput 'magic'...
20140323 232846 debug onDebug - PvOutputAddon::onJob::starting with deviceAurora1
20140323 232846 debug onDebug - PvOutputAddon::onJob::starting with deviceGrisuCave

(0000403)
mfrijmann (administrator)
2014-03-25 10:30

Ok, your calc look OK.

but (yeah there is a but again....);
I think this is not the (fair) way to see if WSL is doing (to) much database read/writes.

On top of the database is a database engine(SQLite3) thats continuously manage the database. For example;
There are lots of indexes on the various tables and the engine need to keep them up2date also the engine manage in-file (delayed) read/write operations/caches. And lots of other thing.

Also its not so that 1 write operation of WSL will result in 1 write operation on the database. As mentioned earlier WSL uses table-indexes. So when WSL writes to a table that has for example 4 indexes, it could result in minimal 5 write operations;
1. savings the new records
2-5. updating the 4 indexes.

In the worst case scenario it could happen that one modification on a table will result in;
1. saving the new record
2. modifying an index
3. SQLite could not mod the index in one operation and need to create a temp. table/index.
4. creates a new temp. index/table.
5. write all index record
6. etc. etc. etc.

This could also happening when WSL (or you) updates a existing record.

WSL also uses transactions to bundle big read/write processes and prevent lots of loos open/close operations on the database.

The transactions have there benefits but also there downside on low-powered devices. One of the downsides is thats low-powered devices needs more time to handle big transactions and this could cause "big" lock times on the database file. But we thought its better to handle one big transaction of 5 queries, then run 5 queries seperated that causes 5 open/close operations on the database and 5 changes on tables/indexes.


I agree with you that 1 mod every 1,5 sec is allot, but i think its not really "fair" to measure it this way and blaming it WSL.

Perhaps you have a MySQL database in use and you could measure that to.
(0000404)
mfrijmann (administrator)
2014-03-25 10:38

I did you test on my local machine.
In this case wsl.sh and(!) the queueserver was not running and i had WSL's index.php opened in chrome. While opened a browsed through some days with the main graph and the WSL-frontend was querying the database for live data to display on the gauges.
=============================
marco@Marcos:~/www/websolarlog/database$ date && time inotifywatch -t 100 -r *
di mrt 25 10:33:18 CET 2014
Establishing watches...
Finished establishing watches, now collecting statistics.
total access close_write open filename
1661 1544 58 59 wsl.sdb

real 1m40.022s
user 0m0.000s
sys 0m0.025s
===========================

So in my case i monitored for about 100 secs and had 1661 file actions.
And thats only from the frontend requesting data from the database.
(0000405)
mfrijmann (administrator)
2014-03-25 11:29
edited on: 2014-03-25 13:54

Here i closed the WSL tab and the database didn't change.
=========================================================
di mrt 25 10:53:58 CET 2014
Establishing watches...
Finished establishing watches, now collecting statistics.
No events occurred.

real 1m40.038s
user 0m0.000s
sys 0m0.002s


====================================================
next test
====================================================

Now i going to test what happens when i add an records to the weather table. In my case the Weather table has 3 indexes so i think this is interesting.

Why the weather table?

Because the weather addon keeps running in sunset.

====================================================
di mrt 25 11:07:54 CET 2014
Establishing watches...
Finished establishing watches, now collecting statistics.
total access modify attrib close_write delete_self filename
18 10 4 1 1 1 wsl.sdb-wal
15 8 6 0 1 0 wsl.sdb
4 0 0 1 1 1 wsl.sdb-shm

I added the record through the console, so there is no overhead caused by (webbased) gui's.

The WAL file is a Write-Ahead-Log and is used by transactions.
The SHM file is some kind of shared-memory file.

Let take a look on the .sdb file;
total access modify attrib close_write delete_self filename
15 8 6 0 1 0 wsl.sdb

So add one record to Weather gives 6 file-based mod operations and in total 15 operations.
I think/hope this show that WSL is not directly causing the tons of file mods and that most of it is done DB-engine and we can't change that.

(0000406)
Paolo (reporter)
2014-03-25 15:05

You are right, QueueItem table is not the one that causes of the writes.

More investigation told me that most of the writes to the DB are in cache table, coming from CacheAddon::averagePower. At least now with solar production on.

Is it possible to move this "cache" table in RAM?

This is a "raw" log I got after some modification to R.php. See the SQL updates about 1 per second.

20140325 145403 fire :: object=CacheAddon, methodname=averagePower
20140325 145403 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145404 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145405 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145406 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145407 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145408 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145409 fire :: object=CacheAddon, methodname=EnergyValues
20140325 145409 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145410 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145411 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145412 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145413 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145414 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145415 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145417 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145418 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145419 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145420 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145421 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145423 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145424 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145425 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145426 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145427 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145428 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145429 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145430 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145431 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145432 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145432 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145433 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145434 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145435 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145436 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145437 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145438 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145439 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145440 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145441 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145442 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
20140325 145443 R::updaterecord SQL String=UPDATE `cache` SET `key` = ? , `value` = ? , `module` = ? , `page` = ? , `timestamp` = ? WHERE id = ?
(0000409)
mfrijmann (administrator)
2014-03-25 15:17

Ok, now we have something :)

I will take a look and see if and how we could fix this.

Table in memory is not a option. Its still our goal to let WSL run on MySQL and (as far as i known) MySQL (and atleast RedBeanPHP) doesn't support memory tables.
(0000411)
mfrijmann (administrator)
2014-03-25 18:43
edited on: 2014-03-25 18:44

I looked at the Cache addon.
The thing with the addon is, the data that its generates is very CPU intensive.

For example;
The Overall value is based on ALL records in the energy table.
My installation is running almost 2 year and had therefore more then 600 records.
These records needs to be summed(total) and divided(kwh/kwp) per record and total.
In the past we these figures were calculated on the fly by the frontend. In the beginning this was a good thing, but the more records were add, longer the function needed to calculate everything and hang the frontend.
The second problem was that when an open WSL has 10 www visitors, this function is called 10 times.....

So we decided that we should move these calculation from the frontend to the backend. But this brought another problem; when do we (re)calculate these figures? First we did this every 15 min. but in the solar season big installation has big gaps in the figures.

So to prevent these big gaps, we decided that 1 minute is a good mix between frontend loading, 15 min. or 1 min. "delayed".

We could change the 1 min. job to 2 or 5 minutes, but there will always be one person that could not live with 1,2,5,10,30 minutes.

I hear you think;
Stop the cacheaddon on sunset. Ok, thats possible and will result in not updating the "some figures" when somebody modified values in Admin::Yields.

I don't know what is THE solution for this.

For now i will make it possible to let the user change the update rate for the cacheAddon. After that we need to see what we could do to make the addon even better/smarter.

(0000412)
Paolo (reporter)
2014-03-25 22:22

Understood.

Do you think that it's really impossible to make sqlite do these "cached" calculations with a (even complicated) query?

A query (or several of them) should be able to write all values with a single transaction, faster and with less read/writes than PHP code.

I would like to help you more. Let me try with one of these cached cacls (I usually work with SQL). Could you write down one of these formulas and where I will find input fields to read and output fields to write? :)
(0000413)
arno58 (reporter)
2014-03-25 23:52

Memory tables are not an option but could a database on a tmpfs be an alternative.
I use smaspot and send the extra logging to a tmpfs to limit writing to sd memory.
Implementing two databases is not easy and losing data when there is a loss of power.
You could use a database on tmpfs and sync its working table(s) on a delayed timer to the table(s) on the permanent database.

I located 4GB to a tmpfs
tmpfs on /home/pi/smaspot/data/tempfs type tmpfs (rw,relatime,size=4096000k,mode=777)
(0000414)
mfrijmann (administrator)
2014-03-26 07:50
edited on: 2014-03-26 08:57

This discussion is going nowhere.
First its WSL thats using to much cycles in sunset. What is the definition of to much?
Then we need, during sunrise, save data to temp. dirs and sync it on sunset back to the main database.

This solution results in more cpu usage on sunset and the extra logic thats needed for such a sync also generates extra load on the system.

For example;
A few days ago i "fixed" the "late start" issue. The fix results in 1 extra query every time an history record is saved. Some people have a historyRate of <1 min. which results in at least 60 extra queries every hour on top of the 60 WSL needs to save the records.... So this "feature" comes from 60 queries and now does 120 an hour. Just to automatically fix a issue that in most cases is not the cause of WSL and could fix manually with Admin::Yields.
My WSL's historyRate is 180sec/3min. so every hour i have 20 records. On days with 12hours daylight this results in 12*20 = 240 extra queries on top of the 240 queries we need to save the data. So saving the history records "costs" 480 queries and i don't want to know how much IO/CPU cycles that needs and how much mods this generates on the database file to regenerate indexes.

It just an example on "how far" we could go to fix things automatically and generate more load on the host or let the user decide if the want to fix it and how the wants to fix it.


About the swap/tmpfs;
I think this is also no option because its need advanced linux knowledge of the end-user and a much bigger SD-card.


- Issue History
Date Modified Username Field Change
2014-03-19 23:39 Paolo New Issue
2014-03-20 16:30 mfrijmann Product Version => Release 1.0.0
2014-03-20 16:30 mfrijmann Target Version => Release 1.1.0
2014-03-20 16:30 mfrijmann Assigned To => mfrijmann
2014-03-20 16:30 mfrijmann Status new => confirmed
2014-03-20 20:25 mfrijmann Note Added: 0000380
2014-03-21 07:31 mfrijmann Status confirmed => assigned
2014-03-21 08:34 mfrijmann Note Added: 0000381
2014-03-21 09:30 Changeset attached => SourceForge trunk r1798
2014-03-21 21:30 Changeset attached => SourceForge trunk r1803
2014-03-22 05:55 sparky Note Added: 0000386
2014-03-22 07:23 mdiphoorn Note Added: 0000394
2014-03-22 12:30 Changeset attached => SourceForge trunk r1805
2014-03-22 13:00 Changeset attached => SourceForge trunk r1806
2014-03-22 15:30 Changeset attached => SourceForge trunk r1808
2014-03-22 15:41 mfrijmann Note Added: 0000395
2014-03-24 22:05 Paolo Note Added: 0000399
2014-03-25 07:55 mfrijmann Note Added: 0000401
2014-03-25 09:58 Paolo Note Added: 0000402
2014-03-25 10:28 Paolo Note Edited: 0000402 View Revisions
2014-03-25 10:30 mfrijmann Note Added: 0000403
2014-03-25 10:38 mfrijmann Note Added: 0000404
2014-03-25 11:29 mfrijmann Note Added: 0000405
2014-03-25 11:29 mfrijmann Note Edited: 0000405 View Revisions
2014-03-25 13:54 mfrijmann Note Edited: 0000405 View Revisions
2014-03-25 13:54 mfrijmann Note Edited: 0000405 View Revisions
2014-03-25 15:05 Paolo Note Added: 0000406
2014-03-25 15:17 mfrijmann Note Added: 0000409
2014-03-25 18:43 mfrijmann Note Added: 0000411
2014-03-25 18:44 mfrijmann Note Edited: 0000411 View Revisions
2014-03-25 22:22 Paolo Note Added: 0000412
2014-03-25 23:52 arno58 Note Added: 0000413
2014-03-26 07:50 mfrijmann Note Added: 0000414
2014-03-26 08:01 mfrijmann Note Edited: 0000414 View Revisions
2014-03-26 08:04 mfrijmann Note Edited: 0000414 View Revisions
2014-03-26 08:56 mfrijmann Note Edited: 0000414 View Revisions
2014-03-26 08:57 mfrijmann Note Edited: 0000414 View Revisions
2014-03-27 08:43 mfrijmann Status assigned => resolved
2014-03-27 08:43 mfrijmann Fixed in Version => Release 1.1.0
2014-03-27 08:43 mfrijmann Resolution open => fixed


Copyright © 2000 - 2019 MantisBT Team
Powered by Mantis Bugtracker