From: Edi Weitz
Subject: Re: why Lispworks' file i/o way slower than Clisp?
Date:
Message-ID: <uvevf1n1q.fsf@agharta.de>
On 15 Feb 2006 19:12:34 -0800, "corps" <·········@gmail.com> wrote:
> ;;;testio.lisp
> (defun output ()
> (let ((str (make-string 100 :initial-element #\a)))
> (with-open-file (out "E:/test.txt" :direction :output :if-exists
> :overwrite)
> (dotimes (i 100000)
> (write-line str out)))))
>
> (defun count-line ()
> (with-open-file (in "E:/test.txt")
> (loop for line = (read-line in nil nil) with total = 0 while line
> do (incf total) finally (print total))))
Your subject line looks rather trollish to me but I'll answer anyway.
I can't reproduce your results. From the "E:/" I guess you're on
Windows. Below are my results (WinXP pro) where LispWorks is clearly
faster. Did you run each call several times to get a meaningful
average? Is "E:/" some special device like a network volume?
Cheers,
Edi.
CLISP
-----
CL-USER> (compile-file "/tmp/test.lisp")
;; Compiling file C:\tmp\test.lisp ...
;; Wrote file C:\tmp\test.fas
0 errors, 0 warnings
#P"C:\\tmp\\test.fas"
NIL
NIL
CL-USER> (load *)
;; Loading file C:\tmp\test.fas ...
;; Loaded file C:\tmp\test.fas
T
CL-USER> (time (output))
Real time: 0.4306192 sec.
Run time: 0.4206048 sec.
Space: 5028 Bytes
NIL
CL-USER> (time (output))
Real time: 0.7210368 sec.
Run time: 0.6609504 sec.
Space: 5136 Bytes
NIL
CL-USER> (time (output))
Real time: 0.7210368 sec.
Run time: 0.6208928 sec.
Space: 5136 Bytes
NIL
CL-USER> (time (output))
Real time: 0.7210368 sec.
Run time: 0.650936 sec.
Space: 5136 Bytes
NIL
CL-USER> (time (count-line))
100000
Real time: 1.0114543 sec.
Run time: 0.8712528 sec.
Space: 10805356 Bytes
GC: 18, GC time: 0.0600864 sec.
NIL
CL-USER> (time (count-line))
100000
Real time: 1.00144 sec.
Run time: 0.9613824 sec.
Space: 10805356 Bytes
GC: 18, GC time: 0.0600864 sec.
NIL
CL-USER> (time (count-line))
100000
Real time: 1.0214688 sec.
Run time: 0.9313392 sec.
Space: 10805356 Bytes
GC: 18, GC time: 0.0901296 sec.
NIL
CL-USER> (lisp-implementation-version)
"2.37 (2006-01-02) (built on winsteingoldlap.bluelnk.net [10.41.52.143])"
LispWorks
---------
CL-USER 1 > (compile-file "/tmp/test.lisp")
;;; Compiling file /tmp/test.lisp ...
;;; Safety = 3, Speed = 1, Space = 1, Float = 1, Interruptible = 0
;;; Compilation speed = 1, Debug = 2, Fixnum safety = 3
;;; Source level debugging is on
;;; Source file recording is on
;;; Cross referencing is on
; (TOP-LEVEL-FORM 1)
; OUTPUT
; Loading fasl file C:\Program Files\LispWorks\lib\4-4-0-0\load-on-demand\pcl\macros\loop.fsl
; COUNT-LINE
; (TOP-LEVEL-FORM 2)
#P"c:/tmp/test.fsl"
NIL
NIL
CL-USER 2 > (load *)
; Loading fasl file c:\tmp\test.fsl
#P"c:/tmp/test.fsl"
CL-USER 3 > (time (output))
Timing the evaluation of (OUTPUT)
; Loading fasl file C:\Program Files\LispWorks\lib\4-4-0-0\load-on-demand\pcl\util\callcoun.fsl
user time = 0.130
system time = 0.010
Elapsed time = 0:00:01
Allocation = 19768 bytes standard / 3674 bytes conses
0 Page faults
NIL
CL-USER 4 > (time (output))
Timing the evaluation of (OUTPUT)
user time = 0.120
system time = 0.010
Elapsed time = 0:00:00
Allocation = 17376 bytes standard / 2871 bytes conses
0 Page faults
NIL
CL-USER 5 > (time (output))
Timing the evaluation of (OUTPUT)
user time = 0.120
system time = 0.010
Elapsed time = 0:00:00
Allocation = 17376 bytes standard / 2893 bytes conses
0 Page faults
NIL
CL-USER 6 > (time (count-line))
Timing the evaluation of (COUNT-LINE)
100000
user time = 0.230
system time = 0.010
Elapsed time = 0:00:00
Allocation = 12137776 bytes standard / 3366 bytes conses
0 Page faults
NIL
CL-USER 7 > (time (count-line))
Timing the evaluation of (COUNT-LINE)
100000
user time = 0.210
system time = 0.000
Elapsed time = 0:00:00
Allocation = 12137776 bytes standard / 3388 bytes conses
0 Page faults
NIL
CL-USER 8 > (time (count-line))
Timing the evaluation of (COUNT-LINE)
100000
user time = 0.190
system time = 0.020
Elapsed time = 0:00:00
Allocation = 12137776 bytes standard / 3410 bytes conses
0 Page faults
NIL
CL-USER 9 > (lisp-implementation-version)
"4.4.6"
--
European Common Lisp Meeting 2006: <http://weitz.de/eclm2006/>
Real email: (replace (subseq ·········@agharta.de" 5) "edi")
Hi, Edi,
Thanks for your reply. I retry it and get the same results as before.
I am using the Lispworks Personal Edition. is there any setting I am
missing that causes this? And I find the i/o time in your test is much
faster than that in my test, both in CLisp and Lispworks. I am using
WinXP Pro too. I am puzzled. Is your machine much faster than mine? :)
best regards,
LYSH
From: Edi Weitz
Subject: Re: why Lispworks' file i/o way slower than Clisp?
Date:
Message-ID: <umzgqnxxl.fsf@agharta.de>
On 16 Feb 2006 18:16:06 -0800, "corps" <·········@gmail.com> wrote:
> Thanks for your reply. I retry it and get the same results as
> before. I am using the Lispworks Personal Edition. is there any
> setting I am missing that causes this?
Are you using the PE without modifications or do you load something
first? Have you changed any settings? Do you use SLIME?
> And I find the i/o time in your test is much faster than that in my
> test, both in CLisp and Lispworks. I am using WinXP Pro too. I am
> puzzled. Is your machine much faster than mine? :)
I doubt it. It's an IBM Thinkpad laptop about 18 months old. Every
decent and not-too-old desktop machine should be faster.
Have you other (background) programs running while executing your
tests? Maybe some virus checker or whatever which monitors every HD
access?
--
European Common Lisp Meeting 2006: <http://weitz.de/eclm2006/>
Real email: (replace (subseq ·········@agharta.de" 5) "edi")
corps wrote:
> Timing the evaluation of (OUTPUT)
>
> user time = 3.421
> system time = 0.046
> Elapsed time = 0:00:04
> Allocation = 20965328 bytes standard / 4664 bytes conses
> 0 Page faults
The allocation numbers here are so out to lunch for a program that just
dumps the same string to a stream over again. Edi got way smaller
numbers when he ran the test. The loop variable doesn't look like it
gets beyond the fixnum range, so it's not allocating bignums.
This is just a shot in the dark, but it smells a lot like code being
instrumented. You know, gathering execution profiling data or something
of the sort.
I don't know LispWorks, which is actually a cool thing here, because I
get to play detective.
It's fishy. Come on, twenty megabytes allocated to write a 100
character string to a file, one hundred thousand times? Where does that
come from? I have an idea. Suppose that the characters are two byte
objects. That would make the string about 200 bytes long plus overhead.
Multiply that by 100,000 and you get ... 20 megabytes! Perhaps the
string is being duplicated into a new object on each call to WRITE. But
why would that happen? Why would an array that is allocated and used to
initialize a lexical variable be copied when it is passed to some other
code? Why couldn't the pointer to that object just be passed? The
potential aswer to this is this: it's not safe, for some reason, to
give that pointer away. For instance, what if the object is
stack-allocated so that it disappears when the dynamic contour
terminates? The external function could stash a pointer to the object,
which would become a dangling pointer. There is perhaps something in
the compiler optimization settings which is causing such a situation?
Things that make you go hmm!
Could you retry with putting the
(time (output))
(time (count-line))
into a
(defun test ()
(time (output))
(time (count-line)))
and starting test from the listener?
FWIW on my machine
LispWorks Personal Edition 4.4.6
Timing the evaluation of (OUTPUT)
user time = 0.650
system time = 0.140
Elapsed time = 0:00:01
Allocation = 17400 bytes standard / 1254 bytes conses
0 Page faults
and clisp/mingw
Output
Real time: 1.6924336 sec.
Run time: 1.4921457 sec.
Space: 4728 Bytes