Excessive memory Use - Memory Leak?

[Wilko500]

Brief description.  The application interrogates my inverter and retrieves 22 data values.  These values are displayed in the GUI as tables, charts and gauges, logged to an output file for upload to web and stored in flat files for later display or export.  Timers control the data logging and chart display.  A main loop when started runs continuously polling the inverter. At end of each poll two procedures process retrieved information and data.  The information is about determining the state of the inverter, awake, asleep, waking up or going to sleep and the data is processed accordingly.

The application although still in early phase of development works as expected, data is retrieved, displayed and logged. 

The problem is that after a few days it crashes or rather the MacOs closes it down with an Out of Memory error.  I have tracked this using MacOs’s Activity Monitor, see attachment  ActivityMon.  The memory usage value marked at A is the key value.  The program crashes when this value exceeds approx 120GB’s.

The application uses LazSerial for comms (RS485), Industrial for the Gauges & LED’s and Charts for display.  I think that all three have been ruled out by extensive testing although there may still be some issues lurking therein. 

I have narrowed the cause down to a few of the 22 procedures that poll the inverter for data, one procedure for each inverter command, one in particular is used in the latest testing. It may not be the sole culprit but a solution here is likely to throw light on other problems.

A summary of test results, see TestResults, seems to indicate that the cause is my Decode routine.  This takes an 8 byte return value from the inverter and converts It into a single value.  Simple right, or so I thought.
First the code that polls inverter for GridWatt

Code: Pascal  [Select][+][-]

1. Procedure DoCmd59x3(Var iErr:Int32);
2. Var
3.   i:      Int32;     //Function return var
4.   k:      Int32;     //Loop counter
5.   RcvBuf: ar8;       //Receive buffer
6. Begin
7. Try
8.   For k:= 1 to 3 Do   //Try 3 times
9.       Begin
10.       frmMain.AdvLed1.Flash(LedFlashDur);
11. //    LazSerial1.SynSer.Purge;
12.       i:=LazSerial1.SynSer.SendBuffer(@RdGridPower,10);
13.       Sleep (RcvInvWait);  //Give time for inverter to respond;
14.       //frmMain.AdvLed2.Flash(LedFlashDur);    //For testing move this to Ok response
15.       i:=LazSerial1.SynSer.RecvBufferEx(@RcvBuf,8,RcvWait);
16.       If (LazSerial1.SynSer.LastError <> 0) Then
17.           //Timeout or other error
18.           Begin
19.           iErr:=i;
20.           End
21.       Else
22.           //Ok response
23.           Begin
24.           //Check if response is valid
25.           //All checks, checksum, global & Transmission state(s)
26.           If IsResponseValid(RcvBuf, 7) = 0 Then
27.               //Yes, response is good
28.               Begin
29.              If Not frmMain.chkDecode1.Checked Then gInv.OutputPower:=DecodeToSingle(RcvBuf) Else gInv.OutputPower:=195.5;
30.               iErr:=0;
31.               Break;
32.               End
33.           Else
34.               Begin
35.               //Try again. cause is logged in IsResponseValid
36.           End;{If}
37.           //Try again
38.       End;{If}
39.   End;{For}
40. Except
41.   On E: Exception Do
42.   Begin
43.   GlobalErrorHandler('Proc', 'DoCmd59x3', E);
44.   End;
45. End;{Try}
46. End;{Procedure DoCmd59x3}
47.  

and the DecodeToSingle function

Code: Pascal  [Select][+][-]

1. Function DecodeToSingle(Const b:ar8): Single;
2. Var
3.   x: Array[0..3] Of Byte;  //Holder for the 4 bytes to convert to single
4.   s: single absolute x;    //Makes var s share same memory location as var x
5. Begin
6. Try
7.   //Data received from Inverter in Big Endian format
8.   {$IFDEF ENDIAN_LITTLE}
9. //  {$ENDIF}
10.   x[3]:=b[2];
11.   x[2]:=b[3];
12.   x[1]:=b[4];
13.   x[0]:=b[5];
14.   {$ENDIF}
15.   {$IFDEF ENDIAN_BIG}
16.   x[0]:=b[2];
17.   x[1]:=b[3];
18.   x[2]:=b[4];
19.   x[3]:=b[5];
20.   {$ENDIF}
21.   Result:=s;
22. Except
23.    On E: Exception Do
24.   Begin
25.   ShowMessage('Exception in DecodeToSingle: ' + E.ClassName + ':' + E.Message);
26.   End;
27. End;{Try}
28. End;{Function DecodeToSingle}

