0000190: During observations of > 24 hrs, the writing of data to the MS crashes after 24 hrs - WSRT Issue Tracker

0000190: During observations of > 24 hrs, the writing of data to the MS crashes after 24 hrs

Viewing Issue Simple Details [ Jump to Notes ]

[ Issue History ] [ Print ]

ID

Category

Severity

Reproducibility

Date Submitted

Last Update

0000190

[TMS]

minor

always

25-11-09 15:26

14-06-10 07:55

Reporter

Arno Schoenmakers

View Status

public

Assigned To

Arno Schoenmakers

Priority

normal

Resolution

open

Status

closed

Summary

0000190: During observations of > 24 hrs, the writing of data to the MS crashes after 24 hrs

Description

In a large mosaic for VLBI it was observed that 24 hrs after the start of an observation, the system started to create many empty MSes.

Investigation revealed that for some reason the counter that counts the number of 10-sec intervals of data in the observation was set to -4 after 24 hrs. This caused ProcessDZB to not understand the order of data it received anymore. And so it stopped to dirty way. In this case, ReadDZB is not able to start a fully working ProcessDZB anymore (hung shared memory, etc.)

Additional Information

Hoi,

op 20 November is iets vreemds gebeurd tijdens een meting 10905255. De sample counter van ReadDZB wordt tijdens de meting gezet op -4... Agv daarvan crashte de hele santekraam rond ProcessDZB want die snapte er geen biet meer van.

Uit de ReadDZB logfile:

2 [11/20/2009 08:06:30] TMSReadDZBTransfer::nextSample - Added sample 8635 for DZB Tick 15727 (UT 11/20/2009 08:06:10) to Sh
ared memory buffer
2 [11/20/2009 08:06:30] TMSReadDZBTransfer::nextSample - Total number of samples processed now: 8635
1 [11/20/2009 08:06:30] TMSReadDZB::handleSample - INFO: Obtained succesfully data sample 8635
2 [11/20/2009 08:06:31] TMSReadDZB::handleDatabaseEvent - Received DevTick 2920 (RTStatus: Observing)
2 [11/20/2009 08:06:31] TMSReadDZBTransfer::nextSample - Waiting for new data from DZB
2 [11/20/2009 08:06:41] TMSReadDZBTransfer::nextSample - Acquired a data sample with DZB Tick 15728
2 [11/20/2009 08:06:41] TMSReadDZBTransfer::nextSample - Added sample -4 for DZB Tick 15728 (UT 11/20/2009 08:06:20) to Shared memory buffer

Nou is dit precies 24 uur na de start van de meting. Nadere inspectie van de meting leert dat dit een > 24 hrs positie mosaic meting is. Ik weet niet in hoeverre dit soort metingen getest of mogelijk is, maar er gaat iets helemaal mis in de tijdhuishouding. Het systeem denkt blijkbaar dat de starttijd en dus de samplecounters die ReadDZB gebruikt na 24 uur gereset moeten worden, vandaar opeens die -4; sample 0 zou dan weer samenvallen met de nieuwe starttijd.

Hans, jij hebt dit ooit ingebouwd, wat weet jij nog?

OCSinstrConfig logfile laat zien:

2 [11/20/2009 08:06:00] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2916 Status running
2 [11/20/2009 08:06:10] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2917 Status running
2 [11/20/2009 08:06:20] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2918 Status running
2 [11/20/2009 08:06:30] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2919 Status running
2 [11/20/2009 08:06:30] TMSRPointingWindow::doAdjust - True start time : 11/20/2009 08:07:10
2 [11/20/2009 08:06:30] TMSRPointingWindow::doAdjust - Sync start time : 11/19/2009 08:00:00
2 [11/20/2009 08:06:30] TMSRFrequencyWindow::doAdjust - True start time : 11/20/2009 08:07:10
2 [11/20/2009 08:06:30] TMSRFrequencyWindow::doAdjust - Sync start time : 11/20/2009 08:07:10
2 [11/20/2009 08:06:40] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2920 Status running
2 [11/20/2009 08:06:50] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2921 Status running
2 [11/20/2009 08:07:00] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2922 Status running
2 [11/20/2009 08:07:10] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2923 Status running
1 [11/20/2009 08:07:10] TMSRTSystem::doAdjust - INFO: Setting StartTime to: 2009/11/20 08:07:10
2 [11/20/2009 08:07:20] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2924 Status running
2 [11/20/2009 08:07:30] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2925 Status running
2 [11/20/2009 08:07:40] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2926 Status running
2 [11/20/2009 08:07:50] TMSOcsInstrConfig::handleRtDbEvent - ClockTick 2927 Status running

Arno

Relationships

Notes
(0000201) Arno Schoenmakers 25-11-09 15:28	Hans van Someren-Greve heeft dit onderzocht en begrepen waar de fout zit. Omdat testen moeilijk is, is hij aan het proberen een offline test op te zetten met ProcessDummy om te zien of hij een ingebouwde oplossing kan testen zonder telescooptijd te gebruiken. Als dit goed werkt, kan de bugfix in het systeem worden gezet. Ik zal Hans vragen de oplossing te documenteren.

(0000202) Arno Schoenmakers 30-11-09 07:52	Hans vSG heeft de code waar het probleem zit aangepast en voorzover mogelijk offline getest; de echte test komt pas over twee weken als er weer een > 24 uurs mosaic waarneming ingescheduled staat. Tot die tijd blijft de status op 'test'

(0000203) Arno Schoenmakers 01-12-09 07:57	Observers, Arno, Today (30-11-2009) i replaced the program OcsInstrConfig. The changes are : 1) It is possible to observe for more than 24 hours, and produce a good MS. (But it stille has to be proven.) 2) The gradient mode has been removed. Hans

Issue History
Date Modified	Username	Field	Change
25-11-09 15:26	Arno Schoenmakers	New Issue
25-11-09 15:28	Arno Schoenmakers	Note Added: 0000201
25-11-09 15:28	Arno Schoenmakers	Assigned To	=> Arno Schoenmakers
25-11-09 15:28	Arno Schoenmakers	Status	new => progressing
30-11-09 07:52	Arno Schoenmakers	Note Added: 0000202
01-12-09 07:57	Arno Schoenmakers	Note Added: 0000203
01-12-09 07:57	Arno Schoenmakers	Status	progressing => resolved
14-06-10 07:55	Arno Schoenmakers	Status	resolved => closed