forums.silverfrost.com Forum Index forums.silverfrost.com
Welcome to the Silverfrost forums
 
 FAQFAQ   SearchSearch   MemberlistMemberlist   UsergroupsUsergroups   RegisterRegister 
 ProfileProfile   Log in to check your private messagesLog in to check your private messages   Log inLog in 

SLow performance with DIRECT ACCESS unformatted files
Goto page 1, 2, 3, 4  Next
 
Post new topic   Reply to topic    forums.silverfrost.com Forum Index -> Support
View previous topic :: View next topic  
Author Message
wahorger



Joined: 13 Oct 2014
Posts: 1217
Location: Morrison, CO, USA

PostPosted: Fri Jan 23, 2015 11:47 pm    Post subject: SLow performance with DIRECT ACCESS unformatted files Reply with quote

There appears to be a performance issue associated with UNFORMATTED files, either DIRECT or SEQUENTIAL access.

I had noticed that the work files created as DIRECT, UNFORMATTED seemed very slow to create, and slow to access. So, I ran a set of comparisons.

I wrote (and read) a file of 2000 records, of length=194 and timed the loop. The results are as follows:

For Direct Access (using REC= in the write or read)
Code:

 Starting the test at: 20150123 151057.900
 For access=direct format=unformatted, Written using REC=, in sequential order, file size=388,000
 writing         2000 records took      44.0332

 Starting the test at: 20150123 152815.356
 For access=direct format=unformatted, Read using REC=, in sequential order
 reading         2000 records took      2.12500



For Sequential access (see notation for use of REC=)
Code:
 Starting the test at: 20150123 151600.514
 For access=sequential, format=unformatted, written with no REC= , file size=392,000
 writing         2000 records took      1.76172

 Starting the test at: 20150123 151702.044
 For access=sequential, format=unformatted, records written as REC=, sequentially, file size=388,000
 writing         2000 records took      51.9512

 Starting the test at: 20150123 153330.497
 For access=sequential           format=unformatted, read as sequential records
 reading         2000 records took      1.73828



These data confirm that the act of creating a direct access file is about 25 times slower than sequential unformatted. I noticed that with Sequential/Unformatted, one can specify the REC= in the read or write. When REC= is specified, the creation of the file takes the equivalent amount of time.

It should also be noted that while using REC=, the amount of disk access that occurred was significantly more than for the faster records. I believe that is reflected in the timing data, although the root reason is unknown.

I have not bench-marked a sequential formatted file; my experience is that this is lightning fast.

[code:1:353a03158e]!FTN95 application...
PROGRAM main
integer print_every
integer failed_open,failed_delete,failed_close,failed_write
character iorecord(194)
character*8 ddate
character*10 ttime
character*5 zzone
integer values(8)
character*20 access,form
! Test program to open a unformatted direct access file, then write several records
! then close it and try again. Each failure to open will be logged along with the error code and date/time
! a 2 second wait will be done, then re-try.
!
! The first time, we'll delete the file, then create as a new, then old from then on
!
print_every = 0
failed_open = 0
failed_delete = 0
failed_close = 0
failed_write = 0
call date_and_time(ddate,ttime,zzone,values)
print *,"Starting the test at: ",ddate(1:8),' ',ttime(1:10)
access = 'sequential'
form = 'unformatted'
max_recs=2000
! the READ tests require that the file exists, so change 'replace' to 'old'
open(unit=15,file='testfile.dat',access=access,iostat=icode,err=12000,&
form=form,recl=194,status='old',share='compat')
start_loop = high_res_clock@(.true.)
do i=1,max_recs
call randomfile(iorecord,194) ! this is always left in to even out the loop timing
!This next line must change to reflect read or write and rec= if needed
read(15,err=13000)iorecord
end do
end_loop = high_res_clock@(.false.)
print *,'For access=',access,' format=',form
print *,"writing ",max_recs,' records took ',end_loop-start_loop
close(unit=15)
pause
stop
13000 continue
print *,"io error"
stop
12000 continue
print *,"open error",icode
stop