Code: Pascal  [Select][+][-]

1. Type
2.   ar8 = Array [0..7] Of Byte;

The line was just a way to substitute a good value instead of using the decode function. temporary checkbox is on main form for testing

Code: Pascal  [Select][+][-]

1.  If Not frmMain.chkDecode1.Checked Then gInv.OutputPower:=DecodeToSingle(RcvBuf) Else gInv.OutputPower:=195.5;

A second issue that I do not understand is that when testing I can simulate the increasing memory usage but at the end of the loop, the repeats value in the test results, the memory uses reset to a "sensible" value after a few seconds.  In the real life running the application runs 24 x 7 so never get to the end of the loop thus eventually runs out of memory. 
For information each set of 22 inverter polls takes just over 2 seconds.
Your thoughts

[MathMan]

Hello Wilko500,

I do not see anything in the code itself that immediately springs to mind. However - how long is RcvInvWait? From your explanation you're calling it 22 times in 2 sec and the procedure does 3 trials with a Sleep.

Is there a reasonable chance, that DoCmd59x3 gets called again before the previous call terminated?

[Wilko500]

RcvInvWait is 100 mSecs and RcvWait is 70 mSecs.  The 2 sec timing was from the program before I made debug changes. It took just over 2 secs to cycle through the loop and call each procedure once.  DoCmd59x3 is called thus

Code: Pascal  [Select][+][-]

1. rocedure TfrmMain.Button1Click(Sender: TObject);
2. Var
3.   i:        Int32;
4.   iErr:     Int32;
5. begin
6.   OpenComPort(Res);
7.   If Res = True Then
8.       Begin
9.       For i:= 1 to strToInt(txtCount.Text) Do
10.       Begin
11.           If chkStatus.Checked Then DoCmd50(Ierr);           //Status
12.           If chkSerialNo.Checked Then DoCmd63(ierr);         //SerialNo
13.           If chkManWkY.Checked Then DoCmd65(ierr);           //Man WkY
14.           If chkSysDateTime.Checked Then DoCmd70(ierr);      //SysDateTime
15.           If chkVersion.Checked Then DoCmd58(Ierr);          //Version
16.           If chkPartNo.Checked Then DoCmd52(Ierr);           //PartNo
17.  
18.           If chkEnToday.Checked Then DoCmd78x0(iErr);        //EnToday
19.           If chkEnLife.Checked Then DoCmd78x5(Ierr);         //EnLife
20.           If chkGridVolt.Checked Then DoCmd59x1(Ierr);       //GridVolt
21.           If chkGridAmp.Checked Then DoCmd59x2(Ierr);        //GridAmp
22.           If chkGridWatt.Checked Then DoCmd59x3(Ierr);       //GridWatt  // <=======
23.  
24.           If chkInvTemp.Checked Then DoCmd59x21(Ierr);       //InvTemp
25.           If chkBoostTemp.Checked Then DoCmd59x22(Ierr);     //BoostTemp
26.           If chkGridFreq.Checked Then DoCmd59x4(Ierr);       //GridFreq
27.           If chkCurLeak.Checked Then DoCmd59x7(Ierr);        //CurLeak
28.           If chkIsoRes.Checked Then DoCmd59x30(Ierr);        //IsoRes
29.  
30.           If chkInpVolt1.Checked Then DoCmd59x23(Ierr);      //InpVolt1
31.           If chkInpAmp1.Checked Then DoCmd59x25(Ierr);       //InpAmp1
32.           If chkInpVolt2.Checked Then DoCmd59x26(Ierr);      //InpVolt2
33.           If chkInpAmp2.Checked Then DoCmd59x27(Ierr);       //InpAmp2
34.           If chkPowerPeak.Checked Then DoCmd59x34(Ierr);     //PowerPeak
35.           If chkPowerMaxDaily.Checked Then DoCmd59x35(Ierr); //PowerMaxDaily
36.  
37.           ProcessData;
38.           txtDone.Text:=IntToStr(i);
39.       End;{For}
40.       Sleep (300);
41.       End
42.   Else
43.       Begin
44.       Edit27.Text:='Port not available: ' + IntToStr(iErr);
45.   End;{If}
46. End;{Procedure Button1Click}

