My application reads a sensor, does a bunch of calculations, sends a speed control command to a motor/pump and writes several hundred bytes of data to a log file on a microSD card. Right now I do that whole loop every 500 milliseconds but eventually I might need to go faster, maybe every 100 milliseconds. Worst case that makes it about 3000 bytes/second. The program works fine for several minutes and then throws the exception below when I try to write to the SD card. I used to get the exception at the .WriteLine command so I added the try/catch with a .Flush in the catch block. Now I get the error at the .Flush command. I can’t figure out what might be going wrong from the Debug output text. Any suggestions would be greatly appreciated.
Note: I also tried the using block that is commented out in the code but couldn’t get it to work. Would that be a better way to do this? If so, how do I set up a using block properly?
I would say based on "System.ObjectDisposedException - CLR_E_OBJECT_DISPOSED " that somehow “engrLogWriter” has been disposed when you try to access it. Put a test at the start of writelog to confirm the object is still vallid. If not you need to find where and how the object is detroyed. Maybe GC?
Here is my whole engrLog class (short for Engineering log where I log the gory details only an engineer will be interested in). The engrLogWriter (and engrLogReader) are instantiated at the top. The initEngrLog method is called at the very beginning of the app where I initialize everything that needs initialization.
I’ve been warned about eventually getting bit by GC. If that is in fact what is going on, is there a way to instantiate something in a way that prevents the GC from disposing of it?
using System;
using System.IO;
using System.Text;
using Microsoft.SPOT;
using Microsoft.SPOT.IO;
using GHI.Premium.IO;
namespace MFConsoleApplication1
{
public static class EngrLog
{
public static StreamWriter engrLogWriter;
public static StreamReader engrLogReader;
public static String engrLogFilename;
public static void initEngrLog()
{
PersistentStorage sdCard = new PersistentStorage("SD");
sdCard.MountFileSystem();
VolumeInfo sdVol = new VolumeInfo("SD");
engrLogFilename = sdVol.RootDirectory + "\\engrLog" + DateTime.Now.ToString("yyyyMMMdd" + "T" + "HHmmss");
engrLogWriter = new StreamWriter(engrLogFilename, true);
Debug.Print("Volume Name: " + sdVol.Name.ToString());
Debug.Print("Volume Total Size: " + sdVol.TotalSize.ToString());
Debug.Print("Volume Free Space: " + sdVol.TotalFreeSpace.ToString());
Debug.Print("Volume File System: " + sdVol.FileSystem.ToString());
Debug.Print("Volume Serial Num: " + sdVol.SerialNumber.ToString());
Debug.Print("Volume ID: " + sdVol.VolumeID.ToString());
Debug.Print("Volume Label: " + sdVol.VolumeLabel.ToString());
Debug.Print("Volume Root Dir: " + sdVol.RootDirectory.ToString());
}
public static void writeLog(string logString)
{
try
{
engrLogWriter.WriteLine(logString);
}
catch
{
engrLogWriter.Flush();
}
//using (var writer = new StreamWriter(engrLogFilename))
// engrLogWriter.WriteLine(logString);
Debug.Print(logString);
}
Thanks for the advice, I’ll implement your suggestions and let you know how that turns out. In the mean time, is the following a better (or even legal in .Net micro) way to do this?
using (var engrLogWriter = new StreamWriter(engrLogFilename))
engrLogWriter.WriteLine(logString);
Well declaring sdCard as a public static variable didn’t seem to work. Sure would have been nice. I haven’t been able to figure out a way to see if engrLogWriter is still valid before I use it. Any suggestions?
I am currently calling the logger every 500 milliseconds but might like to call it every 100 milliseconds in the future.
I’m only using 1 thread, can’t say what .NET micro might be doing under the hood.
I’m using a Spider mainboard and the GHI microSD card along with 3 RS232 modules that I read and write too. I also have a SPI device that I read along with everything else.
I’m using the 4.2SDK and straight .NET micro C#, no Gadgeteer calls.
I generate a lot of data with Debug.Print. In the past, I’ve only used the output to look at my engineering data. But, I just looked again and lo and behold the results of a GC were there. I don’t call the GC so it must get printed out to the Debug output window on its own. I will have to do a little more work to see if I can correlate this with my error.
I wrote a really simple version of my program that makes up some data and call the engrLogger. The code is below. Even this simple app winds up calling the GC. I ran it for about 25 minutes and the GC seemed to run about every 2 minutes. Here is a typical GC output from the Debug Output window sandwiched in between two of the normal program Debug.Print statements. Interestingly, in this simple program I’m not getting any errors from the catch block in the engrLogWriter although I do seem to get them in the full up program.
The goal is for the full up code to run autonomously for years at a time so stability, robustness, repeatability and testability are all critical. As effective as .NETMF and C# have been, the GC is really at odds with these goals. Here are several specific questions and any other suggestions will be greatly appreciated.
What in this code is causing the GC to run, or does it run no matter what even if almost everything is declared public static?
Given I’m looking for long term stability/robustness for my program running for potentially several years, is FileWriter a better choice?
Can I and/or should I explicitly dispose of all the temporary variables that aren’t declared public static?
The error I get in the full up code seems to be the GC disposes of my engrLogWriter variable. Is there a clean way to check if engrLogWriter is still valid and redefine it if it has been disposed of?
Many thanks for all the help - Gene
04/16/2013 10:10:55.186;Data;AutoBallast;Goto Vel SP= 0.000 ;Depth SP= 100.000;Pres= -0.01939;Last Pres= -0.03232;Vel= 0.02586;y1= 0.012;y2= 0.005;v= -4.232;u= -4.232;uCPS= -8464.688;I= 0.000;Bel Pos= 82.3260
GC: 191msec 52692 bytes used, 7286976 bytes available
Type 0F (STRING ): 756 bytes
Type 11 (CLASS ): 2304 bytes
Type 12 (VALUETYPE ): 84 bytes
Type 13 (SZARRAY ): 5628 bytes
Type 03 (U1 ): 4272 bytes
Type 04 (CHAR ): 360 bytes
Type 07 (I4 ): 36 bytes
Type 0F (STRING ): 168 bytes
Type 11 (CLASS ): 792 bytes
Type 15 (FREEBLOCK ): 7286976 bytes
Type 16 (CACHEDBLOCK ): 264 bytes
Type 17 (ASSEMBLY ): 15288 bytes
Type 18 (WEAKCLASS ): 48 bytes
Type 19 (REFLECTION ): 24 bytes
Type 1B (DELEGATE_HEAD ): 144 bytes
Type 1D (OBJECT_TO_EVENT ): 48 bytes
Type 1E (BINARY_BLOB_HEAD ): 23976 bytes
Type 1F (THREAD ): 1152 bytes
Type 20 (SUBTHREAD ): 144 bytes
Type 21 (STACK_FRAME ): 1416 bytes
Type 27 (FINALIZER_HEAD ): 96 bytes
Type 31 (IO_PORT ): 72 bytes
Type 34 (APPDOMAIN_HEAD ): 72 bytes
Type 36 (APPDOMAIN_ASSEMBLY ): 1176 bytes
04/16/2013 10:10:55.209;Data;AutoBallast;Goto Vel SP= 0.000 ;Depth SP= 100.000;Pres= -0.01939;Last Pres= -0.03232;Vel= 0.02586;y1= 0.012;y2= 0.005;v= -4.232;u= -4.232;uCPS= -8464.688;I= 0.000;Bel Pos= 82.3260
Here is my Program.cs
using System;
using System.Threading;
using Microsoft.SPOT;
using Microsoft.SPOT.Hardware;
using GHI.Premium.Hardware;
namespace engrLogTest
{
public class Program
{
public static String DateTimeNowMilliSeconds()
{
DateTime timeNow = DateTime.Now;
String temp = timeNow.ToString() + "." + timeNow.Millisecond.ToString();
return (temp);
}
public static void Main()
{
Utility.SetLocalTime(RealTimeClock.GetTime());
Debug.Print("\r\n" + DateTime.Now.ToString() + " Starting Program ...\r\n");
EngrLog.initEngrLog();
String typicalString = ";Data;AutoBallast;Goto Vel SP= 0.000 ;Depth SP= 100.000;Pres= -0.01939;Last Pres= -0.03232;Vel= 0.02586;y1= 0.012;y2= 0.005;v= -4.232;u= -4.232;uCPS= -8464.688;I= 0.000;Bel Pos= 82.3260";
for (int i = 0; i < 100000; i++)
EngrLog.writeLog(DateTimeNowMilliSeconds() + typicalString);
EngrLog.getDirectory();
}
}
}
Here is the EngrLog Class
using System;
using System.IO;
using System.Text;
using System.Collections;
using Microsoft.SPOT;
using Microsoft.SPOT.IO;
using GHI.Premium.IO;
namespace engrLogTest
{
class EngrLog
{
public static StreamWriter engrLogWriter;
//public static StreamReader engrLogReader;
public static String engrLogFilename;
public static PersistentStorage sdCard = new PersistentStorage("SD");
public static void initEngrLog()
{
sdCard.MountFileSystem();
VolumeInfo sdVol = new VolumeInfo("SD");
engrLogFilename = sdVol.RootDirectory + "\\engrLog" + DateTime.Now.ToString("yyyyMMMdd" + "T" + "HHmmss");
engrLogWriter = new StreamWriter(engrLogFilename, true);
Debug.Print("Volume Name: " + sdVol.Name.ToString());
Debug.Print("Volume Total Size: " + sdVol.TotalSize.ToString());
Debug.Print("Volume Free Space: " + sdVol.TotalFreeSpace.ToString());
Debug.Print("Volume File System: " + sdVol.FileSystem.ToString());
Debug.Print("Volume Serial Num: " + sdVol.SerialNumber.ToString());
Debug.Print("Volume ID: " + sdVol.VolumeID.ToString());
Debug.Print("Volume Label: " + sdVol.VolumeLabel.ToString());
Debug.Print("Volume Root Dir: " + sdVol.RootDirectory.ToString());
}
public static void writeLog(string logString)
{
try
{
engrLogWriter.WriteLine(logString);
Debug.Print(logString);
}
catch
{
Debug.Print("engrLogWrite error");
}
}
public static void getDirectory()
{
VolumeInfo sdVol = new VolumeInfo("SD");
String[] fileNames = Directory.GetFiles(sdVol.RootDirectory);
for (int i = 0; i < fileNames.Length; i++)
{
FileInfo fileInfo = new FileInfo(fileNames[i]);
Debug.Print(i.ToString() + " File name: " + fileNames[i]
+ " Creation Date = " + fileInfo.CreationTime.ToString()
+ " Length = " + fileInfo.Length.ToString());
}
}
}
}
This gets more and more complicated. I’ve been trying to understand the differences between StreamReader/Writer and FileStream. I have a program (see below) that reads a 266 Kbyte file off my SD card, first with StreamReader and then with FileStream. The FileStream loop seems to work fine although it is pretty slow compared to the StreamReader loop. However, the StreamReader loop crashes part way through reading the file at pretty much the same spot with the following error.
Here’s a simple suggestion to show how this can have an effect. Create a new console application. In the console app create an INT variable, say i, and then debug.print("This is a test " + i). Put a break point on the debug.print and hit F5, then F11 to step into the debug.print. Watch how many string related operations go on, I count at least 4 calls to string.concat when I ran it plus a handful of other calls. Each of those sub-components then gets disposed and GCed. So if you’re using strings, you’ll need GC. You could even check how many times the strings are called in your TimeNow method.
The only issue I think you should work through is why your log writer object goes out of scope and gets GCed. I am not the right person to comment (I don’t know enough about scope of objects in C#) but when faced with a similar issue I would have attempted to specifically instantiate the logwriter outside the scope of MAIN.