END PROGRAM main
subroutine randomfile(iorecord,length)
character*1 iorecord(length)
do i=1,length
iorecord=char(int(255.*random@()))
en
Back to top
View user's profile Send private message Visit poster's website
mecej4



Joined: 31 Oct 2006
Posts: 1886

PostPosted: Sat Jan 24, 2015 1:17 am    Post subject: Reply with quote

With the files on a ramdisk, on a Windows 8.1 laptop, writing and reading the data file with your test program took less than 0.02 seconds each. Are your files located in a remote file system, perhaps? What is the nature of your hardware, and which version of the compiler did you use?

Last edited by mecej4 on Tue Jan 27, 2015 2:33 am; edited 1 time in total
Back to top
View user's profile Send private message
wahorger



Joined: 13 Oct 2014
Posts: 1217
Location: Morrison, CO, USA

PostPosted: Sat Jan 24, 2015 7:05 am    Post subject: Reply with quote

V7.10 system (latest release). HD is 7200 RPM 2 TB, SATA. Not a networked file.

I would expect the RAMDISK to fly on this. As I mentioned in the post, there is a LOT of disk activity while the file is being created DIRECT. It's so slow that I can see it incrementing in 5K chunks every second. Not so for the sequential file. It's running 100K+ per second.

It's the creation time that makes no sense, especially given the access time for the READ operations once it is created is quite snappy.

On my ramdisk, 2000 records took 2 seconds, or .001 seconds/record.
Back to top
View user's profile Send private message Visit poster's website
JohnCampbell



Joined: 16 Feb 2006
Posts: 2554
Location: Sydney

PostPosted: Sat Jan 24, 2015 11:47 am    Post subject: Reply with quote

Check your record length in the OPEN statement : RECL=, which should only be used for direct access, unformatted, fixed length records.
REC= can/should only be used for Direct access unformatted files.

I have never identified a performance issue associated with UNFORMATTED files, either DIRECT or SEQUENTIAL access when used as limited by the standard. Your poor elapsed times being reported are probably due to problems with your incompatible use of OPEN and WRITE and are not as expected.

The combination of Fortran unformatted I/O with Windows 7 or 8 gives very good performance for the testing I have done. The file buffering works very well in FTN95.

John
Back to top
View user's profile Send private message
mecej4



Joined: 31 Oct 2006
Posts: 1886

PostPosted: Sat Jan 24, 2015 2:52 pm    Post subject: Reply with quote

On an external 7200 RPM hard drive, connected using USB 3.0 to a Windows 8.1 laptop, I get the following results for a data file creation run:

Starting the test at: 20150124 074847.450
For access=direct format=unformatted
writing 2000 records took 1.86719


Last edited by mecej4 on Tue Jan 27, 2015 2:34 am; edited 1 time in total
Back to top
View user's profile Send private message
wahorger



Joined: 13 Oct 2014
Posts: 1217
Location: Morrison, CO, USA

PostPosted: Sat Jan 24, 2015 3:00 pm    Post subject: Reply with quote

John, thanks for the reply.

Pray tell, what is wrong/incompatible with the code of the timing code that I posted? I start by creating the file using the appropriate OPEN (STATUS='REPLACE') and time this operation, then change the OPEN to reflect its now created status (STATUS='OLD'), and change the WRITE to READ. What could be simpler than this?

How about running this as a WRITE test (not on RAMDISK) and get a timing of it, post the results that you get. And include some pertinent info about your system for the comparison.

I get nearly the same results running on my 3.6 GHz Window 7 system as I do on my 1.9 GHz Windows 2000 system. HD's have the same RPM, interfaces are SATA vs. ATA. RAMDISK shows expected performance, except there is no physical disk access, so seek times are not included in the RAMDISK data (other postings from yesterday).

No, something else is going on.
Back to top
View user's profile Send private message Visit poster's website
mecej4



