Re: bad files causing thredds crash

Hi Bob:

1) What heap memory settings are you giving to the JVM on tomcat 
startup? (to verify, you can look at http://server/thredds/debug and 
choose "showRuntimeInfo", assuming you have remote debugging enabled)

2) what is the hardware, OS, and JVM version?

3) how big is /thredds/Hfradar/aggreghfradarC1/u33h/catalog.xml  ?

4) remind me of the URL of your server so i can see how big some of 
these datasets are.

Im guessing there is a "memory leak" (objects not getting GCd) but i 
need to eliminate the obvious first.

Re: the info in the log, eg:

2007-11-28T04:55:27.959 -0800 [ 633762099][ 1094643]

= date [msecs since server start] [request number]

so this server has been up about 7 days, and served > 1 million requests (!)

I need to investigate what TDS does with bad files, especially if you 
replace them. Ill get back to you asap.

Bob Simons wrote:
> OK. Thredds crashed this morning attached are the catalina.out and 
> threddsServlet.logs from that time period.
>
> I hope that first bracketed number on each line of threddsServlet.log 
> isn't memoryInUse. Is it?
>
>
> A possibly related question about bad files:
> If there is a bad data file (e.g., 0 bytes) which Thredds notices and 
> we subsequently delete, if we then replace that file, does thredds 
> notice that it is a new file (because the cacheAged cache includes 
> information about the files date and notices that the file's date has 
> changed) or do we need to delete the relevant cacheAged file whenever 
> we delete a data file?
>
> Thanks for looking into this.
>
> John Caron wrote:
> > too bad. if.when it happens again, grab it. i will try to replicate 
> > here.
> >
> > (you are checking all files of the form threddsServlet.log.N N=1..10 ?)
> >
> >
> > Bob Simons wrote:
> > > Sorry. It has been too long. That information is no longer available.
> > >
> > > John Caron wrote:
> > > > sorry to be vague; in content/thredds/logs/threddsServlet.log there 
> > > > should be at least one more, possibly 2
> > > >
> > > > Bob Simons wrote:
> > > > > That was the only message with "[    6343]".
> > > > >
> > > > >
> > > > > John Caron wrote:
> > > > > > Hi Bob:
> > > > > >
> > > > > > Can you look in the log file for all messages from request 6343:
> > > > > >
> > > > > > 2007-11-15T08:17:57.883 -0800 [   1024030][    6343] ERROR - 
> > > > > > thredds.server.opendap.NcDODSServlet - Error
> > > > > > java.lang.OutOfMemoryError: Java heap space
> > > > > > these will be in order, but may be interleaved with other requests:
> > > > > >
> > > > > > id like to see what size the original request was.
> > > > > >
> > > > > >
> > > > > > Bob Simons wrote:
> > > > > > > We're having a lot of problems with thredds crashing lately.
> > > > > > > We're hoping you can look into the problem or give us advice.
> > > > > > > We recently updated to THREDDS Data Server Version 3.16.22 Build 
> > > > > > > Date = 2007-10-25 19:10:28.
> > > > > > >
> > > > > > > The general scenario is:
> > > > > > > 1) One or more invalid .nc files are added to the data directories.
> > > > > > >   Obviously, this isn't intentional.
> > > > > > >   And we just found the source of many of these: a bad NIC card.
> > > > > > >   But given the huge number of files involved, it has always
> > > > > > >   occurred periodically.
> > > > > > >   Often, it is a file with 0 bytes.
> > > > > > >
> > > > > > > 2) During aggregation, thredds notices the bad file and reports
> > > > > > >   it to catalina.out. For example:
> > > > > > >
> > > > > > > 2007-11-15T09:17:45.277 -0800 [   1446340][    3538] ERROR - 
> > > > > > > thredds.server.opendap.NcDODSServlet - Error
> > > > > > > java.io.IOException: Cant read 
> > > > > > > /u00/satellite/AK/sstd/hday/AK2007272_014200h_sstd.nc: not a 
> > > > > > > valid NetCDF file.
> > > > > > >         at ucar.nc2.NetcdfFile.open(NetcdfFile.java:459)
> > > > > > >         at ucar.nc2.NetcdfFile.open(NetcdfFile.java:261)
> > > > > > >         at 
> > > > > > > ucar.nc2.dataset.NetcdfDataset.openFile(NetcdfDataset.java:341)
> > > > > > >         at 
> > > > > > > ucar.nc2.ncml.Aggregation$Dataset$PolymorphicReader.open(Aggregation.java:1286) 
> > > > > > >
> > > > > > >         at 
> > > > > > > ucar.nc2.NetcdfFileCache.acquire(NetcdfFileCache.java:188)
> > > > > > >         at 
> > > > > > > ucar.nc2.ncml.Aggregation$Dataset._acquireFile(Aggregation.java:1186) 
> > > > > > >
> > > > > > >         at 
> > > > > > > ucar.nc2.ncml.Aggregation$Dataset.acquireFile(Aggregation.java:1172) 
> > > > > > >
> > > > > > >         at 
> > > > > > > ucar.nc2.ncml.Aggregation$Dataset.getNcoords(Aggregation.java:1100)
> > > > > > >         at 
> > > > > > > ucar.nc2.ncml.Aggregation$Dataset.setStartEnd(Aggregation.java:1121) 
> > > > > > >
> > > > > > >         at 
> > > > > > > ucar.nc2.ncml.Aggregation$Dataset.access$100(Aggregation.java:1002)
> > > > > > >         at 
> > > > > > > ucar.nc2.ncml.Aggregation.buildCoords(Aggregation.java:315)
> > > > > > >         at 
> > > > > > > ucar.nc2.ncml.AggregationExisting.buildDataset(AggregationExisting.java:61) 
> > > > > > >
> > > > > > >         at ucar.nc2.ncml.Aggregation.finish(Aggregation.java:293)
> > > > > > >         at ucar.nc2.ncml.NcMLReader.readNetcdf(NcMLReader.java:397)
> > > > > > >
> > > > > > > 3) Sometime afterwards
> > > > > > >   (not immediatly, but it seems to be sooner if there are more 
> > > > > > > bad files),
> > > > > > >   thredds crashes. For example:
> > > > > > >
> > > > > > > 2007-11-15T08:17:57.883 -0800 [   1024030][    6343] ERROR - 
> > > > > > > thredds.server.opendap.NcDODSServlet - Error
> > > > > > > java.lang.OutOfMemoryError: Java heap space
> > > > > > > DODServlet ERROR (anyExceptionHandler): 
> > > > > > > java.lang.OutOfMemoryError: Java heap space
> > > > > > > java.lang.OutOfMemoryError: Java heap space
> > > > > > > ReqState:
> > > > > > >   serverClassName:    'thredds.server.opendap.NcDODSServlet'
> > > > > > >   dataSet:            'satellite/CM/usfc/hday'
> > > > > > >   requestSuffix:      'dods'
> > > > > > >   CE:                 'altitude,lat,lon,time'
> > > > > > >   compressOK:          false
> > > > > > >   InitParameters:
> > > > > > >     DebugOn: ''
> > > > > > >     maxNetcdfFilesCached: '10'
> > > > > > >
> > > > > > > java.lang.OutOfMemoryError: Java heap space
> > > > > > >
> > > > > > > There may be a couple of these errors (referring to different 
> > > > > > > datasets) in rapid succession, then:
> > > > > > >
> > > > > > > 2007-11-15T08:18:18.048 -0800 [   1044195][    6487] ERROR - 
> > > > > > > org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/thredds].[NetcdfDODS] 
> > > > > > > - Servlet.service() for servlet NetcdfDODS threw exception
> > > > > > > java.lang.OutOfMemoryError: Java heap space
> > > > > > > Nov 15, 2007 8:18:12 AM 
> > > > > > > org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor 
> > > > > > > processChildren
> > > > > > > SEVERE: Exception invoking periodic operation:
> > > > > > > java.lang.OutOfMemoryError: Java heap space
> > > > > > > Nov 15, 2007 8:18:53 AM unknown unknown
> > > > > > > SEVERE: Exception invoking periodic operation:
> > > > > > > java.lang.OutOfMemoryError: Java heap space
> > > > > > >
> > > > > > >
> > > > > > >
> > > > > > > So, we aren't certain that the bad files are the cause of the 
> > > > > > > OutOfMemoryErrors, but the correlation is strong.  With no or 
> > > > > > > few bad files, thredds seems to stay up longer. With more bad 
> > > > > > > files, thredds seems more likely to crash.
> > > > > > >
> > > > > > > As a possible cause, I'll mention the previous problem with .nc 
> > > > > > > files not being automatically closed by an over-ridden finalize 
> > > > > > > method. (See Original Message below.) This caused a memory and 
> > > > > > > resource leak if the program didn't explicitly close every file 
> > > > > > > (even if an Exception or Error is thrown during processing). A 
> > > > > > > similar problem could certainly be the cause of the problem here.
> > > > > > >
> > > > > > > And I'll mention our previous request to have Thredds simply 
> > > > > > > ignore bad files, but keep serving the rest of the dataset. (See 
> > > > > > > Original Message below.) You said you were going to work on 
> > > > > > > that. I don't know if you made changes or what changes you made. 
> > > > > > > I'll just point out that we only recently upgraded to a version 
> > > > > > > of thredds which might have these changes in it.  We had 
> > > > > > > previously been using a somewhat older version because of other 
> > > > > > > problems with the intervening versions of thredds.
> > > > > > >
> > > > > > > I hope that is helpful.
> > > > > > >
> > > > > > > Thanks for looking into this.
> > > > > > >
> > > > > > > Sincerely,
> > > > > > >
> > > > > > > Bob Simons
> > > > > > > Satellite Data Product Manager
> > > > > > > Environmental Research Division
> > > > > > > NOAA Southwest Fisheries Science Center
> > > > > > > 1352 Lighthouse Ave
> > > > > > > Pacific Grove, CA 93950-2079
> > > > > > > (831)658-3205
> > > > > > > address@hidden
> > > > > > >
> > > > > > > The contents of this message are mine personally and
> > > > > > > do not necessarily reflect any position of the
> > > > > > > Government or the National Oceanic and Atmospheric
> > > > > > > Administration.
> > > > > > > <>< <>< <>< <>< <>< <>< <>< <>< <><
> > > > > > >
> > > > > > >
> > > > > > > -------- Original Message --------
> > > > > > > Subject: finalize
> > > > > > > Date: Fri, 18 Aug 2006 12:10:57 -0700
> > > > > > > From: Bob Simons <address@hidden>
> > > > > > > Organization: NOAA/ERD
> > > > > > > To: John Caron <address@hidden>
> > > > > > >
> > > > > > > I had a bug in a new procedure I was writing (my fault, I admit),
> > > > > > > wherein the close() method of many NetcdfFile objects was never 
> > > > > > > called.
> > > > > > >
> > > > > > > On Windows, this code ran fine. The Java implementation on Windows
> > > > > > > (specifically the garbage collector) must have been smart enough to
> > > > > > > recover all the memory allocated and close all the files when the
> > > > > > > NetcdfFile objects were no longer referenced.
> > > > > > >
> > > > > > > But on Linux, the procedure failed after many calls, and I got 
> > > > > > > an error
> > > > > > > message (from Java? from Tomcat? it doesn't matter) saying "too 
> > > > > > > many
> > > > > > > files open".
> > > > > > >
> > > > > > > Fine. I fixed the problem in my code. But I two requests for you:
> > > > > > >
> > > > > > > 1) In the JavaDocs for the NetcdfFile class (up at the top), please
> > > > > > > include the same suggestion as you already have in 
> > > > > > > NetcdfFileCache's
> > > > > > > JavaDocs regarding the use of "finally" to ensure that close() is
> > > > > > > called.  E.g.,
> > > > > > >
> > > > > > >     NetcdfFile ncfile = null;
> > > > > > >     try {
> > > > > > >         ncfile = NetcdfFile.open(fileName);
> > > > > > >         ...
> > > > > > >     } finally {
> > > > > > >         ncfile.close();
> > > > > > >     }
> > > > > > >
> > > > > > > 2) I think it would be a huge improvement to NetcdfFile (and 
> > > > > > > presumably
> > > > > > > NetcdfFileCache, NetcdfDataset, NetcdfDatasetCache, DODSNetcdfFile
> > > > > > > (which isn't in the latest copy of the documentation I have), 
> > > > > > > and any
> > > > > > > similar object), to include the following method (or something 
> > > > > > > like it):
> > > > > > >
> > > > > > >     protected void finalize() throws Throwable {
> > > > > > >         close();
> > > > > > >     }
> > > > > > >
> > > > > > > As you probably know, the finalize() method is inherited from the
> > > > > > > java.lang.Object class and is called whenever an object is 
> > > > > > > eligible for
> > > > > > > garbage collection.  In this case, overriding finalize() lets 
> > > > > > > you ensure
> > > > > > > that the close() method always gets called.
> > > > > > >
> > > > > > > In real life, it isn't always possible to use try/finally. That 
> > > > > > > opens up
> > > > > > > the possibility of not calling close() if an error occurs. It is
> > > > > > > dangerous to have that resource leakage be a possibility.
> > > > > > >
> > > > > > > Your use of finalize() prevents this type of resource leakage (as
> > > > > > > dangerous as memory leaks in other languages) from occurring.
> > > > > > >
> > > > > > > I admit again that it was my coding error that lead to these issue
> > > > > > > coming up. But I think it is good defensive programming to have a
> > > > > > > finalize() method for classes like these.
> > > > > > >
> > > > > > > Thank you.
> > > > > > > ***end -------- Original Message --------
> > > > > > >
> > > > > > >
> > > > > > >
> > > > > > >
> > > > > > > -------- Original Message --------
> > > > > > > Subject: Request for enhancement
> > > > > > > Date: Wed, 03 Jan 2007 15:23:39 -0800
> > > > > > > From: Bob Simons <address@hidden>
> > > > > > > Organization: NOAA/ERD
> > > > > > > To: John Caron <address@hidden>
> > > > > > > CC: Roy Mendelssohn <address@hidden>,  Dave Foley 
> > > > > > > <address@hidden>
> > > > > > >
> > > > > > > The Problem:
> > > > > > >
> > > > > > > We often use THREDDS to aggregate near-real-time data. We have one
> > > > > > > directory per data set and frequently (hourly or daily) add an
> > > > > > > additional data file to each data set's directory. Sometimes 
> > > > > > > things go
> > > > > > > wrong (e.g., power outages) and a partial and/or damaged file is 
> > > > > > > left in
> > > > > > > a data set's directory. We try to deal with this, but our 
> > > > > > > methods aren't
> > > > > > > perfect.
> > > > > > >
> > > > > > > Currently, when THREDDS is aggregating a data set, if THREDDS 
> > > > > > > finds an
> > > > > > > invalid .nc data file in with all the .nc data files for a given 
> > > > > > > data
> > > > > > > set, it throws an Exception ("java.io.IOException: Cant read 
> > > > > > > [fileName]:
> > > > > > > not a valid NetCDF file.") and rejects the entire dataset. This 
> > > > > > > is a
> > > > > > > serious problem for us because one bad file makes an entire dataset
> > > > > > > disappear from THREDDS. The only way for us to find out if this has
> > > > > > > happened is to go through the <tomcat>/logs/catalina.out log 
> > > > > > > file (which
> > > > > > > we do periodically) and look for the Exception messages.
> > > > > > >
> > > > > > > The Request:
> > > > > > >
> > > > > > > It would be nice if THREDDS simply rejected the bad files 
> > > > > > > (throwing an
> > > > > > > Exception as it does now), but kept going with the aggregation 
> > > > > > > of the
> > > > > > > data set.
> > > > > > >
> > > > > > > (I realize that the proposed recommendation is good for our 
> > > > > > > situation
> > > > > > > and you may not be comfortable making it the standard behavior 
> > > > > > > for THREDDS.)
> > > > > > >
> > > > > > >
> > > > > > > Thank you.
> > > > > > > ***end -------- Original Message --------