[MLton] MLton.TextIO.mkstemps
Matthew Fluet
fluet at cs.cornell.edu
Fri Dec 1 13:47:25 PST 2006
> Could you strace the simultaneous compiles of mlnlffigen to see what's
> going on?
I have a plausible explaination for some of the observed behavior.
I have three simultaneous 'make tools' going, and all three have errors in
the link stage:
PROC1:
ktrace -i -t cn mlton @MLton max-heap 512m -- -target self -native-split 1 -default-ann 'sequenceNonUnit warn' mlnlffigen.mlb
i686-apple-darwin8-gcc-4.0.1: /tmp/file4ofPIQ.o: No such file or directory
call to system failed with exit status 1:
PROC2:
ktrace -i -t cn mlton @MLton max-heap 512m -- -target self -native-split 1 -default-ann 'sequenceNonUnit warn' mlnlffigen.mlb
/usr/bin/ld: multiple definitions of symbol _f_28
/tmp/filemTweS8.o definition of _f_28 in section (__TEXT,__text)
/tmp/fileo9zyUP.o definition of _f_28 in section (__TEXT,__text)
collect2: ld returned 1 exit status
call to system failed with exit status 1:
PROC3:
ktrace -i -t cn mlton @MLton max-heap 512m -- -target self -native-split 1 -default-ann 'sequenceNonUnit warn' mlnlffigen.mlb
i686-apple-darwin8-gcc-4.0.1: /tmp/fileo9zyUP.o: No such file or directory
call to system failed with exit status 1:
At the end of this message is the ktrace/kdump relevant to fileo9zyUP.o;
the number after the process name is the absolute time of the trace point
(a nice feature of ktrace/kdump).
In this situation, the assembler is clearly to blame; when directed to
output to an existing file, the assembler unlinks the file and then opens
the (new) file, leaving a window for another process to grab the filename
for its use.
Here is the fine-grained detail, ordered by absolute time, where the
leading (N) indicates that the trace point came from the PROC<N> run:
(2) 2939 as 1165003845.198909 CALL stat(0xbfffec18,0xbfffe898)
(2) 2939 as 1165003845.198913 NAMI "/tmp/fileo9zyUP.o"
(2) 2939 as 1165003845.198924 RET stat 0
(2) 2939 as 1165003845.198929 CALL unlink(0xbfffec18)
(2) 2939 as 1165003845.198932 NAMI "/tmp/fileo9zyUP.o"
(2) 2939 as 1165003845.199078 RET unlink 0
(2) 2939 as 1165003845.199085 CALL open(0xbfffec18,0x601,0x1b6)
(3) 817 mlton-compile 1165003845.199086 CALL open(0x3116c84,0xa01,0x180)
(2) 2939 as 1165003845.199090 NAMI "/tmp/fileo9zyUP.o"
(3) 817 mlton-compile 1165003845.199094 NAMI "/tmp/fileo9zyUP.o"
(3) 817 mlton-compile 1165003845.199276 RET open 5
(3) 817 mlton-compile 1165003845.199281 CALL ioctl(0x5,FIODTYPE,0xbfffde4c)
(3) 817 mlton-compile 1165003845.199286 RET ioctl -1 errno 25 Inappropriate ioctl for device
(3) 817 mlton-compile 1165003845.199313 CALL ioctl(0x5,TIOCGETA,0xbfffde20)
(3) 817 mlton-compile 1165003845.199317 RET ioctl -1 errno 25 Inappropriate ioctl for device
(3) 817 mlton-compile 1165003845.199321 CALL fstat(0x5,0xbaaf80)
(3) 817 mlton-compile 1165003845.199336 RET fstat 0
(2) 2939 as 1165003845.199347 NAMI "/tmp/fileo9zyUP.o"
(3) 817 mlton-compile 1165003845.199348 CALL lseek(0x5,0,0x1)
(3) 817 mlton-compile 1165003845.199353 RET lseek 0
(2) 2939 as 1165003845.199400 RET open 5
(2) 2939 as 1165003845.199408 CALL write(0x5,0x78000,0xf64)
(2) 2939 as 1165003845.199446 RET write 3940/0xf64
(2) 2939 as 1165003845.199451 CALL close(0x5)
(2) 2939 as 1165003845.199461 RET close 0
(3) 817 mlton-compile 1165003845.199850 CALL close(0x5)
(3) 817 mlton-compile 1165003845.199930 RET close 0
You can see that the assembler's call to open (with O_WRONLY | O_CREAT |
O_TRUNC) and mlton's call to open (with O_WRONLY | O_CREAT | O_EXCL) are
nearly simultaneous; in particular, mlton's call to open returns well
before the assembler's call, so the presumably the assembler's invocation
of open sees an existing file.
Although Apple uses a modified version of an ancient GNU assembler, this
behavior is still around in the recent versions; On my linux box, I get
the following:
[fluet at localhost tmp]$ strace -f -o strace.out gcc -c -o plugh.o z.c
[fluet at localhost tmp]$ cat strace.out
...
4370 stat("plugh.o", {st_mode=S_IFREG|0644, st_size=4616, ...}) = 0
4370 lstat("plugh.o", {st_mode=S_IFREG|0644, st_size=4616, ...}) = 0
4370 unlink("plugh.o") = 0
4370 open("plugh.o", O_RDWR|O_CREAT|O_TRUNC, 0666) = 3
...
I know I've done many simultaneous invocations of mlton and 'make all' on
my (Opteron) linux box; I don't know why I've never encountered it there
and can reproduce it (fairly) easily on my MacPro.
The bad news: This still doesn't explain my original posting, where the
contention was on '/tmp/file6snPhX.15.c'. The .c files that arise during
a compilation are only opened for reading by gcc. Now, mlton does open
the .c file for writing twice: once via open with O_WRONLY | O_CREAT |
O_EXCL to grab the filename and then once via open with O_WRONLY | O_CREAT
| O_TRUNC to write the contents, but we never unlink it until after the
call to the linker returns and we're cleaning up all intermediate files.
Longer ktrace/kdump output:
PROC1:
...
634 mlton-compile 1165003848.426430 CALL open(0x311b53c,0xa01,0x180)
634 mlton-compile 1165003848.426433 NAMI "/tmp/fileo9zyUP.o"
634 mlton-compile 1165003848.426439 RET open -1 errno 17 File exists
...
PROC2:
...
724 mlton-compile 1165003845.165000 CALL open(0x311a424,0xa01,0x180)
724 mlton-compile 1165003845.165008 NAMI "/tmp/fileo9zyUP.o"
724 mlton-compile 1165003845.166025 RET open 5
724 mlton-compile 1165003845.166032 CALL ioctl(0x5,FIODTYPE,0xbfffde4c)
724 mlton-compile 1165003845.166037 RET ioctl -1 errno 25 Inappropriate ioctl for device
724 mlton-compile 1165003845.166041 CALL ioctl(0x5,TIOCGETA,0xbfffde20)
724 mlton-compile 1165003845.166044 RET ioctl -1 errno 25 Inappropriate ioctl for device
724 mlton-compile 1165003845.166048 CALL fstat(0x5,0xbaaf80)
724 mlton-compile 1165003845.166078 RET fstat 0
724 mlton-compile 1165003845.166090 CALL lseek(0x5,0,0x1)
724 mlton-compile 1165003845.166094 RET lseek 0
724 mlton-compile 1165003845.166597 CALL close(0x5)
724 mlton-compile 1165003845.166608 RET close 0
...
2939 as 1165003845.198909 CALL stat(0xbfffec18,0xbfffe898)
2939 as 1165003845.198913 NAMI "/tmp/fileo9zyUP.o"
2939 as 1165003845.198924 RET stat 0
2939 as 1165003845.198929 CALL unlink(0xbfffec18)
2939 as 1165003845.198932 NAMI "/tmp/fileo9zyUP.o"
2939 as 1165003845.199078 RET unlink 0
2939 as 1165003845.199085 CALL open(0xbfffec18,0x601,0x1b6)
2939 as 1165003845.199090 NAMI "/tmp/fileo9zyUP.o"
2939 as 1165003845.199347 NAMI "/tmp/fileo9zyUP.o"
2939 as 1165003845.199400 RET open 5
2939 as 1165003845.199408 CALL write(0x5,0x78000,0xf64)
2939 as 1165003845.199446 RET write 3940/0xf64
2939 as 1165003845.199451 CALL close(0x5)
2939 as 1165003845.199461 RET close 0
...
3574 i686-apple-darwi 1165003848.384211 CALL access(0xbfffcfdb,0)
3574 i686-apple-darwi 1165003848.384214 NAMI "/tmp/fileo9zyUP.o"
3574 i686-apple-darwi 1165003848.384218 RET access 0
...
3578 ld 1165003849.528330 CALL open(0xbfffc626,0,0)
3578 ld 1165003849.528334 NAMI "/tmp/fileo9zyUP.o"
3578 ld 1165003849.528342 RET open 9
3578 ld 1165003849.528345 CALL fstat(0x9,0x660c0)
3578 ld 1165003849.528349 RET fstat 0
3578 ld 1165003849.528374 CALL close(0x9)
3578 ld 1165003849.528379 RET close 0
3578 ld 1165003849.528418 CALL write(0x2,0xbfff9bf0,0xd)
3578 ld 1165003849.528461 RET write 13/0xd
3578 ld 1165003849.528467 CALL write(0x2,0xbfff9c20,0x24)
3578 ld 1165003849.528471 RET write 36/0x24
3578 ld 1165003849.528475 CALL write(0x2,0xbfff9bf0,0x1)
3578 ld 1165003849.528479 RET write 1
3578 ld 1165003849.528484 CALL write(0x2,0xbfff9ba0,0x12)
3578 ld 1165003849.528489 RET write 18/0x12
3578 ld 1165003849.528494 CALL write(0x2,0xbfff9bc0,0x2f)
3578 ld 1165003849.528498 RET write 47/0x2f
3578 ld 1165003849.528502 CALL write(0x2,0xbfff9ba0,0x12)
3578 ld 1165003849.528506 RET write 18/0x12
3578 ld 1165003849.528511 CALL write(0x2,0xbfff9bc0,0x2f)
3578 ld 1165003849.528539 RET write 47/0x2f
...
724 mlton-compile 1165003851.215862 CALL access(0x311bc20,0)
724 mlton-compile 1165003851.215866 NAMI "/tmp/fileo9zyUP.o"
724 mlton-compile 1165003851.215873 RET access 0
724 mlton-compile 1165003851.215876 CALL unlink(0x311bc48)
724 mlton-compile 1165003851.215909 NAMI "/tmp/fileo9zyUP.o"
724 mlton-compile 1165003851.216006 RET unlink 0
...
PROC3:
...
817 mlton-compile 1165003845.199086 CALL open(0x3116c84,0xa01,0x180)
817 mlton-compile 1165003845.199094 NAMI "/tmp/fileo9zyUP.o"
817 mlton-compile 1165003845.199276 RET open 5
817 mlton-compile 1165003845.199281 CALL ioctl(0x5,FIODTYPE,0xbfffde4c)
817 mlton-compile 1165003845.199286 RET ioctl -1 errno 25 Inappropriate ioctl for device
817 mlton-compile 1165003845.199313 CALL ioctl(0x5,TIOCGETA,0xbfffde20)
817 mlton-compile 1165003845.199317 RET ioctl -1 errno 25 Inappropriate ioctl for device
817 mlton-compile 1165003845.199321 CALL fstat(0x5,0xbaaf80)
817 mlton-compile 1165003845.199336 RET fstat 0
817 mlton-compile 1165003845.199348 CALL lseek(0x5,0,0x1)
817 mlton-compile 1165003845.199353 RET lseek 0
817 mlton-compile 1165003845.199850 CALL close(0x5)
817 mlton-compile 1165003845.199930 RET close 0
...
2947 as 1165003845.231873 CALL stat(0xbfffec18,0xbfffe898)
2947 as 1165003845.231877 NAMI "/tmp/fileo9zyUP.o"
2947 as 1165003845.231888 RET stat 0
2947 as 1165003845.231893 CALL unlink(0xbfffec18)
2947 as 1165003845.231896 NAMI "/tmp/fileo9zyUP.o"
2947 as 1165003845.232053 RET unlink 0
2947 as 1165003845.232058 CALL open(0xbfffec18,0x601,0x1b6)
2947 as 1165003845.232062 NAMI "/tmp/fileo9zyUP.o"
2947 as 1165003845.232172 RET open 5
2947 as 1165003845.232177 CALL write(0x5,0x78000,0x778)
2947 as 1165003845.232200 RET write 1912/0x778
2947 as 1165003845.232205 CALL close(0x5)
2947 as 1165003845.232214 RET close 0
...
4870 i686-apple-darwi 1165003858.239429 CALL access(0xbfffc65d,0)
4870 i686-apple-darwi 1165003858.239431 NAMI "/tmp/fileo9zyUP.o"
4870 i686-apple-darwi 1165003858.239457 RET access -1 errno 2 No such file or directory
4870 i686-apple-darwi 1165003858.239477 CALL write(0x2,0xbfffad10,0x1e)
4870 i686-apple-darwi 1165003858.239597 RET write 30/0x1e
4870 i686-apple-darwi 1165003858.239611 CALL write(0x2,0xbfffad40,0x2c)
4870 i686-apple-darwi 1165003858.239621 RET write 44/0x2c
4870 i686-apple-darwi 1165003858.239627 CALL write(0x2,0xa0001cb3,0x1)
4870 i686-apple-darwi 1165003858.239633 RET write 1
...
817 mlton-compile 1165003858.670080 CALL access(0x3119fd8,0)
817 mlton-compile 1165003858.670083 NAMI "/tmp/fileo9zyUP.o"
817 mlton-compile 1165003858.670111 RET access -1 errno 2 No such file or directory
...
More information about the MLton
mailing list