Redirection to log file is quicker than to null : Why?

Discussion forum for all Windows batch related topics.

Moderator: DosItHelp

Message
Author
SIMMS7400
Posts: 539
Joined: 07 Jan 2016 07:47

Redirection to log file is quicker than to null : Why?

#1 Post by SIMMS7400 » 23 Feb 2017 11:20

Hi Folks -

I run a SQL process using batch and when I redirect output to a log file it runs much quicker than if i do > nul 2>&1.

script1.cmd is executed via a parent script. Within script1.cmd is where I invoke SQLPLUS.

For instance, the first option is the quickest:

Code: Select all

call script1.cmd > Logfile.txt


While this is slower by almost 50%.

Code: Select all

call script1.cmd > nul 2>&1


Is there any reason for that?

Thanks!

Squashman
Expert
Posts: 4465
Joined: 23 Dec 2011 13:59

Re: Redirection to log file is quicker than to null : Why?

#2 Post by Squashman » 23 Feb 2017 11:32

That is not an accurate example.

You are redirecting standard error and standard output to nul.

the other one is only redirecting standard output to a logfile.

SIMMS7400
Posts: 539
Joined: 07 Jan 2016 07:47

Re: Redirection to log file is quicker than to null : Why?

#3 Post by SIMMS7400 » 23 Feb 2017 11:55

Squash -

That is correct, thank you for rehashing that.

I'm seeing 50% performance increase if I direct to an actual log file rather than just direct to NUL.

1>nul yeilds same performance as > nul 2>&1

Just trying to figure out why?

Also, if I don't redirect to anything, the output is spooled to the CMD window and thus, increases run times.

Squashman
Expert
Posts: 4465
Joined: 23 Dec 2011 13:59

Re: Redirection to log file is quicker than to null : Why?

#4 Post by Squashman » 23 Feb 2017 14:27

Well I can confirm your results just using the type command with a large file.

Code: Select all

@echo off
FOR %%G IN (test.txt) DO ECHO File Size: %%~zG
CALL jTimestamp -f {ums} -r t1
(type test.txt)>nul
CALL jTimestamp -f {ums} -r t2
CALL jTimestamp -d %t2%-%t1% -f "NUL Redirect: {ud} Days {h} Hours {n} Minutes And {s} Seconds" -u

CALL jTimestamp -f {ums} -r t1
(type test.txt)>temp.txt
CALL jTimestamp -f {ums} -r t2
CALL jTimestamp -d %t2%-%t1% -f "FILE Redirect: {ud} Days {h} Hours {n} Minutes And {s} Seconds" -u

pause


Output

Code: Select all

File Size: 2956643952
NUL Redirect: 0 Days 0 Hours 6 Minutes And 43 Seconds
FILE Redirect: 0 Days 0 Hours 2 Minutes And 2 Seconds
Press any key to continue . . .


Piping to findstr:

Code: Select all

type test.txt |findstr /V "^"

Code: Select all

Pipe to Findstr: 0 Days 0 Hours 1 Minutes And 41 Seconds

dbenham
Expert
Posts: 2461
Joined: 12 Feb 2011 21:02
Location: United States (east coast)

Re: Redirection to log file is quicker than to null : Why?

#5 Post by dbenham » 23 Feb 2017 16:28

:shock:

That is disturbing :evil:

penpen
Expert
Posts: 1991
Joined: 23 Jun 2013 06:15
Location: Germany

Re: Redirection to log file is quicker than to null : Why?

#6 Post by penpen » 23 Feb 2017 17:00

I cannot confirm this:

Code: Select all

@echo off
for %%a in (file) do echo %%~za
echo !time!
>nul type "file"
echo !time!
>"file2" type "file"
echo !time!

Result:

Code: Select all

2147483506
23:32:40,67
23:34:11,57
23:36:44,89
So 00:01:30,90 redirected to nul, and 00:02:33,32 redirected to file.