Joined: 31 Oct 2006
Posts: 1886

PostPosted: Sat Jan 24, 2015 5:05 pm    Post subject: Reply with quote

Clutching at a straw: Do you have one of these newfangled back-up-to-the-cloud services running?

John's comment about the rule that opening a file for sequential format precludes using a REC= specifier in I/O statements is well founded. This issue is separate from the slowdown that you reported but I have failed to reproduce.

The Fortran 95 standard stipulates as follows:
Quote:
9.4.1.3 Record number
The REC= specifier specifies the number of the record that is to be read or written. This specifier
may be present only in an input/output statement that specifies a unit connected for direct access

Therefore, if the file has been opened with ACCESS='sequential', no READ/WRITE statements to that file should contain a REC= specifier. FTN95 does not seem to enforce this rule. I have reported this matter in a separate thread: http://forums.silverfrost.com/viewtopic.php?t=2993 .
Back to top
View user's profile Send private message
wahorger



Joined: 13 Oct 2014
Posts: 1217
Location: Morrison, CO, USA

PostPosted: Sun Jan 25, 2015 5:11 am    Post subject: Reply with quote

If you look at the results, then you will see it performed both ways. I was surprised as well, it shouldn't have worked, but it does.

There is obviously something interfering with the write operation.

That being said, the Windows 2000 system, with absolutely no anti-virus installed, shows similar times to yours, but only if the status is OLD.

If I run the program on the Network on the primary machine, with STATUS=OLD, then I get times like you show. With STATUS="REPLACE' (creating a new file), and timing the WRITE operation (REC= for direct unformatted), I still get in the order of 42 seconds for 2000 records. And, about the same amount of time on the Windows 2000 system.

The access times for an old file are in line with expectations, but not for NEW (aka REPLACE) files.

I also have a NetBook, no antivirus and Windows XP. It's processing power and hard drive are quite slow, but I'm seeing file creation times of 165 seconds there. Also, not expected.
Back to top
View user's profile Send private message Visit poster's website
JohnCampbell



Joined: 16 Feb 2006
Posts: 2554
Location: Sydney

PostPosted: Sun Jan 25, 2015 12:44 pm    Post subject: Reply with quote

I could not see the "write" you are referring to ?
The following is my adaptation of your test code. I did not get the performance times you claim.
Code:
  PROGRAM main
 character*10 access
 integer*4    max_recs
!
 character*8  ddate
 character*10 ttime
 character*5  zzone
 integer*4    values(8)
 !
 ! Test program to open a unformatted direct access file, then write several records
 ! then close it and try again. Each failure to open will be logged along with the error code and date/time
 ! a 2 second wait will be done, then re-try.
 !
 ! The first time, we'll delete the file, then create as a new, then old from then on
 !
   max_recs      = 2000
!
   call date_and_time (ddate,ttime,zzone,values)
   print *,"Starting the test at: ",ddate(1:8),' ',ttime(1:10)
!
   call delete_file
!
   access        = 'direct'
   call create_file ( access, 'unformatted', max_recs )
   call read_file   ( access, 'unformatted', max_recs )
!
   access        = 'sequential'
   call create_file ( access, 'unformatted', max_recs )
   call read_file   ( access, 'unformatted', max_recs )

END PROGRAM main
 
subroutine create_file ( access, form, max_recs )
 character*(*) access, form
 integer*4    max_recs
!
 character*1  iorecord(194)
 logical      use_rec
!
 integer*4    i, icode
 real*8       elapsed_time, start_open, start_loop, end_loop
 external     elapsed_time

   use_rec =  access == 'direct'
 
   print *,"Opening testfile.dat"
   start_open = elapsed_time ()
   if ( use_rec ) then
     open ( unit   = 15,               &
            file   = 'testfile.dat',   &
            form   = form,             &
            access = access,           &
            recl   = 194,              &
            status = 'unknown',        &
            iostat = icode,            &
            err    = 12000,            &
            share  = 'compat')
   else
     open ( unit   = 15,               &
            file   = 'testfile.dat',   &
            form   = form,             &
            access = access,           &
            status = 'unknown',        &
            iostat = icode,            &
            err    = 12000,            &
            share  = 'compat')
   end if
