iraf.net

Hello,
I am running IRAF in Cygwin and it seems that for image files greater than a certain critical size on disk (a little over 9M, things slow way down. This is an either/or thing, not a more-or-less thing. For example, a simple task like imhead executes as one would expect if the file is slightly under than this critical size, while if the file is even slightly larger, it takes about 4 seconds or so to execute. Other tasks that use image files seem to do the same thing (implot, ccdproc, imarith are some I've tried). As far as I can tell, all tasks seem to execute properly - there's just this extra time delay.I did some trial and error tests, and it seems to be size on the disk, not number of pixels. I straced 2 versions of imhead executions, one with the delay and one without. It seems like Cygwin is losing the Winsock and is taking time to reestablish it. The traces were identical except for three sections where the same basic things happen. I've pasted in at the end of thsi post the section of the strace that only apperas in the run with the delay.Some other clues -- this seems to only happen with fits files. If I rfits the images in as imh I don't seem to get these delays in execution (although I haven't done any straces yet). Also, when I do things with the files directly with Cygwin (not through IRAF) I don't notice anything strange.I have tried this with three different machines, two with XP and one with Windows 7, and two versions of Cygwin (1.5 and 1.7), and the same thing seems to be happening with all of them. Of course, one common factor is that the same idiot (me) installed both cygwin and iraf on all three machines, so perhaps I've done something stupid . . . .I would like to resolve this, as I would like to work directly with the FITS images. So any hints anyone can give me would be appreciated!Thanks!
JohnSection of the strace follows. The part that is different starts at 19102228 and ends at 20193889.
59 19102030 [main] x_images.e 6036 fhandler_base::close: closing '/home/iraf/images/test4.fits' handle 0x694
89 19102119 [main] x_images.e 6036 stat_worker: 0 = (/home/iraf/images/test4.fits, 0x22C790)
109 19102228 [main] x_images.e 6036 sig_send: sendsig 0x6E4, pid 6036, signal -34, its_me 1
62 19102290 [main] x_images.e 6036 sig_send: wakeup 0x694
67 19102357 [main] x_images.e 6036 sig_send: Waiting for pack.wakeup 0x694
14 19102371 [sig] x_images.e 6036 wait_sig: signalling pack.wakeup 0x694
120 19102491 [main] x_images.e 6036 sig_send: returning 0x0 from sending signal -34
810 19103301 [main] x_images.e 6036 __dup_ent: old hostent structure "DJTX2G31" 0xB14D38
92 19103393 [main] x_images.e 6036 __dup_ent: duping hostent "DJTX2G31", 0x18FD6CA0
95 19103488 [main] x_images.e 6036 __dup_ent: duped hostent "DJTX2G31", 0xB14D38
56 19103544 [main] x_images.e 6036 cygwin_gethostbyname: h_name DJTX2G31
58 19103602 [main] x_images.e 6036 cygwin_socket: socket (2, 1, 0)
102 19103704 [main] x_images.e 6036 fdsock: reset socket inheritance
64 19103768 [main] x_images.e 6036 build_fh_pc: fh 0x6116A068
56 19103824 [main] x_images.e 6036 fhandler_base::set_flags: flags 0x10002, supplied_bin 0x0
57 19103881 [main] x_images.e 6036 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
56 19103937 [main] x_images.e 6036 fhandler_base::set_flags: filemode set to binary
56 19103993 [main] x_images.e 6036 fdsock: fd 4, name '', soc 0x694
56 19104049 [main] x_images.e 6036 cygwin_socket: 4 = socket (2, 1, 0)
58 19104107 [main] x_images.e 6036 sig_send: sendsig 0x6E4, pid 6036, signal -34, its_me 1
61 19104168 [main] x_images.e 6036 sig_send: wakeup 0x660
66 19104234 [main] x_images.e 6036 sig_send: Waiting for pack.wakeup 0x660
14 19104248 [sig] x_images.e 6036 wait_sig: signalling pack.wakeup 0x660
122 19104370 [main] x_images.e 6036 sig_send: returning 0x0 from sending signal -34
60 19104430 [main] x_images.e 6036 fhandler_socket::ioctl: socket is now nonblocking
56 19104486 [main] x_images.e 6036 fhandler_socket::ioctl: 0 = ioctl_socket (8004667E, 22B39C)
204 19104690 [main] x_images.e 6036 __set_errno: void __set_winsock_errno(const char*, int):234 val 119
95 19104785 [main] x_images.e 6036 __set_winsock_errno: connect:788 - winsock error 10036 -> errno 119
72 19104857 [main] x_images.e 6036 cygwin_select: 5, 0x0, 0x22B350, 0x22B330, 0x0
96 19104953 [main] x_images.e 6036 dtable::select_write: fd 4
57 19105010 [main] x_images.e 6036 dtable::select_except: fd 4
57 19105067 [main] x_images.e 6036 cygwin_select: to NULL, ms FFFFFFFF
56 19105123 [main] x_images.e 6036 cygwin_select: sel.always_ready 0
98 19105221 [main] x_images.e 6036 start_thread_socket: Handle 0x694
56 19105277 [main] x_images.e 6036 start_thread_socket: Added to writefds
55 19105332 [main] x_images.e 6036 start_thread_socket: Added to exceptfds
56 19105388 [main] x_images.e 6036 start_thread_socket: exitsock 0x684
55 19105443 [main] x_images.e 6036 start_thread_socket: stuff_start 0x22B2B4
105 19105548 [select_socket] x_images.e 6036 thread_socket: stuff_start 0xB1132C
30 19105578 [main] x_images.e 6036 select_stuff::wait: m 2, ms 4294967295
1086061 20191639 [select_socket] x_images.e 6036 thread_socket: Win32 select returned 1
144 20191783 [select_socket] x_images.e 6036 thread_socket: s 0xB14E40, testing fd 4 ()
75 20191858 [select_socket] x_images.e 6036 thread_socket: except_ready
90 20191948 [main] x_images.e 6036 select_stuff::wait: woke up. wait_ret 1. verifying
74 20192022 [main] x_images.e 6036 select_stuff::wait: gotone 1
83 20192105 [main] x_images.e 6036 select_stuff::wait: returning 0
71 20192176 [main] x_images.e 6036 select_stuff::cleanup: calling cleanup routines
58 20192234 [main] x_images.e 6036 socket_cleanup: si 0xB0E318 si->thread 0x61106F30
101 20192335 [main] x_images.e 6036 socket_cleanup: sent a byte to exitsock 0x684, res 1
121 20192456 [main] x_images.e 6036 socket_cleanup: reading a byte from exitsock 0x684
82 20192538 [main] x_images.e 6036 socket_cleanup: recv returned 1
94 20192632 [main] x_images.e 6036 socket_cleanup: returning
58 20192690 [main] x_images.e 6036 peek_socket: considering handle 0x694
56 20192746 [main] x_images.e 6036 peek_socket: adding write fd_set , fd 4
69 20192815 [main] x_images.e 6036 peek_socket: WINSOCK_SELECT returned 0
55 20192870 [main] x_images.e 6036 set_bits: me 0xB14E40, testing fd 4 ()
57 20192927 [main] x_images.e 6036 set_bits: ready 1
55 20192982 [main] x_images.e 6036 select_stuff::poll: returning 1
56 20193038 [main] x_images.e 6036 select_stuff::cleanup: calling cleanup routines
55 20193093 [main] x_images.e 6036 select_stuff::~select_stuff: deleting select records
98 20193191 [main] x_images.e 6036 cygwin_getsockopt: WinSock SO_ERROR = 10061
55 20193246 [main] x_images.e 6036 cygwin_getsockopt: 0 = getsockopt (4, 65535, 0x1007, 0x22B394, 0x22B398)
58 20193304 [main] x_images.e 6036 __set_errno: int cygwin_connect(int, const sockaddr*, socklen_t):806 val 111
68 20193372 [main] x_images.e 6036 fhandler_socket::ioctl: socket is now blocking
54 20193426 [main] x_images.e 6036 fhandler_socket::ioctl: 0 = ioctl_socket (8004667E, 22B390)
57 20193483 [main] x_images.e 6036 cygwin_connect: -1 = connect (4, 0x22B600, 16)
59 20193542 [main] x_images.e 6036 close: close (4)
92 20193634 [main] x_images.e 6036 fhandler_socket::close: 0 = fhandler_socket::close()
79 20193713 [main] x_images.e 6036 close: 0 = close (4)
176 20193889 [main] x_images.e 6036 stat64: entering
58 20193947 [main] x_images.e 6036 normalize_posix_path: src /home/iraf/images/test4.fits
56 20194003 [main] x_images.e 6036 normalize_posix_path: /home/iraf/images/test4.fits = normalize_posix_path (/home/iraf/images/test4.fits)

I tried this with images of various sizes, but can't reproduce the "step" in processing time you describe.Do you see this outside of IRAF as well, i.e. if you do something like[code:1:607238425f]% time cat foo.fits > /dev/null[/code:1:607238425f]do you still see a break at ~8MB in filesize? Even so, this sounds like something at the Cygwin level, there isn't anything in IRAF that can be tweaked to change it. Do you notice other increased times at multiples of 8Mb or is this the only one?-Mike