I wonder why... .
My System: Intel(R) Core(TM)2 Duo CPU E8400 @3.00GHz, 2 MB RAM, Windows 10 Pro, 32 bit.
Degree of file fragmentation: My file consists of two chunks a ~0,99GB (2 x World of Warcraft\Data\data\data.000).
Core usage: It seems, my batch always uses the same CPU core for processing the above.


penpen

SIMMS7400
Posts: 539
Joined: 07 Jan 2016 07:47

Re: Redirection to log file is quicker than to null : Why?

#7 Post by SIMMS7400 » 23 Feb 2017 17:49

Oh my :shock:

This is interesting.

Squashman
Expert
Posts: 4465
Joined: 23 Dec 2011 13:59

Re: Redirection to log file is quicker than to null : Why?

#8 Post by Squashman » 23 Feb 2017 18:50

Well I could run it on my desktop rig down stairs but my work laptop is fairly comparable.

Processor: Intel(R) Core(TM) i5-5300U CPU @ 2.30GHz (4 CPUs), ~2.3GHz
Memory: 16384MB RAM

Squashman
Expert
Posts: 4465
Joined: 23 Dec 2011 13:59

Re: Redirection to log file is quicker than to null : Why?

#9 Post by Squashman » 23 Feb 2017 19:12

Retested.

Code: Select all

File Size: 2956643952
NUL Redirect: 0 Days 0 Hours 7 Minutes And 22 Seconds
FILE Redirect: 0 Days 0 Hours 2 Minutes And 4 Seconds

aGerman
Expert
Posts: 4654
Joined: 22 Jan 2010 18:01
Location: Germany

Re: Redirection to log file is quicker than to null : Why?

#10 Post by aGerman » 24 Feb 2017 04:48

Win7 Enterprise, 64 bit
Intel(R) Core(TM) i5-4300U CPU @ 1,90GHz (4 CPUs), ~2.5GHz
4GB RAM

Code: Select all

File Size: 2269852080
NUL Redirect: 0 Days 0 Hours 5 Minutes And 58 Seconds
FILE Redirect: 0 Days 0 Hours 2 Minutes And 37 Seconds


I'll retest on my Win10 toy at home this evening. Maybe they changed the behavior as penpen's results show.

Steffen

penpen
Expert
Posts: 1991
Joined: 23 Jun 2013 06:15
Location: Germany

Re: Redirection to log file is quicker than to null : Why?

#11 Post by penpen » 24 Feb 2017 07:23

I created a file of the exact same size, you (Squashman) are using:

Code: Select all

