Testing CMU version of LBC tracking

On Sky 20141224

Barry used it on-sky on 24-Dec-2014.

Four crashes in TCS processing, all in cleanup of the result object. Ignore this for now - there's nothing driving the move to Ice.

2014-12-24 00:40:37.08039 core.30705
2014-12-24 00:46:21.6027 core.17927
2014-12-24 00:50:31.1083 core.18819
2014-12-24 00:54:54.8221  core.19486

(gdb) where
#0  0x00b0d424 in __kernel_vsyscall ()
#1  0x00520b11 in raise () from /lib/libc.so.6
#2  0x005223ea in abort () from /lib/libc.so.6
#3  0x005609d5 in __libc_message () from /lib/libc.so.6
#4  0x00566e31 in malloc_printerr () from /lib/libc.so.6
#5  0x0808c3ba in Result_destroy (res=0x831eeb0) at src/tcs/ICE_ANSI-C_bridge.cpp:1264
#6  0x0808c28f in fillResultStruct (sres=..., res=...) at src/tcs/ICE_ANSI-C_bridge.cpp:1224
#7  0x0808d4a9 in AMI_IIFServer_PresetTelescopeI::ice_response (this=0xabb00bc0, res=...) at src/tcs/ICE_ANSI-C_bridge.cpp:199
#8  0x080fc1e7 in lbto::AMI_IIFServer_PresetTelescope::__response (this=0xabb00bc0, __ret=...) at ./IIFServer.h:1479
#9  0x08134543 in lbto::CallbackNC_IIFServer_PresetTelescope<lbto::AMI_IIFServer_PresetTelescope>::__completed (this=0xabb006a8, 
    __result=...) at ./IIFServer.h:9403
#10 0x06bcff0d in Ice::AsyncResult::__response (this=0xabb0073c) at OutgoingAsync.cpp:314
#11 0x06bd25cd in IceInternal::OutgoingAsync::__finished (this=0xabb00738, is=...) at OutgoingAsync.cpp:731
#12 0x06b33993 in Ice::ConnectionI::dispatch (this=0xabb01410, startCB=..., sentCBs=std::vector of length 0, capacity 0, 
    compress=0 '\000', requestId=4, invokeNum=0, servantManager=..., adapter=..., outAsync=..., stream=...) at ConnectionI.cpp:1469
#13 0x06b3373e in Ice::ConnectionI::message (this=0xabb01410, current=...) at ConnectionI.cpp:1437
#14 0x06c4dabc in IceInternal::ThreadPool::run (this=0xb0801360, thread=...) at ThreadPool.cpp:624
#15 0x06c4f4af in IceInternal::ThreadPool::EventHandlerThread::run (this=0xaa900560) at ThreadPool.cpp:1097
#16 0x001f5baa in startHook (arg=0xaa900560) at Thread.cpp:413
#17 0x0021bb39 in start_thread () from /lib/libpthread.so.0
#18 0x005d8d6e in clone () from /lib/libc.so.6
(gdb) quit
[root@cmu current]# cd src

For all of them, the last thing in the log was:
ROTATOR           loading tracking trajectory start...   

Restarted for them without the Ice TCS version at 00:59:44.

One crash in createTmpFITS1:
 294273024 2014-12-24 03:55:19.4686  core.21412

Last thing in the log:

2014/12/24 03:55:19.128323 N R TRACKERS IA       assignOutImageNext reading catalog file /images/IA/track/r_image1.cat
2014/12/24 03:55:19.128407 N R TRACKERS IA          read star 1  1 1271.121000 192.827000 6.940000 395561.200000
2014/12/24 03:55:19.128448 N R TRACKERS IA       assignOutImageNext: Selected 1 Good Sources in CHIP 1
2014/12/24 03:55:19.128501 N R TRACKERS IA       Found a Guide Source (1.000 Threshold): XCENTR = 1270.379000  YCENTR = 196.113000

Barry wrote at 04:17UTC:
I'm doing a DOFPIA again before iteration #3 for Christian's program. I've noticed twice tonight that the STOP button didn't stop the OB. The first time happened during skyflats, and it finished the OB. The second was just about 5min ago when I loaded the OB to do DOFPIA. It kept going on the exposures while DOFPIA was running. Once I finish DOFPIA maybe we should revert.
-Barry