In testing only one of the 22 calls is being made, DoCmd59x3, all others are disabled to simplify.  It should not be possible for DoCmd59x3 to be called before previous call completes because it's called from a loop.  Eventually I want to call it from a timer and then it would be possible for it to be called too soon and that would need to be checked.

[Josh]

hi

its worth putting a check in code that could be called re-entrant.
create a global var xxxRuning:Boolean=false;

then in the working procedure at first line put

Code: Pascal  [Select][+][-]

1. begin
2.  
3.   if xxxRuning then showmessage('Damn been called while running!');
4.   xxxRuning:=true;
5. ....
6.  
7. lastline
8.   xxxRuning:=false;
9. end;

not familiar enough, but you appear to be opening the comport, on each click OpenComPort(Res); does it need closing at end of proc?

[MathMan]

I see - it was just a hunch, but I thought better mention it.

Another question. Your statistics show that after 2500 iterations of the (I assume) loop you showed in your last answer there is already 1 GByte of memory associated to your application. I understand that there is not necessarily a 1:1 relation between allocated memory and used part of that - but this seems to hint to a relatively large chunk of memory being 'lost' (~400 kByte) with each iteration of the loop. Do you handle a data structure of a comparable size in your application at all?

[jamie]

I see u open a comport, do u close it?

[Martin_fr]

You don't by any chance use threads?
Because you have calls to LCL controls on the form. And that is only allowed in the main thread. Just in case.

I don't know what of the below will be useful.

Just a few "tricks" to check mem alloc stuff. Maybe something in those can help...


You can always pull info from the FPC heapmanager

I think (but may need to be double checked)

Code: Pascal  [Select][+][-]

1. var h: TFPCHeapStatus;
2. begin
3.   h := GetFPCHeapStatus;
4.   writeln(h.CurrHeapUsed);
5.  

Writeln, or display where ever you need. (there are some more fields)

Then you can see, how much mem is actually used by your app, versus how much is "used" as reserve (or too fragmented to be used).

Then if the actual usage indeed goes up, you can start debugging.

E.g. if in your test memory adds up, but gets released after the loop (which in real life does not happen, if I read you correct?) then you can try a breakpoint in FreeMem.

Only that needs an RTL with debug info. Or you can hook the mem manager, and inject your own. And break in your code (which forwards the call).

Code: Pascal  [Select][+][-]

1. var
2.   MMgr: TMemoryManager;
3.   OrigFreemem             : Function(p:pointer):ptruint;
4.   OrigFreememSize         : Function(p:pointer;Size:ptruint):ptruint;
5.  
6. Function MyFreemem(p:pointer):ptruint;
7. begin
8.   Result := OrigFreemem(p);
9. end;
10. Function MyFreememSize(p:pointer;Size:ptruint):ptruint;
11. begin
12.   Result := OrigFreememSize(p,Size);
13. end;
14.  
15. initialization
16.   GetMemoryManager(MMgr);
17.   OrigFreemem     := MMgr.Freemem;
18.   OrigFreememSize := MMgr.FreememSize;
19.   MMgr.Freemem     := @MyFreemem;
20.   MMgr.FreememSize := @MyFreememSize;
21.   SetMemoryManager(MMgr);
22.  

Though you will get a lot of calls. It may not be plausible to check them all.

You can also use that to log calls, depending on where the code is.
E.g. in your main code set a flag "MyVarLogMem := true;" for a small block of the code. Then you can log what happens in there.
Or you can accumulate all allocation sizes

Put a hook an alloc mem: AllocMem            : Function(Size:ptruint):Pointer;