Z:\>test.bat
@echo off
setlocal enableExtensions enableDelayedExpansion
type "%~f0" & echo(
if not exist "file" (
        set "a=aaaa"
        call set "a=%%a:a=!a:a=aa!%%"
        call set "a=%%a:a=!a:a=aa!%%"
        echo !time!
        set "a=!a:~-1022!"
        >file (
                for /l %%a in (1, 1, 2887347) do echo(!a!
                echo(!a:~-624!
        )
)
for %%a in ("file") do echo %%~za
echo !time!
>nul type "file"
echo !time!
>"file2" type "file"
echo !time!
endlocal

13:21:21,71
2956643954
13:25:03,57
13:27:07,63
13:30:45,65
Same result (00:02:04,06 to nul, 00:03:38,02 to file), so it is neither the filesize nor its fragmentation.
The core speed (2.3/3.0 GHz) shouldn't make such a difference (and i assume the cores are running in parallel - but to be honest i never realy thought about it).

Another possible cause were the 32 versus 64 bit win os.
@SIMMS7400:
Are you also using a 64 bit OS?

The bad thing: Actually i have no access to other PCs.


penpen

SIMMS7400
Posts: 539
Joined: 07 Jan 2016 07:47

Re: Redirection to log file is quicker than to null : Why?

#12 Post by SIMMS7400 » 24 Feb 2017 07:50

Thank you all for your help on this!

So I did some additional testing this morning and performance doesn't become affected TOO much until you hit .5g or higher. Under .5g the differences are only seconds. Here a few tests above .5g.

Code: Select all

File Size: 613110967
NUL Redirect: 0 Days 0 Hours 1 Minutes And 11 Seconds
FILE Redirect: 0 Days 0 Hours 0 Minutes And 40 Seconds


So at about 1 gig, we see performance begins to degrade by 50%

Code: Select all

File Size: 1021851611
NUL Redirect: 0 Days 0 Hours 2 Minutes And 24 Seconds
FILE Redirect: 0 Days 0 Hours 0 Minutes And 50 Seconds


Computer Info:

Code: Select all

-----------------------------------------------------------------------------
--------------QUICK REFERENCE------------------------------------------------
-----------------------------------------------------------------------------

Windows version        :  Microsoft Windows [Version 6.1.7601]
Product name           :  Windows 7 Enterprise, 32 bit
Performance indicators :  Processor Cores: 4      Visible RAM: 3376796 Bytes

Date/Time format       :  mm/dd/yy (12 hours)     Fri 02/24/2017   8:49:41.23
Extensions             :  system: Enabled   user: Enabled
Delayed expansion      :  system: Disabled  user: Disabled
Locale name            :  en-US       Code Pages: OEM  437    ANSI 1252
DIR  format            :  02/14/2017  08:23 AM     3,457,839,104 pagefile.sys
Permissions            :  Elevated Admin=Yes, Admin group=Yes

 
Disk Space - Total     :  179 GB
Disk Space - Available :  61 GB

Memory - Total         :  3298
Memory - Used          :  2061

Squashman
Expert
Posts: 4465
Joined: 23 Dec 2011 13:59

Re: Redirection to log file is quicker than to null : Why?

#13 Post by Squashman » 24 Feb 2017 08:09

PenPen,
Would there be any differences with processor architecture. You have an older duo core which as I understand is two separate processors linked together whereas the newer I5 and I7 are 4 cores on one wafer?

penpen
Expert
Posts: 1991
Joined: 23 Jun 2013 06:15
Location: Germany

Re: Redirection to log file is quicker than to null : Why?

#14 Post by penpen » 24 Feb 2017 09:31

The Intel Core2 Duo Processor E8400 also is just a single processor with two cores on one wafer.
So the processor architecture should not differ that much, except that my CPU has 6MB internal cache instead of 3MB (which shouldn't make any difference here), and the number of threads of your CPU is 4 (instead of 1), so your CPU should be able up to process 8 instructions at the same time (instead of 2).

If i don't misinterpret the core speed usage, then your CPU should be up to (8/2*2.3/3.0~=) 3,0667 times faster (on overall computation) than mine, athough each single thread is a little bit slower and reaches only (2.3/3.0~=) 76.7% of the speed of the other CPU.
This also shouldn't explain the big difference.

Under XP the nul device is just a file device (class) which write function just is an empty function, so it should be faster than a function that also does something (writing to file).

Another possible reason that came to my mind (seeing SIMMS7400 his last post; "until you hit .5g or higher" ):
A virus scanner may find it suspicious to pass big amounts of data to nul;
i'm using the built in windows defender only.


penpen

SIMMS7400
Posts: 539
Joined: 07 Jan 2016 07:47

Re: Redirection to log file is quicker than to null : Why?

#15 Post by SIMMS7400 » 24 Feb 2017 10:27

Team -

Some new development.

I did some additonal testing direction output to the console INSTEAD of NUL. The performance degradation is insane.

Please see: File is 1.6gigs

Code: Select all

File Size: 1634962577
Command Window Redirect: 0 Days 0 Hours 48 Minutes And 16 Seconds
FILE Redirect: 0 Days 0 Hours 1 Minutes And 29 Seconds



Yikes.
Last edited by SIMMS7400 on 24 Feb 2017 10:33, edited 1 time in total.

Post Reply