Version 2.02 was restarted at 04:25UTC.

Each STOP command had the same entries in the log:

2014/12/24 01:05:02.396896 N -                   received >STOP< command from 192.168.58.33 address
2014/12/24 01:05:02.397001 N -                   executing STOP command ...
2014/12/24 01:05:02.397077 N -                   Stop signal to IIF functions
2014/12/24 01:05:03.741602 N -                   starting dithering step 4/5
2014/12/24 01:05:03.747373 N -                   executing PLAY command stopped
2014/12/24 01:05:03.747709 N -                   executing PLAY command completed
2014/12/24 01:05:05.673886 N -                   Stop signal to IIF functions removed
2014/12/24 01:05:05.674368 N -                   executing STOP command completed

same at 2014/12/24 01:32:26
        2014/12/24 01:53:09
        2014/12/24 02:23:08
        2014/12/24 03:11:20
        2014/12/24 03:11:29
        2014/12/24 04:12:21
        2014/12/24 04:12:41

At the time Barry complained there was also a PAUSE executed:
2014/12/24 04:12:20.089885 N -                   received >PAUSE< command from 192.168.58.33 address
2014/12/24 04:12:20.089936 N -                   executing PAUSE command 


Also - why didn't we ever perform active optics??

In the old code, it is performed right after the stop start log message. But, in the new, I don't see it get executed. OOPS - bug in the new trackers code, checking for STOP and not doing active optics. But, it actually ONLY OCCURS on the stop command from channel PresetExposeSave .

2014/12/24 02:30:36.784351 N R TRACKERS          performing guiding and Active Optics correction with a 8.000 sec exposure
....
2014/12/24 02:34:25.479969 N R TRACKERS          TCS IIF_OffsetGuiding by (-0.000025612723256deg,+0.000011915590036deg) start
2014/12/24 02:34:30.506804 N R TRACKERS          TCS IIF_OffsetGuiding completed
2014/12/24 02:34:33.417263 N R TRACKERS          >>> stop start
2014/12/24 02:34:33.421280 N R TRACKERS          >>> expose completed
2014/12/24 02:34:33.449057 N R TRACKERS          >>> stop completed
2014/12/24 02:34:33.449074 N R TRACKERS          >>> resume start
2014/12/24 02:34:33.479453 N R TRACKERS          >>> resume completed
But all it is based on is the GUIDINGAO flag, which should be set because we see the initial "Active Optics correction" message (above).

There are also some "no file found" complaints from both track first and track next:
2014/12/24 02:32:36.393699 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 02:32:37.393845 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 02:32:38.393991 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 02:32:39.394154 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 02:32:40.394316 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 02:40:14.983924 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 02:40:15.984107 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 02:40:16.984265 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 02:40:17.984397 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 02:40:18.984543 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 02:43:09.507117 W R TRACKERS IA       ... IATrackingFirst no file, sleeping 1 sec
2014/12/24 03:01:21.588761 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:01:39.990031 N B TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:01:40.990194 N B TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:01:41.990393 N B TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:01:42.990545 N B TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:01:43.990689 N B TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:02:49.510730 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:02:50.511011 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:02:51.511214 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:02:52.511379 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:02:53.511530 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:06:47.389487 W B TRACKERS IA       ... IATrackingFirst no file, sleeping 1 sec
2014/12/24 03:10:16.919023 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:31:44.042820 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:31:45.042955 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:31:46.043075 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:31:47.043190 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 03:31:48.043308 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
2014/12/24 04:07:51.933487 N R TRACKERS IA       ... IATrackingNext no file, sleeping 1 sec
Found a bug in that stuff - it would try 5 times and then just exit normally instead of failing after the 5 tries. We're getting the files from /newdata so sometimes it must just take a little more time frown, sad smile

Topic revision: r4 - 02 Sep 2015, KelleeSummers
This site is powered by FoswikiCopyright © by the contributing authors. All material on this collaboration platform is the property of the contributing authors.
Ideas, requests, problems regarding Foswiki? Send feedback