Jishar13 / pvbeancounter

Automatically exported from code.google.com/p/pvbeancounter
1 stars 0 forks source link

PVService writes hundreds of megabytes of log file in seconds #16

Closed GoogleCodeExporter closed 8 years ago

GoogleCodeExporter commented 8 years ago
What steps will reproduce the problem?
1. Manually sleep pc (doesn't always create the problem)

What is the expected output? What do you see instead?
Millions, yes millions of lines of text written to the log file. Some written 
in the second that the pc sleeps, then when the pc wakes up it continues 
logging the same error till terminated.
1 log file is over 600MB, the next time it happened it got to 800MB till I saw 
it.

I'm not using the service to sleep or resume the pc

What version of the product are you using? On what operating system?
1.3.5.3

Please provide any additional information below.
17/03/2011 11:00:51 :1 :PVService: PVService loaded - version:1.3.5.3
17/03/2011 11:00:51 :4 :PVService: Start requested
17/03/2011 11:01:01 :6 :ExecutionStateManager: Started - Start: 06:00:00 - 
Stop: 23:00:00 - Evening Suspend Type: idle
17/03/2011 11:01:01 :6 :ExecutionStateManager: Started - Wake:  - Suspend:  - 
Interval Suspend Type: idle
17/03/2011 11:01:09 :6 :InverterManagerManager: StartService: connecting to 
database: Provider=Microsoft.Jet.OLEDB.4.0;Data 
Source=E:\Data\SMA\PVRecords\PVRecords_jet.mdb
17/03/2011 11:01:11 :6 :InverterManagerManager: Loading Inverter Managers
17/03/2011 11:01:11 :6 :InverterManagerManager: NextFullDay set to no older 
than 16/03/2011 00:00:00 for all enabled inverter managers
17/03/2011 11:01:11 :6 :SunnyExplorerManager: Inverter Manager - Id = 1 loaded
17/03/2011 11:01:11 :6 :InverterManagerManager: Inverter Managers Loaded
17/03/2011 11:01:11 :8 :SunnyExplorerManager: RunExtract - Inverter Manager - 
Id = 1 - manager running
17/03/2011 11:01:13 :9 :InverterManagerManager: pvoutput.org update started
17/03/2011 11:01:13 :6 :ExecutionStateManager: State: Running Until:17/03/2011 
23:00:00
17/03/2011 11:02:25 :9 :InverterManagerManager: pvoutput.org - Auto Backload 
completed
17/03/2011 11:02:28 :9 :PVOutputUtilities: pvoutput.org batch updated
17/03/2011 11:04:28 :9 :InverterManagerManager: pvoutput.org - Auto Backload 
completed
17/03/2011 11:06:29 :9 :InverterManagerManager: pvoutput.org - Auto Backload 
completed
17/03/2011 11:08:29 :9 :InverterManagerManager: pvoutput.org - Auto Backload 
completed
17/03/2011 11:08:31 :9 :PVOutputUtilities: pvoutput.org batch updated
17/03/2011 11:14:33 :9 :PVOutputUtilities: pvoutput.org batch updated
17/03/2011 11:19:04 :9 :PVOutputUtilities: pvoutput.org batch updated
17/03/2011 11:25:06 :9 :PVOutputUtilities: pvoutput.org batch updated
17/03/2011 11:29:11 :9 :PVOutputUtilities: pvoutput.org batch updated
17/03/2011 11:35:13 :9 :PVOutputUtilities: pvoutput.org batch updated
17/03/2011 11:39:16 :9 :PVOutputUtilities: pvoutput.org batch updated
17/03/2011 11:39:54 :23 :PVService: Received power event: QuerySuspend
17/03/2011 11:39:54 :24 :PVService: Received power event: Suspend
17/03/2011 11:39:54 :6 :ExecutionStateManager: External suspend
17/03/2011 11:39:55 :6 :InverterManagerManager: Stopping Inverter Managers
17/03/2011 11:39:55 :6 :InverterManagerManager: Inverter Managers Interrupted
17/03/2011 11:39:55 :8 :SunnyExplorerManager: RunExtract - Inverter Manager - 
Id = 1 - interrupted
17/03/2011 11:39:56 :9 :InverterManagerManager: pvoutput.org update stopped
17/03/2011 11:39:58 :6 :ExecutionStateManager: State: Suspended 
Until:18/03/2011 06:00:00
17/03/2011 11:44:09 :6 :InverterManagerManager: Loading Inverter Managers
17/03/2011 11:44:09 :6 :InverterManagerManager: NextFullDay set to no older 
than 16/03/2011 00:00:00 for all enabled inverter managers
17/03/2011 11:44:09 :6 :SunnyExplorerManager: Inverter Manager - Id = 1 loaded
17/03/2011 11:44:09 :26 :SunnyExplorerManager: RunExtract - Inverter Manager - 
Id = 1 - manager running
17/03/2011 11:44:09 :6 :InverterManagerManager: Inverter Managers Loaded
17/03/2011 11:44:11 :28 :InverterManagerManager: pvoutput.org update started
17/03/2011 11:44:11 :6 :ExecutionStateManager: State: Running Until:17/03/2011 
23:00:00
17/03/2011 11:44:12 :25 :PVService: Received power event: ResumeSuspend
17/03/2011 11:44:13 :29 :PVService: Received power event: ResumeAutomatic
17/03/2011 11:45:27 :28 :PVOutputUtilities: pvoutput.org batch updated
17/03/2011 11:47:29 :28 :PVOutputUtilities: pvoutput.org batch updated
17/03/2011 11:51:31 :28 :PVOutputUtilities: pvoutput.org batch updated
17/03/2011 11:56:58 :13 :PVService: Received power event: QuerySuspend
17/03/2011 11:56:58 :6 :ExecutionStateManager: External suspend
17/03/2011 11:56:58 :6 :InverterManagerManager: Stopping Inverter Managers
17/03/2011 11:56:58 :6 :InverterManagerManager: Inverter Managers Interrupted
17/03/2011 11:56:58 :26 :SunnyExplorerManager: RunExtract - Inverter Manager - 
Id = 1 - interrupted
17/03/2011 11:56:58 :22 :PVService: Received power event: Suspend
17/03/2011 11:56:58 :6 :ExecutionStateManager: External suspend
17/03/2011 11:56:58 :6 :InverterManagerManager: Stopping Inverter Managers
17/03/2011 11:56:58 :6 :ExecutionStateManager: exception: Object reference not 
set to an instance of an object.System.NullReferenceException
17/03/2011 11:56:58 :6 :ExecutionStateManager: External suspend
17/03/2011 11:56:58 :6 :InverterManagerManager: Stopping Inverter Managers
17/03/2011 11:56:58 :6 :ExecutionStateManager: exception: Object reference not 
set to an instance of an object.System.NullReferenceException
17/03/2011 11:56:58 :6 :ExecutionStateManager: External suspend
17/03/2011 11:56:58 :6 :InverterManagerManager: Stopping Inverter Managers
17/03/2011 11:56:58 :6 :ExecutionStateManager: exception: Object reference not 
set to an instance of an object.System.NullReferenceException

last 3 lines repeated for > 200,000 lines
pc wakes up (manual wake up at 13:20), the same is logged for millions of lines 
till I stop the service.

17/03/2011 11:57:11 :6 :ExecutionStateManager: External suspend
17/03/2011 11:57:11 :6 :InverterManagerManager: Stopping Inverter Managers
17/03/2011 11:57:11 :6 :ExecutionStateManager: exception: Object reference not 
set to an instance of an object.System.NullReferenceException
17/03/2011 11:57:11 :6 :ExecutionStateManager: External suspend
17/03/2011 13:20:24 :6 :InverterManagerManager: Stopping Inverter Managers
17/03/2011 13:20:24 :6 :ExecutionStateManager: exception: Object reference not 
set to an instance of an object.System.NullReferenceException
17/03/2011 13:20:24 :6 :ExecutionStateManager: External suspend
17/03/2011 13:20:24 :6 :InverterManagerManager: Stopping Inverter Managers
17/03/2011 13:20:24 :6 :ExecutionStateManager: exception: Object reference not 
set to an instance of an object.System.NullReferenceException
17/03/2011 13:20:24 :6 :ExecutionStateManager: External suspend
17/03/2011 13:20:24 :6 :InverterManagerManager: Stopping Inverter Managers
17/03/2011 13:20:24 :6 :ExecutionStateManager: exception: Object reference not 
set to an instance of an object.System.NullReferenceException

Original issue reported on code.google.com by googleco...@finnimore.org.uk on 17 Mar 2011 at 7:39

GoogleCodeExporter commented 8 years ago
Investigating - Has this occurred again - ie after you encountered Issue 17?

Usage with MS Access and PVBC is a little unstable, primarily due to limited 
number of users. If you persevere you can help me rectify the MS Access issues. 
Access seems to be very sensitive to the manner of database connection 
destruction. Most Access specific issues have traced back to connection 
handling.

This issue may be a race condition at computer suspend. I try to address in the 
next release.

Original comment by DennisMackayFisher on 18 Mar 2011 at 9:41

GoogleCodeExporter commented 8 years ago
Yes it happened today again, I wondered why pvoutput hadn't been updated and 
found a 1.6GB log file and growing rapidly.
I've changed (locally) 
PVInverterManagement.ExecutionStateManager::ManageExecutionState to throw any 
errors so at least the service now stops as soon as it happens instead of 
chewing my disk up. My new code has been triggered twice since.

I chose MSAccess simply so at the beginning (2 days ago) I could see what it 
was doing by opening the file. Which db do you think works the best with your 
application?

Original comment by googleco...@finnimore.org.uk on 18 Mar 2011 at 10:11

GoogleCodeExporter commented 8 years ago
Probably rectified in version 1.3.6.0 - Please notify if 1.3.6.0 does this

Original comment by DennisMackayFisher on 19 Mar 2011 at 6:34

GoogleCodeExporter commented 8 years ago

Original comment by DennisMackayFisher on 19 Mar 2011 at 6:36

GoogleCodeExporter commented 8 years ago
[deleted comment]
GoogleCodeExporter commented 8 years ago
I've got it set up on my Acer Revo Nettop now running SqlLite (as I didn't want 
to set up a standalone database and have to administer that). I've set it fully 
automated with 6 minute wakes, 10 minute sleeps - it's been working all day 
fantastically, I love your program (and pvoutput)

Original comment by googleco...@finnimore.org.uk on 19 Mar 2011 at 12:36

GoogleCodeExporter commented 8 years ago
Resubmitted due to incorrect statement:

MySQL seems to be better than the others but it takes some setting up. MySQL 
requires little thread syncronisation - more concurrent processing. The others 
have problems with concurrent DB acticity (from multiple threads). It also 
seems to run with lower overall system load.

MS Access suffered from problems associated with .Net command disposal that did 
not affect the others. This caused the most recent Access based issues.

Original comment by DennisMackayFisher on 19 Mar 2011 at 9:58

GoogleCodeExporter commented 8 years ago

Original comment by DennisMackayFisher on 21 Mar 2011 at 10:20