Slow WRITE

[Intel_C_Intel]

I have a model that outputs a diagnostic file. If I open the diagnostic file like this:

	OPEN ( UNIT = OptimDiagnosticLun, 
	1	FILE = TempFileName,
	1	STATUS = 'UNKNOWN',
	1	ACTION = 'WRITE', 
	1	IOSTAT = ios )

the model takes 14.04 seconds to run and produce the output file.

If I open the file like this:

	OPEN ( UNIT = OptimDiagnosticLun, 
	1	FILE = TempFileName,
	1	STATUS = 'UNKNOWN',
	1	IOSTAT = ios )

the model takes only 0.67 seconds to run and produce the output file.

Why?

[Steven_L_Intel1]

Compiler name and version?

Nothing comes to mind offhand... Is it actually the WRITEs that are slow? What if you comment out the WRITEs from both versions?

Steve

[Intel_C_Intel]

Sorry Steve - I always forget that, CVF 6.6B on Windows 2000.

I'm actually comparing a new version with an old version. I expected the new one to be quicker, was using diagnostics to check the results and was surprised to find I was wrong. The above difference is the only change that has been made relating to diagnostics, so I don't think commenting out all the WRITEs would show anything. Besides which, there are hundreds of them spread over tens of files! I noticed this because the new version WAS faster when I turned the diagnostics off completely.

I did some more tests this morning with full diagnostics:

Old version: 17 iterations in 5.70s
New version with ACTION='WRITE': 11 iterations in 106.5s
New version without ACTION='WRITE': 11 iterations in 2.31s
(all producing 5.57 MB of diagnostic output)

I did notice that with ACTION='WRITE' hardly any processor time was being used by my process (usually it grabs as much as it can).

The file is being written to a UNC path on our network.

ACTION='WRITE' was added to prevent crashes when trying to write to read only files, and the only explanation I can think of is that it is adding some kind of over head to every WRITE statement (a 'writeability' check?)...

Dan

[Intel_C_Intel]

Steve, I tested some more and it seems to be a problem with network writing. I used the following test program to demonstrate:

!****************************************************************************
!
!  PROGRAM: FWriteTest
!
!****************************************************************************

	PROGRAM FWriteTest

	IMPLICIT NONE

	! Variables

	CHARACTER	FileName*260
	INTEGER*4	i, ios
	REAL*8		start, fin, time
!****************************************************************************
	! Body of FWriteTest
	
	!FileName = 'C:TempFWriteTestTestOutput1.txt'
	FileName = 'SRV-OSPREYDEVTestOutput1.txt'

	OPEN ( UNIT = 1, FILE = FileName, STATUS = 'UNKNOWN', ACTION = 'WRITE', IOSTAT = ios, BUFFERED = 'YES' )

	CALL CPU_TIME(start)
	DO i = 1, 100000
		WRITE (1, *) 'All work and no play makes Jack a dull boy.'
	END DO
	CALL CPU_TIME(fin)

	time = fin - start

	WRITE (1, '(A, G10.5)') 'Time:', time
!****************************************************************************
	CLOSE (UNIT=1)

	!FileName = 'C:TempFWriteTestTestOutput2.txt'
	FileName = 'SRV-OSPREYDEVTestOutput2.txt'

	OPEN ( UNIT = 1, FILE = FileName, STATUS = 'UNKNOWN', IOSTAT = ios, BUFFERED = 'YES' )

	CALL CPU_TIME(start)
	DO i = 1, 100000
		WRITE (1, *) 'All work and no play makes Jack a dull boy.'
	END DO
	CALL CPU_TIME(fin)

	time = fin - start

	WRITE (1, '(A, G10.5)') 'Time:', time

	CLOSE (UNIT=1)
!****************************************************************************
	END PROGRAM FWriteTest

At first I didn't have the BUFFERED statement, and it took 9.3s to write with ACTION='WRITE' and 0.5s to write without. Buffering helps, bring both times down to about 0.1s, but it is still slightly faster without the ACTION='WRITE'

[Intel_C_Intel]

Steve, I tested some more and it seems to be a problem with network writing. I used the following test program to demonstrate:

!*********************************************************
!
!  PROGRAM: FWriteTest
!
!*********************************************************

PROGRAM FWriteTest

IMPLICIT NONE

! Variables

CHARACTER	FileName*260
INTEGER*4	i, ios
REAL*8		start, fin, time
!*********************************************************
! Body of FWriteTest
	
!FileName = 'C:TempFWriteTestTestOutput1.txt'
FileName = 'SRV-OSPREYDEVTestOutput1.txt'

OPEN ( UNIT = 1, FILE = FileName, STATUS = 'UNKNOWN', ACTION = 'WRITE', IOSTAT = ios, BUFFERED = 'YES' )

CALL CPU_TIME(start)
DO i = 1, 100000
	WRITE (1, *) 'All work and no play makes Jack a dull boy.'
END DO
CALL CPU_TIME(fin)

time = fin - start

WRITE (1, '(A, G10.5)') 'Time:', time
CLOSE (UNIT=1)
!*********************************************************
!FileName = 'C:TempFWriteTestTestOutput2.txt'
FileName = 'SRV-OSPREYDEVTestOutput2.txt'

OPEN ( UNIT = 1, FILE = FileName, STATUS = 'UNKNOWN', IOSTAT = ios, BUFFERED = 'YES' )

CALL CPU_TIME(start)
DO i = 1, 100000
	WRITE (1, *) 'All work and no play makes Jack a dull boy.'
END DO
CALL CPU_TIME(fin)

time = fin - start

WRITE (1, '(A, G10.5)') 'Time:', time

CLOSE (UNIT=1)
!*********************************************************
END PROGRAM FWriteTest

At first I didn't have the BUFFERED statement, and it
took 9.3s to write with ACTION='WRITE' and 0.5s to write
without. Buffering helps, bring both times down to about 0.1s, but it is still slightly faster without the ACTION='WRITE'

[Steven_L_Intel1]

Ah, the file is on a network share. You didn't tell us that originally!

I don't know why ACTION='WRITE' makes a difference, but I'm guessing this causes the Windows file system to do something different. CVF just passes that as part of the arguments to CreateFile.

Steve

[Intel_C_Intel]

We have noticed slower network access with CVF (6.6 on NT and XP) but have not been able to trace it - we cannot be sure it's CVF that is the problem though.