!
   start_loop = elapsed_time ()
   do i = 1,max_recs
     call randomfile (iorecord,194)
!
     if ( use_rec ) then
       write (15, rec=i, iostat = icode, err=13000) iorecord
     else
       write (15,        iostat = icode, err=13000) iorecord
     end if
   end do
   end_loop = elapsed_time ()
!
   print *,'For access=',access,' format=',form,' took ',start_loop-start_open
   print *,"writing ",max_recs,' records took ',end_loop-start_loop
   close (unit=15)
   return

 13000 continue
   print *,"io error",icode,' in Create_File'
   call report_iocode (icode)
   stop

 12000 continue
   print *,"open error",icode,' in Create_File'
   call report_iocode (icode)
   stop

END subroutine create_file


Last edited by JohnCampbell on Sun Jan 25, 2015 12:58 pm; edited 1 time in total
Back to top
View user's profile Send private message
JohnCampbell



Joined: 16 Feb 2006
Posts: 2554
Location: Sydney

PostPosted: Sun Jan 25, 2015 12:46 pm    Post subject: Reply with quote

.ctd
Code:
subroutine read_file ( access, form, max_recs )
 character*(*) access, form
 integer*4    max_recs
!
 character*1  iorecord(194)
 logical      use_rec
!
 integer*4    i, icode
 real*8       elapsed_time, start_open, start_loop, end_loop
 external     elapsed_time
 
   use_rec =  access == 'direct'
 
   print *,"Opening testfile.dat"
   start_open = elapsed_time ()
   if ( use_rec ) then
     open ( unit   = 15,               &
            file   = 'testfile.dat',   &
            form   = form,             &
            access = access,           &
            recl   = 194,              &
            status = 'old',            &
            iostat = icode,            &
            err    = 12000,            &
            share  = 'compat')
   else
     open ( unit   = 15,               &
            file   = 'testfile.dat',   &
            form   = form,             &
            access = access,           &
            status = 'old',            &
            iostat = icode,            &
            err    = 12000,            &
            share  = 'compat')
   end if
!
   start_loop = elapsed_time ()
   do i = 1,max_recs
     call randomfile (iorecord,194)
     if ( use_rec ) then
       read (15, rec=i, iostat = icode, err=13000) iorecord
     else
       read (15,        iostat = icode, err=13000) iorecord
     end if
   end do
   end_loop = elapsed_time ()
!
   print *, 'For access=',access,' format=',form,' took ',start_loop-start_open
   print *, "reading ",max_recs,' records took ',end_loop-start_loop
   close (unit=15)
   return

 13000 continue
   print *,"io error",icode,' in Read_File', ' rec =',i
   call report_iocode (icode)
   stop

 12000 continue
   print *,"open error",icode,' in Read_File'
   call report_iocode (icode)
   stop

END subroutine read_file

subroutine delete_file
!
 integer*4    icode
!
   print *,"Deleting testfile.dat"
   open ( unit   = 15,               &
          file   = 'testfile.dat',   &
          form   = 'unformatted',    &
          access = 'direct',         &
          recl   = 1,                &
          status = 'unknown',        &
          iostat = icode,            &
          share  = 'compat')
   call  report_iocode (icode)
   close (unit=15, status='DELETE', iostat = icode)
   call  report_iocode (icode)
   return

END subroutine delete_file

subroutine report_iocode (iocode)
  integer*4 iocode
  character message*128

   if ( iocode == 0) return
   call FORTRAN_ERROR_MESSAGE@ (ioCODE,MESSAGE)
   write (*,*) 'Error :',trim(message)
end subroutine report_iocode

