Date - 2001.05.02 Tester - S.T. Myers (AOC) with Lincoln Greenhill Platform - Linux (sandrock) Note: bugs are denoted by lines with prefix: >>>BUG: and queries are denoted by lines with prefix: >>>QUERY: while comments are prefixed by: >>>COMMENT: Some enhancement requests are given after >>>REQUEST: ------------------------------------------------------------------------------- GOAL: Try one of Lincoln's datasets from 1988 1. Date - 2001.05.02 Version - Stable (1.5 build 284) Data - /home/sandrock/smyers/Testing/May01/AC176/ Interactive mode. Trying to follow procedure outlined in the VLA part of Getting Results. ----------------- vlafillerfromtape ----------------- vlafillerfromtape(msname='ac176.ms', device='/dev/nst0', host='alcor', project='AC176', files=[8] ); try to use remote drive on isleta and alcor, but only get message - waiting for daemon ... sh: glishd: command not found Killed I have ssh permission so I dont understand why this doesnt work >>>NOTE: Ralph found problem in my .cshrc (it was exiting before making aipsinit definitions). ----------------- vlafillerfromdisk ----------------- tape drive on alcor mt -f /dev/nst0 setblk 0 mt -f /dev/nst0 rewind mt -f /dev/nst0 fsf 7 dd if=/dev/nst0 bs=26624 of=ac176.vla mt -f /dev/nst0 offline vlafillerfromdisk(msname='ac176.ms', project='AC176', filename='ac176.vla', host='gibbon', bandname='L'); Because this data is from 1988, we get warning about the filler not having been tested on revisions earlier than 23 (this data is 20). It gives that warning every record, which is very annoying. >>>BUG: It should not fill the logger with these warning messages every record. ----------------- ms.summary ----------------- MeasurementSet Name: /home/sandrock/smyers/Testing/May01/AC176/ac176.ms MS Version 2 Observer: unavailable Project: AC176 Observation: VLA(26 antennas) Fields: 3 Name: 3C286 RA: 13:31:08.29 Dec: +30.30.33.04 (J2000 ) Name: 1216+487 RA: 12:19:06.42 Dec: +48.29.56.18 (J2000 ) Name: N4258 RA: 12:18:57.56 Dec: +47.18.14.42 (J2000 ) Data records: 1837134 Total integration time = 26480 seconds Observed from 22-Mar-1988/06:44:15 to 22-Mar-1988/14:05:35 Data descriptions: 2 (2 spectral windows and 1 polarization setups) ID Ref.Freq #Chans Resolution TotalBW Correlations 1 1464.9 MHz 1 50000 kHz 50000 kHz RR LL RL LR 2 1514.9 MHz 1 50000 kHz 50000 kHz RR LL RL LR Antennas: 26 ID= 1-6: 5=VLA:W12, 7=VLA:W6, 12=VLA:W9, 1=VLA:W8, 9=VLA:W16, 8=VLA:W14, ID= 7-11: 4=VLA:W10, 10=VLA:W18, 28=VLA:W7, 26=VLA:E12, 25=VLA:E6, ID= 12-16: 20=VLA:E16, 14=VLA:E14, 23=VLA:E8, 18=VLA:E9, 24=VLA:E10, ID= 17-21: 13=VLA:E18, 19=VLA:E7, 17=VLA:N12, 11=VLA:N6, 2=VLA:N16, ID= 22-26: 6=VLA:N8, 21=VLA:N9, 3=VLA:N10, 22=VLA:N18, 27=VLA:N7 Tables(rows): (-1 = table absent) MAIN(1837134) ANTENNA(26) DATA_DESCRIPTION(2) DOPPLER(-1) FEED(26) FIELD(3) FLAG_CMD(0) FREQ_OFFSET(-1) HISTORY(0) OBSERVATION(1) POINTING(0) POLARIZATION(1) PROCESSOR(0) SOURCE(-1) SPECTRAL_WINDOW(2) STATE(0) SYSCAL(-1) WEATHER(-1) We see "lister" function under the list. Try it. >>>BUG: starttime and stoptime should default sensibly to whats in the ms starttime='1988/03/22/06:44:15' stoptime='1988/03/22/14:05:35' - LocalExec::SetStatus: abnormal child termination for /home/cluster/aips++/stable/linux_gnu/bin/ms Server 'ms' has failed unexpectedly! You will need to create the relevant tool again. If that causes unexpected behavior, please restart AIPS++ Please submit a bug-report using bug() if you can reproduce the problem. >>>BUG: ----------------- flagger ----------------- run flagger.auto() Flagging 136084 rows ------------------ msplot -> flagger1 ------------------ - LocalExec::SetStatus: abnormal child termination for /home/cluster/aips++/stable/linux_gnu/bin/ms Server 'ms' has failed unexpectedly! You will need to create the relevant tool again. If that causes unexpected behavior, please restart AIPS++ Please submit a bug-report using bug() if you can reproduce the problem. restart aips++, now seems to work ok amp vs. uvdist looks funny (stuff at 150Jy). amp vs. time iterate over ant1, looks like this stable doesnt incorporate the ability to pause between iterations. Also, plot only shows the first few mintues of the dataset. Tried to stop the plotting, DISMISS only got rid of the plot window. Cannot stop. >>>BUG: should be able to abort this task cleanly amp vs. time for each field. for field=2 see low points in second scan when all data plotted, but dont see this when iterating over ant1. Why? found really bad amps in field=3 around 09:10 -> FLAG >>>BUG: the plots should re-autoscale correctly after data has been flagged (or option to not include flagged data in autorange). End session - do not apply flags (revert to previous flags). 1. Date - 2001.05.02 Version - Weekly (1.5 build 354) Data - /home/sandrock/smyers/Testing/May01/AC176/ Interactive mode. ------------------ msplot -> flagger2 ------------------ timing: 1837134 rows in 6m57s Note: this seems much longer than it took in stable (what changed?) timing: took 2m to select data for amp vs. uvdist plot (RR/LL, Spw1, Fld3) (1464495 pts) plot vs. time FLAG time around 09:10 for Field 3 (N4258), in each Spwid get same plot scale problem as before go back to Field 2 (1216+487) - clearly low amps (~0.02) in scan 2. try iterating - aha, the time scale covers only the first scan now. >>>BUG: Default time range plotted in iterative mode is wrong, shows only first scan even when I specify a time range in the Data Selection. It will not let me insert the timerange into the X plot limits and even using the RANGE button fails with Could not insert '1988/03/22/06:53:15.000 1988/03/22/06:56:05.000' Note that the right range is 1988/03/22/06:44:15.000 1988/03/22/14:05:35.000 [Bug Submitted as AOCso02590] try z-display on Field 2, spwid=[1,2] crashes with error Need to select one data_desc_id only when ifrAxis==True Illegal z axis amplitude Supplied CoordinateSystem and image shape are inconsistent Caught an exception! Event type=create exception=Wed May 2 20:32:19 2001 SEVERE image::imagefromaarray (file /aips++/weekly/code/trial/implement/Images/DOimage.cc, line 234) ObjectID=[sequence=10 host=sandrock pid=24599 time=988835539]: Supplied CoordinateSystem and image shape are inconsistent Failed to construct image:Caught an exception! Event type=create exception=Wed May 2 20:32:19 2001 SEVERE image::imagefromaarray (file /aips++/weekly/code/trial/implement/Images/DOimage.cc, line 234) ObjectID=[sequence=10 host=sandrock pid=24599 time=988835539]: Supplied CoordinateSystem and image shape are inconsistent Failed to construct image:Caught an exception! Event type=create exception=Wed May 2 20:32:19 2001 SEVERE image::imagefromaarray (file /aips++/weekly/code/trial/implement/Images/DOimage.cc, line 234) ObjectID=[sequence=10 host=sandrock pid=24599 time=988835539]: Supplied CoordinateSystem and image shape are inconsistent and in the glish window warning, operand to .time_axis is not a record warning, operand to .MJDseconds is not a record warning, operand to .z is not a record warning, operand to .axis_info is not a record warning, operand to .freq_axis is not a record warning, operand to .chan_freq is not a record warning, operand to .z is not a record warning, loop/break/return does not make sense inside whenever private.action[go]->.press do {{ { hung - had to delete the mymsplot tool in the Tool Manager window of open tools... start again ------------------ imager.setjy ------------------ timing: took 3m7s to init MODEL_DATA, CORRECTED_DATA and IMAGING_WEIGHT columns ok:=imagr.setjy(fieldid=1, spwid=-1, fluxdensity=[-1.0]); Claims to have finished, but after gave severe error: Exception: Table /export/home/sandrock/smyers/Testing/May01/AC176/ac176.ms.3C286.spw0.tempcl cannot be deleted: table is still open in this process Exception: ScalarMeasColumn::put() measure has a frame. Illegal for variable reference column. Did not report the flux used? Shouldnt it? But looked at ms in catalog, and see that 14.511 is now in the MODEL_DATA column. The effects of this error are unknown... >>>NOTE: Athol mentioned this was fixed recently. Probably benign but should beware. >>>NOTE: Turns out we should have setjy on the other fieldids also to set them to 1 Jy. I got distracted by the bug and forgot to do the second part (actually should have just set fieldid=-1 and been done with this. ------------------ calibrater ------------------ 3c286 in C-array L-band calib.setdata(mode="none" , nchan=1, start=1, step=1, mstart=[value=0.0, unit="km/s" ], mstep=[value=0.0, unit="km/s" ], uvrange=[0,18], msselect='FIELD_ID==1'); calib.setsolve(type="G" , t=60, preavg=0.0, phaseonly=F, refant=20, table="ac176.calib" , append=F); >>>QUERY: What happens if you default t=0.0? What if t is longer than a scan? calib.solve() By selection 1837134 rows are reduced to 25350 Starting calibrater::solve Initializing solvable electronic gain terms (G-matrix) For interval of 60 seconds, found 16 slots Solving for G G Jones Slot=1, 3C286, spw=1: 22-Mar-1988/06:44:00 to 22-Mar-1988/06:44:59 G Jones Sum of weights is zero G Jones Slot=2, 3C286, spw=1: 22-Mar-1988/06:45:00 to 22-Mar-1988/06:45:59 G Jones Sum of weights is zero G Jones Slot=3, 3C286, spw=1: 22-Mar-1988/06:46:00 to 22-Mar-1988/06:46:59 G Jones Sum of weights is zero G Jones Slot=4, 3C286, spw=1: 22-Mar-1988/06:47:00 to 22-Mar-1988/06:47:59 G Jones Initial fit per unit weight = 14.6781 Jy, sum of weights = 2.22099e+07 G Jones Final fit per unit weight = 0.224337 Jy after 7 iterations G Jones Slot=5, 3C286, spw=1: 22-Mar-1988/06:48:00 to 22-Mar-1988/06:48:59 G Jones Initial fit per unit weight = 1.98863 Jy, sum of weights = 6.36888e+08 G Jones Final fit per unit weight = 0.326947 Jy after 8 iterations G Jones Slot=6, 3C286, spw=1: 22-Mar-1988/06:49:00 to 22-Mar-1988/06:49:59 G Jones Initial fit per unit weight = 14.6062 Jy, sum of weights = 2.0612e+08 G Jones Final fit per unit weight = 0.228488 Jy after 7 iterations G Jones Slot=7, 3C286, spw=1: 22-Mar-1988/06:50:00 to 22-Mar-1988/06:50:59 G Jones Initial fit per unit weight = 2.00814 Jy, sum of weights = 6.38778e+08 G Jones Final fit per unit weight = 0.327335 Jy after 8 iterations G Jones Slot=8, 3C286, spw=1: 22-Mar-1988/06:51:00 to 22-Mar-1988/06:51:59 G Jones Initial fit per unit weight = 2.01262 Jy, sum of weights = 1.07851e+08 G Jones Final fit per unit weight = 0.159403 Jy after 8 iterations G Jones Slot=9, 3C286, spw=2: 22-Mar-1988/06:44:00 to 22-Mar-1988/06:44:59 G Jones Sum of weights is zero G Jones Slot=10, 3C286, spw=2: 22-Mar-1988/06:45:00 to 22-Mar-1988/06:45:59 G Jones Sum of weights is zero G Jones Slot=11, 3C286, spw=2: 22-Mar-1988/06:46:00 to 22-Mar-1988/06:46:59 G Jones Sum of weights is zero G Jones Slot=12, 3C286, spw=2: 22-Mar-1988/06:47:00 to 22-Mar-1988/06:47:59 G Jones Initial fit per unit weight = 1.96755 Jy, sum of weights = 1.99035e+07 G Jones Final fit per unit weight = 0.901267 Jy after 53 iterations G Jones Slot=13, 3C286, spw=2: 22-Mar-1988/06:48:00 to 22-Mar-1988/06:48:59 G Jones Initial fit per unit weight = 2.43655 Jy, sum of weights = 5.5938e+08 G Jones Final fit per unit weight = 0.891463 Jy after 45 iterations G Jones Slot=14, 3C286, spw=2: 22-Mar-1988/06:49:00 to 22-Mar-1988/06:49:59 G Jones Initial fit per unit weight = 1.97127 Jy, sum of weights = 1.8128e+08 G Jones Final fit per unit weight = 0.877924 Jy after 46 iterations G Jones Slot=15, 3C286, spw=2: 22-Mar-1988/06:50:00 to 22-Mar-1988/06:50:59 G Jones Initial fit per unit weight = 2.40779 Jy, sum of weights = 5.60845e+08 G Jones Final fit per unit weight = 0.886218 Jy after 44 iterations G Jones Slot=16, 3C286, spw=2: 22-Mar-1988/06:51:00 to 22-Mar-1988/06:51:59 G Jones Initial fit per unit weight = 2.45672 Jy, sum of weights = 9.47975e+07 G Jones Final fit per unit weight = 0.893095 Jy after 44 iterations Storing G matrix in table ac176.calib Finished calibrater::solve 14.32 real 11.8 user 0.76 system >>>BUG: Instead of reporting every slot solution, it should give a readable summary of solution quality. note that the solutions in spw=2 took 40+ iterations, while spw=1 took only 8 - bad sign calib.setdata(mode="none" , nchan=1, start=1, step=1, mstart=[value=0.0, unit="km/s" ], mstep=[value=0.0, unit="km/s" ], uvrange=0, msselect='FIELD_ID==2'); calib.setsolve(type="G" , t=60, preavg=0.0, phaseonly=F, refant=20, table="ac176.calib" , append=F); calib.solve() By selection 1837134 rows are reduced to 193050 Starting calibrater::solve Initializing solvable electronic gain terms (G-matrix) For interval of 60 seconds, found 120 slots Solving for G ... G Jones Slot=120, 1216+487, spw=2: 22-Mar-1988/14:05:00 to 22-Mar-1988/14:05:59 G Jones Initial fit per unit weight = 0.133746 Jy, sum of weights = 2.10413e+08 G Jones Final fit per unit weight = 0.0511987 Jy after 46 iterations G Jones Did not converge for 6 time intervals Storing G matrix in table ac176.calib Finished calibrater::solve 396.7 real 363.76 user 10.2 system timing: looks like it takes around 1-3 secs per slot. excessive? note that there were 46 iterations in slot 120! >>>BUG: There appears to be overhead in reporting solutions each slot - it seems to take about 1s even for slots with weight=0, just over a second for slots with about 10 iterations, up to 3 sec for 40+ iterations (see example above). Should have option to turn off logging of each slot and only give summary. [Submitted as AOCso02589] If found an error listed in the glish window, I dont know where it came from: - "synclistboxes.g", line 391: error, self->[$name] does not have a string-valued index "synclistboxes.g", line 391: error, ->* illegal for sending an event ignore for now calib.plotcal(tablename='ac176.calib') calib.fluxscale(tablein='ac176.calib', tableout='ac176.calout', reference='3C286', transfer=['1216+487'] ) Flux density for 1216+487 (spw=1) is: inf +/- nan Jy Flux density for 1216+487 (spw=2) is: inf +/- nan Jy oops - append was FALSE in setsolve so 3C286 was overwritten go back and redo 3C286, but with append=true calib.setdata(mode="none" , nchan=1, start=1, step=1, mstart=[value=0.0, unit="km/s" ], mstep=[value=0.0, unit="km/s" ], uvrange=[0,18], msselect='FIELD_ID==1'); calib.setsolve(type="G" , t=60, preavg=0.0, phaseonly=F, refant=20, table="ac176.calib" , append=T); calib.solve() calib.fluxscale(tablein='ac176.calib', tableout='ac176.calout', reference='3C286', transfer=['1216+487'] ) Flux density for 1216+487 (spw=1) is: 0.421 +/- 0.003 Jy Flux density for 1216+487 (spw=2) is: 0.053 +/- 0.000 Jy what happened to spw=2? maybe thats why solutions took 40+ iterations for spw=2 but only 8 for spw=1. >>>NOTE: This behavior is almost certainly due to our incorrect running of setjy (helped by the bug). Will go back and redo later. ------------------ msplot -> flagger3 ------------------ try to see whats bad with spw=2 for field 1 nothing obvious in amplitudes try to choose baseline 1-20 for phases, but baseline chooser came up blank worked second time Very strange - looks like there is a big phase ramp for (almost all) baselines in RR while LL phases are flat across the scan. Like a bogus delay was set in the RR for this source. But this was in SPW=1, not 2! ------------------ calibrater (again) ------------------ Looks like we should, in the interests of speed, just use the first table for 1216 assumed 1 Jy (instead of 0.4 Jy) and apply it to the target calib.setdata(mode="none" , nchan=1, start=1, step=1, mstart=[value=0.0, unit="km/s" ], mstep=[value=0.0, unit="km/s" ], uvrange=0, msselect='FIELD_ID==2 && FIELD_ID==3'); It seems to be stuck - keeps saying stuff like Selection is empty: reverting to sorted MeasurementSet By selection 1837134 rows are reduced to 372 and cant get out of this even by resetting string. Try restarting calibrater (and do the Boolean right!) calib.setdata(mode="none" , nchan=1, start=1, step=1, mstart=[value=0.0, unit="km/s" ], mstep=[value=0.0, unit="km/s" ], uvrange=0, msselect='FIELD_ID==2 || FIELD_ID==3'); By selection 1837134 rows are reduced to 1809756 calib.setapply(type='G', table='ac176.calib', select='FIELD_ID==2'); >>>BUG: Functions like setapply (and setsolve) should give some indication in the log that they actually have been done! Looks like there is no choice in interpolation, and the interpolation (and action of setting the interval) is not explained in the User Reference. >>>REQUEST: There should be more choice in interpolation in setapply, and what it actually does should be better documented. calib.correct(); timing: took over 19 minutes when I aborted! Note - first time I mistakenly applied the non-existent T table (bad default from when I had to restart calibrater). Could it be made to know that there was no nontrivial T table to be applied in this table? Seems reasonable. oading G table from ac176.calib Finished calibrater::correct 2436.39 real 758.01 user 400.6 system timing: took 40m37s to apply table! >>>BUG: This is just way too long! Is there any way to speed this up? calib.done(); ------------------ imager ------------------ imgr.setdata(fieldid=3, mode='none', nchan=1, start=1, step=1, spwid=1); Selecting on field and spectral window ids No selection string given By selection 1837134 rows are reduced to 808353 imagr.setimage(nx=512, ny=512, cellx='3.0arcsec', celly='3.0arcsec', stokes='I', fieldid=3, spwid=1, start=1, step=1, nchan=1, mode='channel'); imagr.makeimage(image='n4258.dirty',type='corrected') Wow - this looks pretty cool, you can see the arms and lots of point sources! In spite of the crappy calibration... imagr.makeimage(image='n4258.model',type='model') imagr.makeimage(image='n4258.psf',type='psf') imagr.fitpsf(psf='n4258.psf') Fitting to psf Beam fit: 19.0889 by 16.1724 (arcsec) at pa 90.0386 (deg) Could have used 4" cells. Lets get gutsy and try multiscale clean to show Lincoln something new. imagr.setscale() imagr.clean(algorithm='multiscale', niter=1000, gain=0.1, model='n4258.model', image='n4258.restored', residual='n4258.residual'); Finished imager::clean 584.73 real 383.28 user 104.88 system Model image seemed to consist of point source at center??? End of day - quit for now. Post-Mortem: It didn't work too badly. The worst thing was the slow performance of calibrater and still the pain in editing in msplot. I need to go back and do the setjy right also, which will fix a number of problems. This is a good dataset to test with and so I will run it through aips as a check.