Code: Pascal  [Select][+][-]

1. Function MyAllocMem (Size:ptruint):Pointer;
2. begin
3.   result := OrigAllocMem(Size);
4.   if MyVarLogMem  then
5.     MyVarMemAllocSum := MyVarMemAllocSum + Size;
6. end;

Then in your code
  MyVarMemAllocSum := 0;
  MyVarLogMem  := true;

And at the end of the block, print how much was allocated.

Maybe some pattern emerges....



I don't have experience with LazSerial...

What happens if data comes in faster than you process it? Does it have an internal buffer that grows and grows?

[Wilko500]

@Josh, I am sure it isn't but I will check.

@MathMan, the only thing that comes to mind is a class that holds contents on an ini file, <1Kb, a single instance created and loaded at start of program (freed at exit) but not referenced during the tests.

@Jamie, well spotted.  But it is closed on program exit.  The OpenComPort call is only here because of the test scenario.  The program opens Com port at program start and closes it at exit.  Both Open & Close contain tests so that it is only opened if it is not open and closed if it is open.

@Martin, no threads used at present.  The intention is to use a thread for inverter polling but I can't do that yet 'cos I've got to learn how to pass data back to main thread for updating controls.

On LazSerial the call I use retrieves data from an internal buffer, waits for up to RcvWait msecs for 8 chars, if not received in that time it exits with error code.  As a side note I did a lot of serial port logging during the early investigation phase while I was reverse engineering the communications protocol.  It's actually very simple. Inverter receives a packet, checksums it and if good sends out 8 chars.  Earlier versions of my program checked for communication errors, checksum errors, timeouts and logged then to a debug file.  It is for that reason that for each call to the inverter 3 attempts are permitted.  Those errors were extremely rare.  The RcvWait value of 70 msecs was established by observing error frequency after varying the RcvWait value.

Thank you for the FPC heapmanager stuff.  I'll take a look at that, see if I can make sense of it.

And for you all, thanks for suggestions.  I have an uneasy feeling that I'm chasing a ghost, a problem that seems to manifest itself in the call to DoCmd59x3 but is actually somewhere very different or caused by something unrelated.

I recoded my DecodeToSingle function as follows instead of using absolute and it made no difference to the memory increase.  That I think is good news

Code: Pascal  [Select][+][-]

1.   Result.Bytes[3]:=b[2];
2.   Result.Bytes[2]:=b[3];
3.   Result.Bytes[1]:=b[4];
4.   Result.Bytes[0]:=b[5];

I plan to do additional tests on all the calls separately to confirm which other calls if any "cause" the memory build up and separately recode to fire the calls from a timer instead of a loop so I can easily control the frequency. It bothers me that at the end of the current test loop the memory is released after a few seconds and makes me wonder if I've stumbled on a MacOs internals timing issue.
Other than that I might try again to create a new program that does nothing but a single call to the inverter .  .  .

[MathMan]

...
I recoded my DecodeToSingle function as follows instead of using absolute and it made no difference to the memory increase.  That I think is good news

Code: Pascal  [Select][+][-]

1.   Result.Bytes[3]:=b[2];
2.   Result.Bytes[2]:=b[3];
3.   Result.Bytes[1]:=b[4];
4.   Result.Bytes[0]:=b[5];

I plan to do additional tests on all the calls separately to confirm which other calls if any "cause" the memory build up and separately recode to fire the calls from a timer instead of a loop so I can easily control the frequency. It bothers me that at the end of the current test loop the memory is released after a few seconds and makes me wonder if I've stumbled on a MacOs internals timing issue.
Other than that I might try again to create a new program that does nothing but a single call to the inverter .  .  .

Just as an idea - maybe you want to try

Code: Pascal  [Select][+][-]

1.   pSingle( @Result )^ := BEtoN( UnAligned( pDWord( @b[2] )^ ) );
2.  

[Wilko500]

@MathMan, thanks for that.  I'll try it out tomorrow when inverter wakes up.  Mind you, I haven't got my head round pointers yet so I had to ask ChatGPT to explain it to me   Whether or not it makes any difference I have learnt something new.