Differences

This shows you the differences between two versions of the page.

--- kvalobs:kvoss:system:qc2:test:downstream [2010-11-02 15:31:23]
paule
+++ kvalobs:kvoss:system:qc2:test:downstream [2022-05-31 09:29:32] (current)
@@ Line 1: / Line 1: @@
+====== kvqc2_1.0.9 Troubleshooting ======
+As of 25-11-2010, kvqc2-1.0.9 is in operation but still no data arrives at teh warehouse. Thanks to Bjorn for spotting this :-) !
+<code>
+Sendt: 25. november 2010 10:30:52
+Emne: Re: kvqc2_1.0.9
+Hei!
+Have done select in kvalobs DB and and checked in KDVH.
+Seems to me that nothing has been transfered to KDVH.
+Bjørn
+</code>
+====== Double Check dev-vm101 ======
+Test setup
+  * kvdatalistener running on dev-vm101
+  * listens to the kvServiced accrding to the setup in $HOME/etc/kvdatalistener.conf
+  * Check the ouput from kvqc2 and monitor the kvServiced.log
+  * Data picked up by kvdatalistener is also written to "rcvtest_data" in the kvalobs db. Børge has the version configured on dev-vm101 to only write Qc2 controlled records.
+^An algorithm is Run^
+Qc2:
+<code>
+Looking up object in CORBA nameservice: corbaname::corbans.met.no:2809#kvtest-dev-vm101/kvServiceDataReady
+Data input by kvQc2:
+-- ProcessUnitT Writing Data -6.4 17850 2010-11-25 9:0:0
+</code>
+A corresponding signal is observed in kvServiced.log (all this below is seen (partly a fact that DEBUG mode is on in dev-vm101 and not in production))
+<code>
+20101125201847: DEBUG (ServiceSubscriber)
+--------------- Closing the database connection!
+20101125202116: DEBUG (dataReady)
+--------------- New data from <UNKNOWN>!
+20101125202116: INFO (ServiceSubscriber)
+--------------- New database connection (PostgreSQL) created!
+20101125202116: DEBUG (ServiceSubscriber)
+--------------- Created a new connection to the database!
+20101125202116: DEBUG (ServiceSubscriber)
+--------------- DataReady received from <> (Unknown)!
+20101125202116: DEBUG (ServiceSubscriber)
+--------------- CALL DataSubscribers: stationID: 17850 obstime: 2010-11-25 09:00:00 typeID: 330
+20101125202116: DEBUG (service/getData)
+--------------- called ...
+20101125202116: DEBUG (service/getData)
+--------------- isMaxClientReached: # : 0 max: 10000
+20101125202116: INFO (service/getData)
+--------------- New database connection (PostgreSQL) created!
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: called ...
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- stationid: 17850 currentEndTime: 0000-00-00 --:--:-- endTime: 0000-00-00 --:--:-- iData: 0
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- select(17850, 2010-11-24 17:00:01, 2010-11-25 05:00:00
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- data: nElements=77
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- textData: nElements=0
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- DataIteratorImpl::findData: return TRUE
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[0].dataList.length()=9
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[1].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[2].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[3].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[4].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[5].dataList.length()=8
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[6].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[7].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[8].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[9].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[10].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList->length()=12
+20101125202116: DEBUG (service/DataIterator)
+--------------- text_data:
+20101125202116: DEBUG (service/DataIterator)
+--------------- No <textdata>!
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: called ...
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- stationid: 17850 currentEndTime: 2010-11-25 05:00:01 endTime: 2010-11-25 18:00:00 iData: 0
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- select(17850, 2010-11-25 05:00:01, 2010-11-25 17:00:00
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- data: nElements=52
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- textData: nElements=0
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- DataIteratorImpl::findData: return TRUE
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[0].dataList.length()=10
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[1].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[2].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[3].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[4].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[5].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList[6].dataList.length()=6
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList->length()=8
+20101125202116: DEBUG (service/DataIterator)
+--------------- text_data:
+20101125202116: DEBUG (service/DataIterator)
+--------------- No <textdata>!
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: called ...
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- stationid: 17850 currentEndTime: 2010-11-25 17:00:01 endTime: 2010-11-25 18:00:00 iData: 0
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- select(17850, 2010-11-25 17:00:01, 2010-11-25 18:00:00
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- data: nElements=0
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- textData: nElements=0
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- DataIteratorImpl::findData: return TRUE
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: End of data reached (return false)!
+20101125202116: DEBUG
+--------------- DataIteratorImpl::destroy: called!
+20101125202116: DEBUG
+--------------- DataIteratorImpl::destroy: leaving!
+20101125202116: DEBUG (service/getData)
+--------------- called ...
+20101125202116: DEBUG (service/getData)
+--------------- isMaxClientReached: # : 1 max: 10000
+20101125202116: INFO (service/getData)
+--------------- New database connection (PostgreSQL) created!
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: called ...
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- stationid: 17850 currentEndTime: 0000-00-00 --:--:-- endTime: 0000-00-00 --:--:-- iData: 0
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- select(17850, 2010-11-25 09:00:00, 2010-11-25 09:00:00
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- data: nElements=6
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- textData: nElements=0
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- DataIteratorImpl::findData: return TRUE
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: obsDataList->length()=1
+20101125202116: DEBUG (service/DataIterator)
+--------------- text_data:
+20101125202116: DEBUG (service/DataIterator)
+--------------- No <textdata>!
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: called ...
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: End of data reached (return false)!
+20101125202116: DEBUG
+--------------- DataIteratorImpl::destroy: called!
+20101125202116: DEBUG
+--------------- DataIteratorImpl::destroy: leaving!
+20101125202116: DEBUG (service/getData)
+--------------- called ...
+20101125202116: DEBUG (service/getData)
+--------------- isMaxClientReached: # : 2 max: 10000
+20101125202116: INFO (service/getData)
+--------------- New database connection (PostgreSQL) created!
+20101125202116: DEBUG (service/DataIterator)
+--------------- next: called ...
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- stationid: 17850 currentEndTime: 0000-00-00 --:--:-- endTime: 0000-00-00 --:--:-- iData: 0
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- select(17850, 2010-11-25 09:00:00, 2010-11-25 09:00:00
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- data: nElements=6
+20101125202116: DEBUG (service/DataIterator/findData)
+--------------- textData: nElements=0
+</code>
+The corresponding data is also written into the rcvtest_data table:
+kvalobs=# select * from rcvtest_data;
+<code>
+ stationid |       obstime       |     original      | paramid |       tbtime        | typeid | sensor | level |     corrected     |   controlinfo    |     useinfo      |      cfailed
+-----------+---------------------+-------------------+---------+---------------------+--------+--------+-------+-------------------+------------------+------------------+--------------------
+| 2010-11-25 09:00:00 |            -32767 |     211 | 2010-11-25 09:30:10 |    330 | 0      |     0 | -6.40000009536743 | 0000601100000000 | 5894700000000001 | QC1-4-211:1,QC2d-2
+</code>
+====== Listen to operations ======
+  * Update "$HOME/etc/kvdatalistener.conf" to listen to murky:
+<code>
+kvserver=kvalobs
+#kvserver=kvtest-dev-vm101
+</code>
+  * Run a check on murky (trigger from config file (file time set back afterwards)).
+Qc2 Output:
+<code>
+kvalobs@murky:/var/log/kvalobs$ tail -f Qc2.log
+--------------- Case 10: Single Linear
+20101125201217: INFO
+--------------- Single Linear
+20101125201218: INFO
+--------------- ProcessUnitT Writing Data 63.5 76905 2010-11-25 16:0:0
+20101125201218: INFO
+--------------- ProcessUnitT Writing Data 68 76906 2010-11-25 16:0:0
+20101125201219: INFO
+--------------- ProcessUnitT Writing Data 57.5 76906 2010-11-25 12:0:0
+20101125201219: INFO
+--------------- ProcessUnitT Writing Data 59.5 76905 2010-11-25 12:0:0
+20101125201220: INFO
+--------------- ProcessUnitT Writing Data 69.5 17090 2010-11-25 10:0:0
+20101125201220: INFO
+--------------- ProcessUnitT Writing Data 64.3 17850 2010-11-25 9:0:0
+kvalobs@murky:/var/log/kvalobs$
+</code>
+And the data arrives on dev-vm101:
+<code>
+kvalobs=# select * from rcvtest_data where paramid=262;
+ stationid |       obstime       | original | paramid |       tbtime        | typeid | sensor | level | corrected |   controlinfo    |     useinfo      |      cfailed
+-----------+---------------------+----------+---------+---------------------+--------+--------+-------+-----------+------------------+------------------+--------------------
+| 2010-11-25 16:00:00 |   -32767 |     262 | 2010-11-25 17:30:11 |     11 | 0      |     0 |      63.5 | 0000601100000000 | 5894700000000001 | QC1-4-262:1,QC2d-2
+| 2010-11-25 16:00:00 |   -32767 |     262 | 2010-11-25 17:30:11 |     11 | 0      |     0 |        68 | 0000601100000000 | 5894700000000001 | QC1-4-262:1,QC2d-2
+| 2010-11-25 12:00:00 |   -32767 |     262 | 2010-11-25 13:30:10 |     11 | 0      |     0 |      57.5 | 0000601100000000 | 5894700000000001 | QC1-4-262:1,QC2d-2
+| 2010-11-25 12:00:00 |   -32767 |     262 | 2010-11-25 13:30:10 |     11 | 0      |     0 |      59.5 | 0000601100000000 | 5894700000000001 | QC1-4-262:1,QC2d-2
+| 2010-11-25 10:00:00 |   -32767 |     262 | 2010-11-25 10:45:56 |    502 | 0      |     0 |      69.5 | 0000601100000000 | 5894700000000001 | QC1-4-262:1,QC2d-2
+(5 rows)
+kvalobs=# \q
+kvalobs@dev-vm101:~$
+</code>
+Double check that at least one of the rows is in rcvtest_data but not in the dev-vm101 data table!
+<code>
+kvalobs=# select * from rcvtest_data where paramid=262 and cfailed like '%QC2%' and obstime>'yesterday' and stationid=17090;
+ stationid |       obstime       | original | paramid |       tbtime        | typeid | sensor | level | corrected |   controlinfo    |     useinfo      |      cfailed
+-----------+---------------------+----------+---------+---------------------+--------+--------+-------+-----------+------------------+------------------+--------------------
+| 2010-11-25 10:00:00 |   -32767 |     262 | 2010-11-25 10:45:56 |    502 | 0      |     0 |      69.5 | 0000601100000000 | 5894700000000001 | QC1-4-262:1,QC2d-2
+(1 row)
+kvalobs=# select * from data where paramid=262 and cfailed like '%QC2%' and obstime>'yesterday' and stationid=17090;
+ stationid | obstime | original | paramid | tbtime | typeid | sensor | level | corrected | controlinfo | useinfo | cfailed
+-----------+---------+----------+---------+--------+--------+--------+-------+-----------+-------------+---------+---------
+(0 rows)
+</code>
+and did come from murky:
+<code>
+kvalobs@murky:/etc/kvalobs/Qc2Config$ psql kvalobs
+Welcome to psql 8.3.3, the PostgreSQL interactive terminal.
+Type:  \copyright for distribution terms
+       \h for help with SQL commands
+       \? for help with psql commands
+       \g or terminate with semicolon to execute query
+       \q to quit
+kvalobs=#  select * from data where paramid=262 and cfailed like '%QC2%' and obstime>'yesterday' and stationid=17090 and obstime='2010-11-25 10:00:00';
+ stationid |       obstime       | original | paramid |       tbtime        | typeid | sensor | level | corrected |   controlinfo    |     useinfo      |      cfailed
+-----------+---------------------+----------+---------+---------------------+--------+--------+-------+-----------+------------------+------------------+--------------------
+| 2010-11-25 10:00:00 |   -32767 |     262 | 2010-11-25 10:45:56 |    502 | 0      |     0 |      69.5 | 0000601100000000 | 5894700000000001 | QC1-4-262:1,QC2d-2
+(1 row)
+</code>
+====== OLD MATERIAL ======
 ====== Propagate Qc2 Data Downstream ======
@@ Line 74: / Line 370: @@
 This looks like it worked ... i.e. it did not come from murky! But we fiddled with HQC at the end of the day and did this trigger the transfer?
-====== Yes it works! ======
+====== Yes it works - but only when kv2kl is restarted ... ! ======
 The following contains a mixture of output (note before and after comman bug fix too!)