QC2-OPE-LOG
This test may be run by itself and different configurations files are loaded and the log output is checked. However, more efficiently follow steps 001-002 now and then perform the later steps (003+) when running the ALG001 and ALG004 tests, since the same tests are being carried out.
Step | Direction | Expected Result | Pass/Fail Criteria or Comment |
---|---|---|---|
001 | Locate the Qc2 log file in $PREFIX/var/log/kvalobs and remove all entries: | – | – |
$ cd $PREFIX/var/log/kvalobs | NB PREFIX=/metno/kvalobs in local dev-vm116 installation, probably NULL for the debian roll-out | – | |
$ rm Qc2.log Qc2.log.? | – | ||
NB the “?” is to be typed | – | – | |
002 | start kvQc2 (either standalone or with ~/bin/kvQc2 e.g. see QC2-OPE-CFG) | – | – |
$ ls $PREFIX/var/log/kvalobs | The Qc2.log file has been created (e.g. see below) | – |
kvalobs@pak:~/var/log/kvalobs$ ls postgresql Qc2.log kvalobs@pak:~/var/log$ cat Qc2.log 20100325233426: INFO --------------- Qc2Work: starting work thread! 20100325233426: INFO --------------- New database connection (PostgreSQL) created! 20100325233426: DEBUG --------------- Created a new connection to the database! 20100325233426: INFO --------------- %%%%%%%%%%%%%%%%%%%%%%%%
003 | Monitor the contents of the logfile, e.g. with “tail -f Qc2.log” while the next steps are carried out. | – | – |
Hint: the logfiles rotate and tail -f will stall when a rotation occurs. Just cancel and restart the command. | – | – | |
004 | Unpack the following config files to the Qc2Config directory: | – | – |
alg001-qcd2027.cfg.gz | – | – | |
alg004.cfg.gz | – | – | |
The test database must contain corresponding data, e.g. see ALG001 and ALG004 | – | – | |
It is assumed that kvQc2 is still up and running! | |||
003 | In algoo1-qcd20027.cfg set RunAtHour and RunAtMinute to be a few minutes in the future (NB the clock time is UTC). Monitor the log file. | Typical output such as ALG001-LogFile-Output is observed. | – |
003 | In ALG004.cfg set RunAtHour and RunAtMinute to be a few minutes in the future (NB the clock time is UTC). Monitor the log file. | Typical output such as ALG004-LogFile-Output is observed. | – |
ALG001-LogFile-Output
20100325234714: INFO --------------- Case 1: Redistribute 20100325234714: INFO --------------- Redistribute Accumulations 20100325234751: INFO --------------- Redistribute Precipitation Writing Data -1 45350 2027-6-3 6:0:0 20100325234751: INFO --------------- Redistribute Precipitation Writing Data -1 45350 2027-6-5 6:0:0 20100325234751: ERROR --------------- Can't contact CORBA nameservice. Is the CORBA nameservice running. --------------- (EXCEPTION: Can't obtain a reference for 'kvServiceDataReady' --------------- from the CORBA nameserver!) 20100325234808: INFO --------------- Redistribute Precipitation Writing Data 0.9 41370 2027-6-8 6:0:0 20100325234808: ERROR --------------- Can't contact CORBA nameservice. Is the CORBA nameservice running. --------------- (EXCEPTION: Can't obtain a reference for 'kvServiceDataReady' --------------- from the CORBA nameserver!)
NB The CORBA error above is a result of running this test on a development machine with no CORBA running. The algorithm results are written to the database but the KvServiced is not informed due to no CORBA nameservice. The kvalobs Qc1 code that manages this handles the exception gracefully.
ALG004-LogFile-Output
20100326001754: INFO --------------- Case 4: ProcessUnitT 20100326001754: INFO --------------- ProcessUnitT 20100326001811: INFO --------------- ProcessUnitT Writing Data -6.3 98790 2024-3-30 4:0:0 20100326001829: INFO --------------- ProcessUnitT Writing Data -4.7 84700 2024-3-27 18:0:0 20100326001831: INFO --------------- ProcessUnitT Writing Data -3.7 84700 2024-3-27 13:0:0 20100326001836: INFO --------------- ProcessUnitT Writing Data -9.8 84700 2024-3-27 3:0:0 20100326001838: INFO --------------- ProcessUnitT Writing Data -2.1 98790 2024-3-26 22:0:0 20100326001857: INFO --------------- ProcessUnitT Writing Data -11.5 84700 2024-3-25 2:0:0 20100326001859: INFO --------------- ProcessUnitT Writing Data -4.1 98790 2024-3-24 23:0:0 20100326001903: INFO --------------- ProcessUnitT Writing Data -2.7 98790 2024-3-24 15:0:0 20100326001908: INFO --------------- ProcessUnitT Writing Data -32767 95350 2024-3-24 6:0:0
!!!! Look … something to follow up:
20100326001908: INFO --------------- ProcessUnitT Writing Data -32767 95350 2024-3-24 6:0:0
FIXED
kvalobs=# select * from data where stationid=95350 and obstime>'2024-03-24 04:00:00' and obstime<'2024-03-24 08:00:00' and paramid=211; stationid | obstime | original | paramid | tbtime | typeid | sensor | level | corrected | controlinfo | useinfo | cfailed -----------+---------------------+----------+---------+---------------------+--------+--------+-------+-----------+------------------+------------------+------------------------------------------------------------ 95350 | 2024-03-24 05:00:00 | -7.2 | 211 | 2024-03-24 04:49:35 | 311 | 0 | 0 | -7.2 | 1111200000000012 | 30000000000000C1 | QC1-4-211:1,hqc 95350 | 2024-03-24 06:00:00 | -32767 | 211 | 2024-03-24 06:33:36 | 311 | 0 | 0 | -7.6 | 1000501100000000 | 5894700000000041 | QC1-4-211:1,hqc,QC1-4-211:1 Qc2 UnitT corrected was:-32767 95350 | 2024-03-24 07:00:00 | -7.3 | 211 | 2024-03-24 11:50:47 | 311 | 0 | 0 | -7.3 | 1110200000000012 | 31000004000000C1 | QC1-4-211:1,hqc (3 rows)
In the example output the old corrected value was written to the logfile and not the new interpolated value. This has been corrected. This demonstrates the power of testing!
Added the following as a reminder to discuss!
The are algorithms that will terminate Qc2, e.g. see below. These can all be blocked for an operational release so that even if one writes the corresponding configuration file they will never run (until tested and released). However, only deploying the correct configuration files will also control this.
Here is an example.
Log file:
20100326000825: INFO --------------- Redistribute Precipitation Writing Data 2.1 53730 2027-12-30 6:0:0 20100326000825: INFO --------------- Redistribute Precipitation Writing Data 5.7 53730 2027-12-31 6:0:0 20100326000825: ERROR --------------- Can't contact CORBA nameservice. Is the CORBA nameservice running. --------------- (EXCEPTION: Can't obtain a reference for 'kvServiceDataReady' --------------- from the CORBA nameserver!) 20100326000924: INFO --------------- Case 3: Process4D
Qc2 Run View:
------------------------------------------------- Process Time: 2008-03-28 10:00:00 Station Id: 67280 INPUT 23 -11.3 2008-03-27 23:00:00 N: 0 Tseries Index: 1 HourDec: 23 Original: -11.3 Obstime: 2008-03-27 23:00:00 INPUT 24 -12.2 2008-03-28 00:00:00 N: 1 Tseries Index: 2 HourDec: 24 Original: -12.2 Obstime: 2008-03-28 00:00:00 INPUT 25 -13.5 2008-03-28 01:00:00 N: 2 Tseries Index: 3 HourDec: 25 Original: -13.5 Obstime: 2008-03-28 01:00:00 INPUT 26 -14 2008-03-28 02:00:00 N: 3 Tseries Index: 4 HourDec: 26 Original: -14 Obstime: 2008-03-28 02:00:00 INPUT 27 -32767 2008-03-28 03:00:00 INPUT 28 -32767 2008-03-28 04:00:00 INPUT 29 -32767 2008-03-28 05:00:00 INPUT 30 -32767 2008-03-28 06:00:00 INPUT 31 -32767 2008-03-28 07:00:00 INPUT 32 -32767 2008-03-28 08:00:00 INPUT 33 -32767 2008-03-28 09:00:00 INPUT 34 -32767 2008-03-28 10:00:00 INPUT 35 -32767 2008-03-28 11:00:00 INPUT 36 -32767 2008-03-28 12:00:00 INPUT 37 -32767 2008-03-28 13:00:00 INPUT 38 -32767 2008-03-28 14:00:00 INPUT 39 2.3 2008-03-28 15:00:00 N: 4 Tseries Index: 17 HourDec: 39 Original: 2.3 Obstime: 2008-03-28 15:00:00 INPUT 40 2.6 2008-03-28 16:00:00 N: 5 Tseries Index: 18 HourDec: 40 Original: 2.6 Obstime: 2008-03-28 16:00:00 INPUT 41 1.9 2008-03-28 17:00:00 N: 6 Tseries Index: 19 HourDec: 41 Original: 1.9 Obstime: 2008-03-28 17:00:00 INPUT 42 0.1 2008-03-28 18:00:00 N: 7 Tseries Index: 20 HourDec: 42 Original: 0.1 Obstime: 2008-03-28 18:00:00 INPUT 43 1 2008-03-28 19:00:00 N: 8 Tseries Index: 21 HourDec: 43 Original: 1 Obstime: 2008-03-28 19:00:00 INPUT 44 -1.2 2008-03-28 20:00:00 N: 9 Tseries Index: 22 HourDec: 44 Original: -1.2 Obstime: 2008-03-28 20:00:00 INPUT 45 0.5 2008-03-28 21:00:00 N: 10 Tseries Index: 23 HourDec: 45 Original: 0.5 Obstime: 2008-03-28 21:00:00 INPUT 46 0.5 2008-03-28 22:00:00 N: 11 Tseries Index: 24 HourDec: 46 Original: 0.5 Obstime: 2008-03-28 22:00:00 N: 11 1 4 17 24 HourDec from tt: 23 Corresponding Tseries Time 2008-03-27 23:00:00 Original -11.3 HourDec from tt: 24 Corresponding Tseries Time 2008-03-28 00:00:00 Original -12.2 HourDec from tt: 25 Corresponding Tseries Time 2008-03-28 01:00:00 Original -13.5 HourDec from tt: 26 Corresponding Tseries Time 2008-03-28 02:00:00 Original -14 HourDec from tt: 27 Corresponding Tseries Time 2008-03-28 03:00:00 Original -32767 HourDec from tt: 28 Corresponding Tseries Time 2008-03-28 04:00:00 Original -32767 HourDec from tt: 29 Corresponding Tseries Time 2008-03-28 05:00:00 Original -32767 HourDec from tt: 30 Corresponding Tseries Time 2008-03-28 06:00:00 Original -32767 HourDec from tt: 31 Corresponding Tseries Time 2008-03-28 07:00:00 Original -32767 HourDec from tt: 32 Corresponding Tseries Time 2008-03-28 08:00:00 Original -32767 HourDec from tt: 33 Corresponding Tseries Time 2008-03-28 09:00:00 Original -32767 HourDec from tt: 34 Corresponding Tseries Time 2008-03-28 10:00:00 Original -32767 HourDec from tt: 35 Corresponding Tseries Time 2008-03-28 11:00:00 Original -32767 HourDec from tt: 36 Corresponding Tseries Time 2008-03-28 12:00:00 Original -32767 HourDec from tt: 37 Corresponding Tseries Time 2008-03-28 13:00:00 Original -32767 HourDec from tt: 38 Corresponding Tseries Time 2008-03-28 14:00:00 Original -32767 HourDec from tt: 39 Corresponding Tseries Time 2008-03-28 15:00:00 Original 2.3 HourDec from tt: 40 Corresponding Tseries Time 2008-03-28 16:00:00 Original 2.6 HourDec from tt: 41 Corresponding Tseries Time 2008-03-28 17:00:00 Original 1.9 HourDec from tt: 42 Corresponding Tseries Time 2008-03-28 18:00:00 Original 0.1 HourDec from tt: 43 Corresponding Tseries Time 2008-03-28 19:00:00 Original 1 HourDec from tt: 44 Corresponding Tseries Time 2008-03-28 20:00:00 Original -1.2 HourDec from tt: 45 Corresponding Tseries Time 2008-03-28 21:00:00 Original 0.5 gsl: interp.c:83: ERROR: x values must be monotonically increasing Default GSL error handler invoked. Aborted