From fenner@parc.xerox.com Mon Jun 23 19:22:34 1997 Received: from alpha.xerox.com (alpha.Xerox.COM [13.1.64.93]) by hub.freebsd.org (8.8.5/8.8.5) with SMTP id TAA14912 for ; Mon, 23 Jun 1997 19:22:34 -0700 (PDT) Received: from klute.parc.xerox.com ([13.2.116.207]) by alpha.xerox.com with SMTP id <20132(7)>; Mon, 23 Jun 1997 19:21:54 PDT Received: from sundae.parc.xerox.com ([13.2.117.33]) by klute.parc.xerox.com with SMTP id <59167>; Mon, 23 Jun 1997 19:21:37 PDT Received: (from fenner@localhost) by sundae.parc.xerox.com (8.8.5/8.8.5) id CAA15275; Tue, 24 Jun 1997 02:20:24 GMT Message-Id: <199706240220.CAA15275@sundae.parc.xerox.com> Date: Mon, 23 Jun 1997 19:20:24 PDT From: Bill Fenner Reply-To: fenner@parc.xerox.com To: FreeBSD-gnats-submit@freebsd.org Subject: mmap fails on large file on CDROM X-Send-Pr-Version: 3.2 >Number: 3942 >Category: bin >Synopsis: mmap fails on large file on CDROM >Confidential: no >Severity: serious >Priority: medium >Responsible: freebsd-bugs >State: closed >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Mon Jun 23 19:30:03 PDT 1997 >Closed-Date: Tue Jun 24 16:52:02 PDT 1997 >Last-Modified: Tue Jun 24 16:53:15 PDT 1997 >Originator: Bill Fenner >Release: FreeBSD 2.2-RELEASE i386 >Organization: Xerox >Environment: 2.2-RELEASE. >Description: tail dies on a large file located on CDROM. I think this is symptomatic of mmap() not working properly on iso9660 filesystems. If you're debugging this, you might want to edit forward.c and remove the "register" from the declaration of 'size' in rlines() so that you don't get confused by the fact that gdb didn't know which registers gcc put 'size' into (gdb thought it was in %ebx and %esp, when it was really in %ebx and %esi). I spent a while debugging why the value got smashed when it was just gdb printing gibberish. # gdb ./tail run GDB is free software and you are welcome to distribute copies of it under certain conditions; type "show copying" to see the conditions. There is absolutely no warranty for GDB; type "show warranty" for details. GDB 4.16 (i386-unknown-freebsd), Copyright 1996 Free Software Foundation, Inc... (gdb) run /cdrom/flapometer.out.Jun10-19 Starting program: /usr/src/usr.bin/tail/./tail /cdrom/flapometer.out.Jun10-19 Program received signal SIGSEGV, Segmentation fault. 0x1a8d in rlines (fp=0x80860e0, off=10, sbp=0xefbfdc70) at forward.c:220 220 if (*--p == '\n' && !--off) { (gdb) p p - start $2 = 156628054 (gdb) p *(start+156626944) $1 = 0 '\000' (gdb) p *(start+156626943) $2 = 101 'e' (gdb) p *p $3 = 0 '\000' By the time I got to do any debugging, it's mapped in a page of zeroes, but I'm pretty sure that *p was on an unmapped page and that's why it got a SEGV. Note that *(start+156626943) (the end of the previous page) is the last bit of useful data; there are no NUL's in this file. -rw-r--r-- 1 fenner wheel 156628056 Jun 23 18:08 flapometer.out.Jun10-19 Once I've managed to do whatever the debugger did to get the page of nul's mapped, it's sticky. I can run tail, but the last page (1112 bytes) is filled with NUL's instead of the data I expect: # tail /cdrom/flapometer.out.Jun10-19 | cat -v 06/19/97 16:00:44 205.189.33.88/30 metric change 19 1391 flaps 06/19/97 16:00:44 205.189.33.140/30 metric change 20 87 flaps 06/19/97 16:00:44 205.189.33.152/30 metric change 19 1418 flaps 06/19/97 16:00:44 205.189.33.252/30 metric change 10 1768 flaps 06/19/97 16:00:44 129.46.91.233/32 metric change 21 5091 flaps 06/19/97 16:00:44 129.46.93.41/32 metric change 6 5148 flaps 06/19/97 16:00:52 129.46.14.0/23 metric change 6 6094 flaps 06/19/97 16:00:52 129.46.100.0/23 metric change 6 6169 flaps 06/19/97 16:00:52 129.46.104.0/23 metric change 6 6236 flaps 06/19/97 16:00:52 129.46.106.0/23 metric change^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^ @^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@ I have some vague suspicion that the two different failure modes are due to the presence or absence of the file in the buffer cache, since once I've experienced the second behavior it seems to be sticky, but if I read a bunch of files to try to thrash the cache it sometimes goes back to the first behavior. Neither error occurs when tail'ing the same file when it resides on a disk: # ./tail /sundae/fenner/flapometer.out.Jun10-19 06/19/97 16:00:52 129.46.124.0/23 metric change 6 6050 flaps 06/19/97 16:00:52 129.46.126.0/23 metric change 6 6117 flaps 06/19/97 16:00:52 129.46.128.0/23 metric change 6 3988 flaps 06/19/97 16:00:52 129.46.130.0/23 metric change 6 3910 flaps 06/19/97 16:00:52 129.46.136.0/23 metric change 6 3720 flaps 06/19/97 16:00:52 129.46.144.0/23 metric change 6 4391 flaps 06/19/97 16:00:52 129.46.180.0/23 metric change 6 3488 flaps 06/19/97 16:00:52 129.46.184.0/23 metric change 6 3382 flaps 06/19/97 16:00:52 129.46.188.0/23 metric change 6 3311 flaps 06/19/97 16:00:52 129.46.190.0/23 metric change 6 3274 flaps >How-To-Repeat: mmap() a big file on a CDROM like tail does, notice that the last page is sometimes not mapped and sometimes filled with zeroes. >Fix: unknown. >Release-Note: >Audit-Trail: From: Bill Fenner To: freebsd-gnats-submit@freebsd.org Cc: Subject: Re: bin/3942: mmap fails on large file on CDROM Date: Tue, 24 Jun 1997 12:43:41 PDT A little more info: When performing the "tail" experiment, the following messages often get logged: Jun 24 19:26:16 sundae /kernel: cd0(ncr0:6:0): MEDIUM ERROR info:12e73 asc:15,0 Random positioning error Jun 24 19:26:16 sundae /kernel: vm_fault: pager input (probably hardware) error, PID 16521 failure Jun 24 19:26:16 sundae /kernel: pid 16521 (tail), uid 0: exited on signal 11 However, dd'ing the same file succeeds at reading the block in question, so I'm not sure that I believe there's a medium error in the file. Also, I suspect that the zero-filled page comes from debugging the process; does the debugging fault handler insert a zero-filled page to let a process continue from accessing an unmapped page? And presumably, it makes its way into the buffer cache because of the merged VM/buffer cache (this might be a bug of its own, that debugging a process that uses mmap() can insert stuff into the buffer cache...) I guess these two errors are from trying to flush the modified buffer back to the CDROM: Jun 24 19:33:42 sundae /kernel: vnode_pager_putpages: I/O error 45 Jun 24 19:33:43 sundae /kernel: vnode_pager_putpages: residual I/O 4096 at 38239 Bill State-Changed-From-To: open->closed State-Changed-By: fenner State-Changed-When: Tue Jun 24 16:52:02 PDT 1997 State-Changed-Why: It looks like it's actually the medium or the drive; the CD-ROM drive isn't capable of seeking randomly to the end of the file but is capable of seeking there sequentially. >Unformatted: