6. Logging

AvnFPS has an extensive logging system, similar to collective logging in AWIPS. The amount of information written to log files and its format are configurable.

Each program has its own log file, one per day of the week. File naming is according to the scheme progname_DayOfWeek, so avndis will produce files avndis_Mon through avndis_Sun. Files are broken (old closed, new opened) at the first write attempt of each new day. This is different from AWIPS where a cron job breaks the log after 00Z.

The file etc/logging.cfg controls the location, format and log level for the log files. The format and log level is the same for all programs.

[Note]Note

The log directory is local to each server/workstation. The directory /awips/adapt/avnfps/OB8.3/logs points to /data/logs/adapt/avnfps, which resides on a local partition. This is consistent with the AWIPS standard:

lx2-wfo:46: ll /awips/adapt/avnfps/OB8.3/logs
lrwxrwxrwx    1 fxa      fxalpha        23 Oct  8 16:41 /awips/adapt/avnfps/OB8.3/logs -> /data/logs/adapt/avnfps
		

Here is an example listing of a log file for avndis:

Log rollover at 00:00:01
2006-03-01 00:00:01,280 DEBUG [10517:126217136] TriggerThread: Processing PHLMTRMDT
2006-03-01 00:00:01,647 INFO  [10517:126217136] TextThreadP: Processed KMDT from SAUS70 KMDT 080000
2006-03-01 00:00:01,647 DEBUG [10517:126217136] TriggerThread: Done PHLMTRMDT
2006-03-01 00:00:01,649 DEBUG [10517:126217136] TriggerThread: Processing PITMTRDUJ
2006-03-01 00:00:01,656 DEBUG [10517:27261872] DataIngestServ: Msg: {'src': 'mtrs', 'ident': 'KMDT'}
2006-03-01 00:00:01,754 INFO  [10517:126217136] TextThreadP: Processed KDUJ from SAUS70 KDUJ 080000
2006-03-01 00:00:01,755 DEBUG [10517:126217136] TriggerThread: Done PITMTRDUJ
2006-03-01 00:00:01,756 DEBUG [10517:126217136] TriggerThread: Processing BUFMTRART
2006-03-01 00:00:01,981 DEBUG [10517:27261872] DataIngestServ: Msg: {'src': 'mtrs', 'ident': 'KDUJ'}
2006-03-01 00:00:01,989 INFO  [10517:126217136] TextThreadP: Processed KART from SAUS70 KART 080000
2006-03-01 00:00:01,990 DEBUG [10517:126217136] TriggerThread: Done BUFMTRART
2006-03-01 00:00:01,993 DEBUG [10517:27261872] DataIngestServ: Msg: {'src': 'mtrs', 'ident': 'KART'}
2006-03-01 00:00:05,289 DEBUG [10517:126217136] TriggerThread: Processing HFOMTRHNY
2006-03-01 00:00:05,576 INFO  [10517:101030832] LtgThread: Processing file /data/fxa/point/binLightning/netcdf/20060228_2300
2006-03-01 00:00:05,629 INFO  [10517:126217136] TextThreadP: Processed PHNY from SAUS80 PHNY 080000
2006-03-01 00:00:05,631 DEBUG [10517:126217136] TriggerThread: Done HFOMTRHNY
2006-03-01 00:00:05,633 DEBUG [10517:126217136] TriggerThread: Processing BUFMTRROC
2006-03-01 00:00:06,020 DEBUG [10517:27261872] DataIngestServ: Msg: {'src': 'mtrs', 'ident': 'PHNY'}

		

Each line contains the following fields:

Some typical errors:

2005-07-08 02:00:48,843 INFO  [10517:84941744] MosData: Retrieved ngm data for BUF
2005-07-08 02:00:48,851 ERROR [10517:84941744] MosData: BVI not in /data/fxa/point/mos/NGM/netcdf/20050708_0000	1
2005-07-08 02:00:48,882 INFO  [10517:84941744] MosData: Retrieved ngm data for CHA

2005-07-08 05:32:52,556 DEBUG [10517:126217136] TriggerThread: Done MEMTAFTRI
2005-07-08 05:32:52,558 WARNING [10517:74451888] util: Daemon ** Exception during processing of request from TCPConnection with ('xxx.xxx.xxx.xxx', 45051)
connected=1  type thread.error 2
--- traceback of this exception follows:
 --------------------------------------------------
 <thread.error> RAISED : can't start new thread

 Extended Stacktrace follows (most recent call last)
--------------------------------------------------
File "/awips/adapt/avnfps/Python-2.4.1/lib/python2.4/site-packages/Pyro/protocol.py", line (922), in Daemon::connectionHandler
Source code:
    self.handleInvocation(conn)
File "/awips/adapt/avnfps/Python-2.4.1/lib/python2.4/site-packages/Pyro/core.py", line (695), in Daemon::handleInvocation
Source code:
		

1

This message indicates problem with TAF Site Info configuration file: data for KBVI is not distibuted for NGM MOS product. This does not cause any harm, but one can either select another site which is close enough, or leave the NGM MOS site id empty.

2

Some messages provide detailed traceback to point out to the exact location of the code where the error occured. In this case, the error comes from Pyro code and it is relatively serious. The data ingest server hit the threshold of allowable memory consumption. avndis has this threshold set programatically to avoid clogging the whole operating system. In a situation like this one should restart avndis to avoid data loss. If the problem reoccurs, further investigation is required. (This example is contrived: the threshold was set too low during development).