subroutine randomfile (iorecord, length)
 integer*4   length, i
 character*1 iorecord(length)
  do i=1,length
   iorecord=char(int(255.*random@()))
  end do
end subroutine randomfile

real*8 function elapsed_time ()
 integer*4 COUNT, COUNT_RATE
 
  call system_clock ( COUNT, COUNT_RATE )
  elapsed_time = dble (COUNT) / dble (COUNT_RATE)
end function elapsed_time

Try omitting "share = 'compat')" as this may not work well on all disk types.
Back to top
View user's profile Send private message
IanLambley



Joined: 17 Dec 2006
Posts: 490
Location: Sunderland

PostPosted: Sun Jan 25, 2015 1:14 pm    Post subject: Reply with quote

Have you tried de-fragmenting the disk? If the file is spread about the disk surface, there will be a lot of time for the read/write heads to respond from a mechanical point of view.
Ian
Back to top
View user's profile Send private message Send e-mail
wahorger



Joined: 13 Oct 2014
Posts: 1217
Location: Morrison, CO, USA

PostPosted: Sun Jan 25, 2015 5:40 pm    Post subject: Reply with quote

Ian, the disk(s) used are regularly defragged. I've now used a total of 4 different drive/partitions on three machines (poor times), one ramdisk (extraordinary times), and two with network connection to different NAS (great times).

I posted this originally because the slow times for one kind of access on a physical drive puzzled me beyond measure. Having people post actual timing or suggest interactions that I have not considered helps me to narrow the issue, which is an apparent incompatibility between the OS, the media, and the code. Hard data, however it is obtained (and documented) is invaluable in determining root cause of an issue.

John made a comment about 'COMPAT' being not applicable for all disk types. This is an interesting observation, because the manual would suggest that this is the most compatible method. I will investigate this further. Is it folder permissions? Is it some additional interaction with the virus software that manifests itself only when accessing the local hard drives?

All of these questions have (I hope) an answer. And it from folks like you and others offering suggestions and hard data that I hope to find what the truth is!

I thank you all for helping!
Bill
Back to top
View user's profile Send private message Visit poster's website
LitusSaxonicum



Joined: 23 Aug 2005
Posts: 2388
Location: Yateley, Hants, UK

PostPosted: Sun Jan 25, 2015 8:15 pm    Post subject: Reply with quote

I'm always astonished by radically different hard disk timings, because provided that the file size is less than the disk cache, shouldn't we be measuring the speed of the cache in every case?

Windows is a law unto itself!
Back to top
View user's profile Send private message
wahorger



Joined: 13 Oct 2014
Posts: 1217
Location: Morrison, CO, USA

PostPosted: Sun Jan 25, 2015 10:13 pm    Post subject: Reply with quote

There's disk cache, and there is disk cache....

Yes, Windows is an animal all to its own.
Back to top
View user's profile Send private message Visit poster's website
wahorger



Joined: 13 Oct 2014
Posts: 1217
Location: Morrison, CO, USA

PostPosted: Sun Jan 25, 2015 10:34 pm    Post subject: Reply with quote

I have completed another set of benchmarks on my primary machine, mapped drive, using all SHARE= options, and writing and reading in both DIRECT and SEQUENTIAL file structures, and the results are seen below. I separated each SHARE= into its own set.

From these data, it is clear that, while some may not see these results, there is something "going on" that is getting in the way of the disk I/O when the SHARE is set to either DENYNONE or COMPAT and ACCESS=DIRECT.

That is where I shall place my attention to uncover the answer.


Last edited by wahorger on Mon Jan 26, 2015 1:28 am; edited 2 times in total
Back to top
View user's profile Send private message Visit poster's website
Display posts from previous:   
Post new topic   Reply to topic    forums.silverfrost.com Forum Index -> Support All times are GMT + 1 Hour
Goto page 1, 2, 3, 4  Next
Page 1 of 4

 
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum


Powered by phpBB © 2001, 2005 phpBB Group