[net.bugs.4bsd] Possible bug in rwip

terryl@tekcrl.UUCP (10/29/85)

     I've come across some peculiar behaviour in using demand-paged from an
inode files. I came across this by accident when adding some new system calls
to our port of 4.2 to a 68010-based system, and found that I did the assembler
system call interface wrong. With some kernel printfs (which appear below),
it looks like the code in rwip() that attempts to find text pages that are
hashed in the cmhash data structure is not finding one text page and taking
that text page out of the cmhash structure. For the record, the value of NBPG
(number of bytes per page) for our port is 4096, and the value of CLSIZE (the
number of hardware pages clustered together in software) is 1. My comments
are preceeded by #, kernel printfs are preceeded by a %. Another reason I
think that it is a problem in the kernel, and not a problem in the user-level
code is that after the program fails, I can cp the program I am running to
another file, run the program from another file, and everything runs as
expected, and if I reboot the system, and then run the file that originally
failed, then again everything runs as expected.


     First, a size on the file in question.

text	data	bss	dec	hex
12288	4096	16390	32774	8006

# First run of program, when everything runs fine. The vinifod printf's
# are coming from the kernel rotuine vinifod which sets up the user ptes
# when running a demand-paged from an inode file. blkno is the actual
# block to demand page from, and dev is the major/minor number of the
# device the file resides on.
% vinifod: blkno = 38672 1 dev = 3
% vinifod: blkno = 38688 2 dev = 3
% vinifod: blkno = 38920 3 dev = 3
% vinifod: blkno = 38944 4 dev = 3
# These printfs come from the kernel routine rwip which actually does all
# of the mapping file blocks, copying in the user data into the blocks, etc.
# The resid of 48 and offset of 0 says this is the executable header being
# written out.
% rwip: size 512 count 1 dev 3 resid 48 offset 0
# The printf looking for block <block-number> comes from the routine rwip,
# saying that it is looking for a text page block in the cmhash structure.
% rwip: looking for block 38887 of 0
# This next printf, along with resid 4096 and offset 4096, says this is
# the first text page being written out to the file.
% rwip: size 4096 count 8 dev 3 resid 4096 offset 4096
# Now we look for the text page in the cmhash structure that we just wrote
# out to the file.
% rwip: looking for block 38672 of 0
# This printf also comes from the kernel routine rwip(), saying that we
# did find the text text page we just wrote out in the cmhash structure,
# and thus we take it out of the cmhash structure.
% rwip: found block 38672
# These next seven printfs also come from the kernel routine rwip, but I am
# not too sure why. I think it's an artifact that it takes 8 disk blocks to
# make up one CLBYTES memory block.
% rwip: looking for block 38673 of 1
% rwip: looking for block 38674 of 2
% rwip: looking for block 38675 of 3
% rwip: looking for block 38676 of 4
% rwip: looking for block 38677 of 5
% rwip: looking for block 38678 of 6
% rwip: looking for block 38679 of 7
# This next printf, along with resid 4096 and offset 8192, says this is
# the second text page being written out to the file.
% rwip: size 4096 count 8 dev 3 resid 4096 offset 8192
# Now we look for the text page in the cmhash structure that we just wrote
# out to the file.
% rwip: looking for block 38688 of 0
# This next printf says that we did find the text page we just wrote out
# in the cmhash structure, and thus we take it out of the cmhash structure.
% rwip: found block 38688
% rwip: looking for block 38689 of 1
% rwip: looking for block 38690 of 2
% rwip: looking for block 38691 of 3
% rwip: looking for block 38692 of 4
% rwip: looking for block 38693 of 5
% rwip: looking for block 38694 of 6
% rwip: looking for block 38695 of 7
# This next printf, along with resid 3396 and offset 12288, says this is
# the third text page being written out to the file.
% rwip: size 3584 count 7 dev 3 resid 3396 offset 12288
# NOTE!!! We do not find this text page we just wrote out in the cmhash
# structure!!!!!
% rwip: looking for block 38752 of 0
% rwip: looking for block 38753 of 1
% rwip: looking for block 38754 of 2
% rwip: looking for block 38755 of 3
% rwip: looking for block 38756 of 4
% rwip: looking for block 38757 of 5
% rwip: looking for block 38758 of 6
# This next printf, along with resid 1623 and offset 20480, says this is
# the sysmbol table being written out to the file.
% rwip: size 2048 count 4 dev 3 resid 1623 offset 20480
% rwip: looking for block 38488 of 0
% rwip: looking for block 38489 of 1
% rwip: looking for block 38490 of 2
% rwip: looking for block 38491 of 3
# This next printf, along with resid 2970 and offset 16834, says this is
# the first data segment page being written out to the file. Note that
# we don't find the block in the cmhash structure, because this isn't a
# text page.
% rwip: size 4096 count 8 dev 3 resid 2970 offset 16384
% rwip: looking for block 38944 of 0
% rwip: looking for block 38945 of 1
% rwip: looking for block 38946 of 2
% rwip: looking for block 38947 of 3
% rwip: looking for block 38948 of 4
% rwip: looking for block 38949 of 5
% rwip: looking for block 38950 of 6
% rwip: looking for block 38951 of 7
# This is the second running of the program AFTER the relinking of the
# new syscall interface which has shifted things around a couple of bytes.
# Note that the printfs from the kernel routine vinifod is the same as before,
# but that the block number for the third text page does not correspond to
# the block reported from rwip!!!!!
% vinifod: blkno = 38672 1 dev = 3
% vinifod: blkno = 38688 2 dev = 3
% vinifod: blkno = 38920 3 dev = 3
% vinifod: blkno = 38944 4 dev = 3
# This is a printf from the trap handler saying that the process just had a
# segmentation error with the user pc at 0x219e, which happens to be the
# third text page that wasn't found in the cmhash structure when the file
# was written out!!!!
% buserr user mode:
% 	pc=219e badaddr=1f578 statword=1301 statreg=8119 sr=0
% 	v=31 ndx=25 index=19 omap=21cb signal=11
% d0-d7= 41 4000 4 0 3 612e 7 41
% a0-a7= 7feed8 7feed0 1f579 170b8 326a 303c 7fedf8 7fed34
# This is the third running of the program, this time run under adb.
# Note (again) that the vinifod printfs are the same.
% vinifod: blkno = 38672 1
% vinifod: blkno = 38688 2
% vinifod: blkno = 38920 3
% vinifod: blkno = 38944 4
# And again, the printf from the trap handler. Doing a little poking around
# with adb, I found that from the process image, the text in the file and
# the text in the process was identical, UP TO ADDRESS 0x2000, which happens
# to be the third text page!!!! All of this information is what led me to
# believe that there is problem when writing out text pages for a demand-paged
# from an inode-type file.
% buserr user mode:
% 	pc=219e badaddr=1fb60 statword=1301 statreg=811a sr=0
% 	v=31 ndx=26 index=19 omap=21cb signal=11
% d0-d7= 41 4000 4 0 3 612e 1 41
% a0-a7= 7feedc 7feed4 1fb61 1f8ec 326a 303c 7fedfc 7fed38


     As an aside, I have seen something similar happen on our VAX 750,
but because of the load on the VAX, it is much more difficult to reproduce
this behaviour than it is on one of 68010-based systems. Has anyone run into
this before??? Does anyone have a fix????


			Terry Laskodi
			     of
			Tektronix