Re: SunBlade 100: X is very yellow with XVR-100 (radeon r100)
On 2021-12-11 5:39 a.m., Mark Kettenis wrote:
>> Date: Sat, 11 Dec 2021 05:10:41 -0700
>> From: Ted Bullock
>
> The are several reasons why that test can fail though. It can be an
> endian-ness issue or on sparc64 it could also be an IOMMU issue where
> the wrong address is programmed into the hardware because CPU
> addresses aren't properly translated into device virtual addresses.
>
Trying to figure out what the hell is happening here is making my eyes
bleed a little... there are lots of preprocessor stuff in this code
that looks fragile to me. I've not written much in the last few years
but surely this isn't a normal way of programming or maybe the authors
are smarter than me. :( Anyway I'm looking for where things could get
broken.
>> sys/dev/pci/drm/radeon/r100.c:3651
>> WREG32(scratch, 0xCAFEDEAD);
Starting here this is a macro that calls an inline function:
#define WREG32(reg, v) r100_mm_wreg(rdev, (reg), (v), false)
fwiw r100_mm_wreg is called only by one other thing, the macro:
#define WREG32_IDX(reg, v) r100_mm_wreg(rdev, (reg), (v), true)
I don't know why they wrapped an inline function that is called in only
2 different ways behind a macro but they did so ok, then looking at
r100_mm_wreg:
static inline void r100_mm_wreg(struct radeon_device *rdev, uint32_t reg,
uint32_t v,
bool always_indirect)
{
if ((reg < rdev->rmmio_size || reg < RADEON_MIN_MMIO_SIZE) &&
!always_indirect)
writel(v, ((void __iomem *)rdev->rmmio) + reg);
else
r100_mm_wreg_slow(rdev, reg, v);
}
This has some pointer math but this doesn't look like it has anything to
cause endian issues, so I suppose it's fine.
>> r = radeon_ring_lock(rdev, ring, 2);
>> if (r) {
>> DRM_ERROR("radeon: cp failed to lock ring (%d).\n", r);
>> radeon_scratch_free(rdev, scratch);
>> return r;
>> }
This locking stuff has nothing that looks problematic to me for endian
issues.
>> radeon_ring_write(ring, PACKET0(scratch, 0));
Until we get to this ^, this is kind of a nightmare for me to grasp.
The driver uses ring, or circular queue data structures as I'm familiar
with for interacting with the gpu, work items are written to the queue
and read by the gpu. The queue code doesn't look like it should have
endian issues and obviously it's working on other platforms so can
probably ignore it. It's weird to me that linux, bsd et al have circular
queue data structures pre-rolled so I don't know why they made their
own, perhaps ignorance or hubris, or they are super smart?
PACKET0(scratch, 0) this is kind of a monster though.
#define PACKET0(reg, n) (CP_PACKET0 | \
REG_SET(PACKET0_BASE_INDEX, (reg) >> 2) | \
REG_SET(PACKET0_COUNT, (n)))
and also here:
#define REG_SET(FIELD, v) (((v) << FIELD##_SHIFT) & FIELD##_MASK)
Think that maybe this is a big candidate for some sort of endian bug? I
do. hmmm. This looks insanely fragile but maybe I'm crazy and probably a
moron or something.
>> radeon_ring_write(ring, 0xDEADBEEF);
>> radeon_ring_unlock_commit(rdev, ring, false);
>> for (i = 0; i < rdev->usec_timeout; i++) {
>> tmp = RREG32(scratch);
>> if (tmp == 0xDEADBEEF) {
>> break;
>> }
>> udelay(1);
>> }
>> if (i < rdev->usec_timeout) {
>> DRM_INFO("ring test succeeded in %d usecs\n", i);
>> } else {
>> DRM_ERROR("radeon: ring test failed (scratch(0x%04X)=0x%08X)\n",
>>scratch, tmp);
>> r = -EINVAL;
>> }
--
Ted Bullock
Re: witness with full regress
On Sat, Dec 11, 2021 at 10:25:13AM +, Visa Hankala wrote: > > Some of these "missing" entries may be caused by transitive lock order > > relations that are not handled by the lock order printer. > > > > I have somewhere a diff that improves the situation. Let's see if I can > > find it... > > Here it is, though I want to tweak it before committing. It has problems > with stack usage because of recursion, and the output is still a mess. Seems to work /usr/src/regress/sys/ffs/nfs/../tests/chflags/12.t: "chflags returns EROFS if the named file resides on a read-only file system" Running test #0... okay. witness: lock order reversal: 1st 0xfd876515e600 vmmaplk (>lock) 2nd 0x800022b93080 nfsnode (>n_lock) lock order data w2 -> w1 missing lock order ">lock"(rwlock) -> ">n_lock"(rrwlock) first seen at: #0 rw_enter+0x65 #1 rrw_enter+0x56 #2 VOP_LOCK+0x5b #3 vn_lock+0xad #4 vn_rdwr+0x7f #5 vndstrategy+0x2e6 #6 physio+0x227 #7 spec_write+0x95 #8 VOP_WRITE+0x41 #9 vn_write+0xfc #10 dofilewritev+0x14d #11 sys_pwrite+0x5c #12 syscall+0x374 #13 Xsyscall+0x128 lock order (1) >lock -> (2) >n_lock #0 rw_enter+0x65 #1 rrw_enter+0x56 #2 VOP_LOCK+0x5b #3 vn_lock+0xad #4 vn_rdwr+0x7f #5 vndstrategy+0x2e6 #6 physio+0x227 #7 spec_write+0x95 #8 VOP_WRITE+0x41 #9 vn_write+0xfc #10 dofilewritev+0x14d #11 sys_pwrite+0x5c #12 syscall+0x374 #13 Xsyscall+0x128 lock order (2) >n_lock -> (3) >i_lock #0 rw_enter+0x65 #1 rrw_enter+0x56 #2 VOP_LOCK+0x5b #3 vn_lock+0xad #4 vrele+0x6a #5 vfs_lookup+0x659 #6 namei+0x245 #7 sys___realpath+0x146 #8 syscall+0x374 #9 Xsyscall+0x128 lock order (3) >i_lock -> (1) >lock #0 rw_enter_read+0x38 #1 uvmfault_lookup+0x8a #2 uvm_fault_check+0x32 #3 uvm_fault+0xfc #4 kpageflttrap+0x12b #5 kerntrap+0x91 #6 alltraps_kern_meltdown+0x7b #7 copyout+0x53 #8 ffs_read+0x1f6 #9 VOP_READ+0x41 #10 vn_rdwr+0xa1 #11 vmcmd_map_readvn+0xa6 #12 exec_process_vmcmds+0x84 #13 sys_execve+0x77d #14 start_init+0x29f #15 proc_trampoline+0x1c Running test #1... okay.
Re: witness with full regress
On Sat, Dec 11, 2021 at 09:58:54AM +0100, Mark Kettenis wrote: > This one may be harmless. The first backtrace is from executing > init(8), which only happens once and happens in a somewhat strange > manner. This happens in some /usr/src/regress/misc/posixtestsuite test. It needs pkg_add posixtestsuite from ports. conformance/interfaces/mmap/13-1: execution: PASS witness: lock order reversal: 1st 0xfd8774d45038 vmmaplk (>lock) 2nd 0xfd86eaf8dc48 inode (>i_lock) lock order ">i_lock"(rrwlock) -> ">lock"(rwlock) first seen at: #0 rw_enter_read+0x38 #1 uvmfault_lookup+0x8a #2 uvm_fault_check+0x32 #3 uvm_fault+0xfc #4 kpageflttrap+0x12b #5 kerntrap+0x91 #6 alltraps_kern_meltdown+0x7b #7 copyout+0x53 #8 ffs_read+0x1f6 #9 VOP_READ+0x41 #10 vn_rdwr+0xa1 #11 vmcmd_map_readvn+0xa6 #12 exec_process_vmcmds+0x84 #13 sys_execve+0x77d #14 start_init+0x29f #15 proc_trampoline+0x1c lock order ">lock"(rwlock) -> ">i_lock"(rrwlock) first seen at: #0 rw_enter+0x65 #1 rrw_enter+0x56 #2 VOP_LOCK+0x5b #3 vn_lock+0xad #4 uvn_io+0x1cc #5 uvm_pager_put+0xe6 #6 uvn_flush+0x250 #7 uvm_map_clean+0x1ff #8 syscall+0x374 #9 Xsyscall+0x128 conformance/interfaces/mmap/14-1: execution: PASS > so this is accessing a vnd whichis backed by a file on NFS. Not > terribly surprised that this causes issues. I think: > > > lock order ">lock"(rwlock) -> ">n_lock"(rrwlock) first seen at: > > is the "right" lock order. Unfortunately data for the "wrong" order > is missing... It can be reproduced by /usr/src/regress/sys/ffs/nfs . There I have a diskimage file on ffs. It is mounted via vnd. This file system acts as NFS server. From there it is mounted via 127.0.0.1 as NFS client on the same machine. On top of that the file system test suite is running. /usr/src/regress/sys/ffs/nfs/../tests/chflags/12.t: "chflags returns EROFS if the named file resides on a read-only file system" Running test #0... okay. witness: lock order reversal: 1st 0xfd86f37b7768 vmmaplk (>lock) 2nd 0x800022c19080 nfsnode (>n_lock) lock order data w2 -> w1 missing lock order ">lock"(rwlock) -> ">n_lock"(rrwlock) first seen at: #0 rw_enter+0x65 #1 rrw_enter+0x56 #2 VOP_LOCK+0x5b #3 vn_lock+0xad #4 vn_rdwr+0x7f #5 vndstrategy+0x2e6 #6 physio+0x227 #7 spec_write+0x95 #8 VOP_WRITE+0x41 #9 vn_write+0xfc #10 dofilewritev+0x14d #11 sys_pwrite+0x5c #12 syscall+0x374 #13 Xsyscall+0x128 Running test #1... okay. Running test #2... okay. Next I will tests visa's witness diff.
Re: SunBlade 100: X is very yellow with XVR-100 (radeon r100)
> Date: Sat, 11 Dec 2021 05:10:41 -0700
> From: Ted Bullock
>
> On 2021-12-11 4:41 a.m., Mark Kettenis wrote:
> >> Date: Fri, 10 Dec 2021 17:24:58 -0700
> >> From: Ted Bullock
> > So the real problem is:
> >
> >> [drm] *ERROR* radeon: ring test failed (scratch(0x15E4)=0xCAFEDEAD)
> >> [drm] *ERROR* radeon: cp isn't working (-22).
> >> drm:pid0:r100_startup *ERROR* failed initializing CP (-22).
> >> drm:pid0:r100_init *ERROR* Disabling GPU acceleration
> >> [drm] *ERROR* Wait for CP idle timeout, shutting down CP.
> >> Failed to wait GUI idle while programming pipes. Bad things might happen.
> >
> > as a result of this GPU acceleration is disabled and software
> > rendering is used. Which obviously has endian-ness issues.
>
> Yeah so there are actually 2 problems here. The first is the fault you
> can see above causing it to fall back to software rendering. The second
> is that there is going to be some sort of endian issue (probably) with
> the software renderer causing everything to display in the wrong colors.
>
> > The sad truth is that most of us don't have much time to test older
> > hardware and we tend to favor making new hardware work correctly over
> > keeping the really old stuff working. But help is appreciated and we
> > certainly won't outright reject any fixes you discover.
>
> That's totally expected, and not a problem for me. I'm definitely not
> looking for other people to swoop in and fix this old stuff for me, but
> I am trying to document what I'm finding, and if it's possible to keep
> stuff working a while longer I think it's worth my time. It's not like
> there will ever be another ultrasparc workstation made but there is
> definitely big endian stuff out in the world. Like that new powerpc
> system which is unfortunately a little too expensive to just buy to have
> one sitting around.
>
> Is this more appropriate to take to the freedesktop.org bug list btw?
Yes, but the most likely answer you'll get there is probably "we don't
care about big-endian platforms".
> > That said I think Jonathan said that support for the R100 is going to
> > be removed from Mesa, which would probably mean the end of GPU
> > acceleration support for that hardware.
>
> That's kind of sad to hear given how much hardware is going to still be
> out there, but I guess it depends on people using it, testing and
> fixing. c'est la vie.
>
> ok, regarding this fault, it's also apparently impacting macppc [0] and
> has been around for a while [1].
The are several reasons why that test can fail though. It can be an
endian-ness issue or on sparc64 it could also be an IOMMU issue where
the wrong address is programmed into the hardware because CPU
addresses aren't properly translated into device virtual addresses.
> sys/dev/pci/drm/radeon/r100.c:3651
> WREG32(scratch, 0xCAFEDEAD);
> r = radeon_ring_lock(rdev, ring, 2);
> if (r) {
> DRM_ERROR("radeon: cp failed to lock ring (%d).\n", r);
> radeon_scratch_free(rdev, scratch);
> return r;
> }
> radeon_ring_write(ring, PACKET0(scratch, 0));
> radeon_ring_write(ring, 0xDEADBEEF);
> radeon_ring_unlock_commit(rdev, ring, false);
> for (i = 0; i < rdev->usec_timeout; i++) {
> tmp = RREG32(scratch);
> if (tmp == 0xDEADBEEF) {
> break;
> }
> udelay(1);
> }
> if (i < rdev->usec_timeout) {
> DRM_INFO("ring test succeeded in %d usecs\n", i);
> } else {
> DRM_ERROR("radeon: ring test failed (scratch(0x%04X)=0x%08X)\n",
> scratch, tmp);
> r = -EINVAL;
> }
>
> [0] https://marc.info/?l=openbsd-bugs=162447131102854
> [1] https://gitlab.freedesktop.org/drm/amd/-/issues/162
>
> --
> Ted Bullock
>
Re: SunBlade 100: X is very yellow with XVR-100 (radeon r100)
On Sat, Dec 11, 2021 at 12:41:46PM +0100, Mark Kettenis wrote: > > Date: Fri, 10 Dec 2021 17:24:58 -0700 > > From: Ted Bullock > > > > On 2021-12-10 12:53 a.m., Jonathan Gray wrote: > > > On Thu, Dec 09, 2021 at 10:01:30PM -0700, Ted Bullock wrote: > > >> Thoughts folks? This is clearly going to impact all big endian + radeon > > >> gear. > > >> > > >> Actually, I bet that the macppc platform has the same problem too. > > > > > > sparc64 maps pci little endian, I don't think macppc does > > > > > > can you try the following? > > > > Yeah that did resolve the bios warning; X is yellow still though. > > So the real problem is: > > > [drm] *ERROR* radeon: ring test failed (scratch(0x15E4)=0xCAFEDEAD) > > [drm] *ERROR* radeon: cp isn't working (-22). > > drm:pid0:r100_startup *ERROR* failed initializing CP (-22). > > drm:pid0:r100_init *ERROR* Disabling GPU acceleration > > [drm] *ERROR* Wait for CP idle timeout, shutting down CP. > > Failed to wait GUI idle while programming pipes. Bad things might happen. > > as a result of this GPU acceleration is disabled and software > rendering is used. Which obviously has endian-ness issues. > > I believe the XVR-300 doesn't hit these errors and still (mostly) > works. But you can't plug one of those into a blade100. > > The sad truth is that most of us don't have much time to test older > hardware and we tend to favor making new hardware work correctly over > keeping the really old stuff working. But help is appreciated and we > certainly won't outright reject any fixes you discover. I test on old r100 and i915 hardware but on i386 not sparc64. > > That said I think Jonathan said that support for the R100 is going to > be removed from Mesa, which would probably mean the end of GPU > acceleration support for that hardware. In Mesa git (and >= 22.0) the non-gallium 'classic' drivers are removed. https://gitlab.freedesktop.org/mesa/mesa/-/merge_requests/10153 For radeon r100/r200 are removed. For intel i915 (gen 2-3), i965 (gen 4-7) For i965 there is a new replacement gallium driver (crocus) The proposed way of supporting older hardware is building the 'amber' branch based on 21.3 in addition to building a newer release, with the nvidia libglvnd acting as libGL calling different Mesa versions. I don't think we'd want to go that route. I have a Mesa 21.3 update in the works which still has the classic drivers but that is on hold for now as it expects the kernel drm to implement android sync file interfaces in at least the intel vulkan driver.
Re: SunBlade 100: X is very yellow with XVR-100 (radeon r100)
On 2021-12-11 4:41 a.m., Mark Kettenis wrote:
Date: Fri, 10 Dec 2021 17:24:58 -0700
From: Ted Bullock
So the real problem is:
[drm] *ERROR* radeon: ring test failed (scratch(0x15E4)=0xCAFEDEAD)
[drm] *ERROR* radeon: cp isn't working (-22).
drm:pid0:r100_startup *ERROR* failed initializing CP (-22).
drm:pid0:r100_init *ERROR* Disabling GPU acceleration
[drm] *ERROR* Wait for CP idle timeout, shutting down CP.
Failed to wait GUI idle while programming pipes. Bad things might happen.
as a result of this GPU acceleration is disabled and software
rendering is used. Which obviously has endian-ness issues.
Yeah so there are actually 2 problems here. The first is the fault you
can see above causing it to fall back to software rendering. The second
is that there is going to be some sort of endian issue (probably) with
the software renderer causing everything to display in the wrong colors.
The sad truth is that most of us don't have much time to test older
hardware and we tend to favor making new hardware work correctly over
keeping the really old stuff working. But help is appreciated and we
certainly won't outright reject any fixes you discover.
That's totally expected, and not a problem for me. I'm definitely not
looking for other people to swoop in and fix this old stuff for me, but
I am trying to document what I'm finding, and if it's possible to keep
stuff working a while longer I think it's worth my time. It's not like
there will ever be another ultrasparc workstation made but there is
definitely big endian stuff out in the world. Like that new powerpc
system which is unfortunately a little too expensive to just buy to have
one sitting around.
Is this more appropriate to take to the freedesktop.org bug list btw?
That said I think Jonathan said that support for the R100 is going to
be removed from Mesa, which would probably mean the end of GPU
acceleration support for that hardware.
That's kind of sad to hear given how much hardware is going to still be
out there, but I guess it depends on people using it, testing and
fixing. c'est la vie.
ok, regarding this fault, it's also apparently impacting macppc [0] and
has been around for a while [1].
sys/dev/pci/drm/radeon/r100.c:3651
WREG32(scratch, 0xCAFEDEAD);
r = radeon_ring_lock(rdev, ring, 2);
if (r) {
DRM_ERROR("radeon: cp failed to lock ring (%d).\n", r);
radeon_scratch_free(rdev, scratch);
return r;
}
radeon_ring_write(ring, PACKET0(scratch, 0));
radeon_ring_write(ring, 0xDEADBEEF);
radeon_ring_unlock_commit(rdev, ring, false);
for (i = 0; i < rdev->usec_timeout; i++) {
tmp = RREG32(scratch);
if (tmp == 0xDEADBEEF) {
break;
}
udelay(1);
}
if (i < rdev->usec_timeout) {
DRM_INFO("ring test succeeded in %d usecs\n", i);
} else {
DRM_ERROR("radeon: ring test failed (scratch(0x%04X)=0x%08X)\n",
scratch, tmp);
r = -EINVAL;
}
[0] https://marc.info/?l=openbsd-bugs=162447131102854
[1] https://gitlab.freedesktop.org/drm/amd/-/issues/162
--
Ted Bullock
Re: SunBlade 100: X is very yellow with XVR-100 (radeon r100)
> Date: Fri, 10 Dec 2021 17:24:58 -0700 > From: Ted Bullock > > On 2021-12-10 12:53 a.m., Jonathan Gray wrote: > > On Thu, Dec 09, 2021 at 10:01:30PM -0700, Ted Bullock wrote: > >> Thoughts folks? This is clearly going to impact all big endian + radeon > >> gear. > >> > >> Actually, I bet that the macppc platform has the same problem too. > > > > sparc64 maps pci little endian, I don't think macppc does > > > > can you try the following? > > Yeah that did resolve the bios warning; X is yellow still though. So the real problem is: > [drm] *ERROR* radeon: ring test failed (scratch(0x15E4)=0xCAFEDEAD) > [drm] *ERROR* radeon: cp isn't working (-22). > drm:pid0:r100_startup *ERROR* failed initializing CP (-22). > drm:pid0:r100_init *ERROR* Disabling GPU acceleration > [drm] *ERROR* Wait for CP idle timeout, shutting down CP. > Failed to wait GUI idle while programming pipes. Bad things might happen. as a result of this GPU acceleration is disabled and software rendering is used. Which obviously has endian-ness issues. I believe the XVR-300 doesn't hit these errors and still (mostly) works. But you can't plug one of those into a blade100. The sad truth is that most of us don't have much time to test older hardware and we tend to favor making new hardware work correctly over keeping the really old stuff working. But help is appreciated and we certainly won't outright reject any fixes you discover. That said I think Jonathan said that support for the R100 is going to be removed from Mesa, which would probably mean the end of GPU acceleration support for that hardware. > FWIW, I was worried there might be a hardware fault here so I tested on > solaris > and it was working appropriately there. > > Current relevant dmesg: > > radeondrm0: ivec 0x7d5 > machfb0 at pci0 dev 19 function 0 "ATI Rage XL" rev 0x27 > machfb0: ATY,RageXL, 1152x900 > wsdisplay0 at machfb0 mux 1 > wsdisplay0: screen 0 added (std, sun emulation) > usb0 at ohci0: USB revision 1.0 > uhub0 at usb0 configuration 1 interface 0 "Sun OHCI root hub" rev 1.00/1.00 > addr 1 > dt: 451 probes > vscsi0 at root > scsibus2 at vscsi0: 256 targets > softraid0 at root > scsibus3 at softraid0: 256 targets > bootpath: /pci@1f,0/ide@d,0/disk@0,0 > root on wd0a (abe1c474.a) swap on wd0b dump on wd0b > radeondrm0: RV100 > [drm] *ERROR* radeon: ring test failed (scratch(0x15E4)=0xCAFEDEAD) > [drm] *ERROR* radeon: cp isn't working (-22). > drm:pid0:r100_startup *ERROR* failed initializing CP (-22). > drm:pid0:r100_init *ERROR* Disabling GPU acceleration > [drm] *ERROR* Wait for CP idle timeout, shutting down CP. > Failed to wait GUI idle while programming pipes. Bad things might happen. > radeondrm0: 1280x1024, 8bpp > wsdisplay1 at radeondrm0 mux 1 > wsdisplay1: screen 0 added (std, sun emulation) > Bogus possible_clones: [ENCODER:45:TMDS-45] possible_clones=0x6 (full encoder > mask=0x7) > Bogus possible_clones: [ENCODER:46:TV-46] possible_clones=0x5 (full encoder > mask=0x7) > Bogus possible_clones: [ENCODER:48:DAC-48] possible_clones=0x3 (full encoder > mask=0x7) > > > > > -- > Ted Bullock > >
Re: witness with full regress
On Sat, Dec 11, 2021 at 09:37:08AM +, Visa Hankala wrote:
> On Sat, Dec 11, 2021 at 09:58:54AM +0100, Mark Kettenis wrote:
> > > Date: Sat, 11 Dec 2021 01:13:32 +0100
> > > From: Alexander Bluhm
>
> > > witness: lock order reversal:
> > > 1st 0xfd886921d8d8 vmmaplk (>lock)
> > > 2nd 0x800022c54130 nfsnode (>n_lock)
> > > lock order data w2 -> w1 missing
> > > lock order ">lock"(rwlock) -> ">n_lock"(rrwlock) first seen at:
> > > #0 rw_enter+0x65
> > > #1 rrw_enter+0x56
> > > #2 VOP_LOCK+0x5b
> > > #3 vn_lock+0xad
> > > #4 vn_rdwr+0x7f
> > > #5 vndstrategy+0x2e6
> > > #6 physio+0x227
> > > #7 spec_write+0x95
> > > #8 VOP_WRITE+0x41
> > > #9 vn_write+0xfc
> > > #10 dofilewritev+0x14d
> > > #11 sys_pwrite+0x5c
> > > #12 syscall+0x374
> > > #13 Xsyscall+0x128
> >
> > so this is accessing a vnd whichis backed by a file on NFS. Not
> > terribly surprised that this causes issues. I think:
> >
> > > lock order ">lock"(rwlock) -> ">n_lock"(rrwlock) first seen at:
> >
> > is the "right" lock order. Unfortunately data for the "wrong" order
> > is missing...
>
> Some of these "missing" entries may be caused by transitive lock order
> relations that are not handled by the lock order printer.
>
> I have somewhere a diff that improves the situation. Let's see if I can
> find it...
Here it is, though I want to tweak it before committing. It has problems
with stack usage because of recursion, and the output is still a mess.
witness: lock order reversal:
1st 0xfd810891f188 vmmaplk (>lock)
2nd 0x8000227cc138 nfsnode (>n_lock)
lock order data w2 -> w1 missing
lock order ">lock"(rwlock) -> ">n_lock"(rrwlock) first seen at:
#0 rw_enter+0x65
#1 rrw_enter+0x56
#2 VOP_LOCK+0x5b
#3 vn_lock+0xad
#4 vn_rdwr+0x7f
#5 vndstrategy+0x2e6
#6 physio+0x227
#7 spec_write+0x95
#8 VOP_WRITE+0x41
#9 vn_write+0xfc
#10 dofilewritev+0x14d
#11 sys_pwrite+0x5c
#12 syscall+0x3a9
#13 Xsyscall+0x128
lock order (1) >lock -> (2) >n_lock
#0 rw_enter+0x65
#1 rrw_enter+0x56
#2 VOP_LOCK+0x5b
#3 vn_lock+0xad
#4 vn_rdwr+0x7f
#5 vndstrategy+0x2e6
#6 physio+0x227
#7 spec_write+0x95
#8 VOP_WRITE+0x41
#9 vn_write+0xfc
#10 dofilewritev+0x14d
#11 sys_pwrite+0x5c
#12 syscall+0x3a9
#13 Xsyscall+0x128
lock order (2) >n_lock -> (3) netlock
#0 rw_enter_write+0x43
#1 solock+0x4b
#2 sosend+0x136
#3 nfs_send+0x89
#4 nfs_request+0x270
#5 nfs_getattr+0xc8
#6 VOP_GETATTR+0x51
#7 mountnfs+0x379
#8 nfs_mount+0x121
#9 sys_mount+0x364
#10 syscall+0x3a9
#11 Xsyscall+0x128
lock order (3) netlock -> (1) >lock
#0 rw_enter_read+0x38
#1 uvmfault_lookup+0x8a
#2 uvm_fault_check+0x32
#3 uvm_fault+0xfc
#4 kpageflttrap+0x12b
#5 kerntrap+0x91
#6 alltraps_kern_meltdown+0x7b
#7 copyin+0x5e
#8 sysctl_bounded_arr+0x83
#9 tcp_sysctl+0x387
#10 sys_sysctl+0x184
#11 syscall+0x3a9
#12 Xsyscall+0x128
diff --git a/sys/kern/subr_witness.c b/sys/kern/subr_witness.c
index ad50f29e066..b4e43d8a1b7 100644
--- a/sys/kern/subr_witness.c
+++ b/sys/kern/subr_witness.c
@@ -369,6 +369,8 @@ static struct witness_lock_order_data
*witness_lock_order_get(
struct witness *child);
static voidwitness_list_lock(struct lock_instance *instance,
int (*prnt)(const char *fmt, ...));
+static voidwitness_print_cycle(struct witness *parent,
+ struct witness *child);
static voidwitness_setflag(struct lock_object *lock, int flag, int set);
/*
@@ -1101,6 +1107,8 @@ witness_checkorder(struct lock_object *lock, int flags,
printf("lock order data "
"w1 -> w2 missing\n");
}
+
+ witness_print_cycle(w1, w);
}
witness_debugger(0);
goto out_splx;
@@ -1870,6 +1885,88 @@ witness_list_lock(struct lock_instance *instance,
stacktrace_print(>li_stack->ls_stack, prnt);
}
+static int
+witness_dls(struct witness *w, struct witness *target, struct witness **path,
+int depth, int *remaining)
+{
+ int i, any_remaining;
+
+ if (depth == 0) {
+ *remaining = 1;
+ return (w == target);
+ }
+
+ any_remaining = 0;
+ for (i = 1; i <= w_max_used_index; i++) {
+ if (w_rmatrix[w->w_index][i] & WITNESS_PARENT) {
+ if (witness_dls(_data[i], target, path, depth - 1,
+ remaining)) {
+ path[depth - 1] = _data[i];
+ *remaining = 1;
+ return 1;
+ }
+ if (remaining)
+ any_remaining = 1;
+ }
+ }
+ *remaining = any_remaining;
+ return 0;
+}
+
Re: witness with full regress
On Sat, Dec 11, 2021 at 09:58:54AM +0100, Mark Kettenis wrote: > > Date: Sat, 11 Dec 2021 01:13:32 +0100 > > From: Alexander Bluhm > > witness: lock order reversal: > > 1st 0xfd886921d8d8 vmmaplk (>lock) > > 2nd 0x800022c54130 nfsnode (>n_lock) > > lock order data w2 -> w1 missing > > lock order ">lock"(rwlock) -> ">n_lock"(rrwlock) first seen at: > > #0 rw_enter+0x65 > > #1 rrw_enter+0x56 > > #2 VOP_LOCK+0x5b > > #3 vn_lock+0xad > > #4 vn_rdwr+0x7f > > #5 vndstrategy+0x2e6 > > #6 physio+0x227 > > #7 spec_write+0x95 > > #8 VOP_WRITE+0x41 > > #9 vn_write+0xfc > > #10 dofilewritev+0x14d > > #11 sys_pwrite+0x5c > > #12 syscall+0x374 > > #13 Xsyscall+0x128 > > so this is accessing a vnd whichis backed by a file on NFS. Not > terribly surprised that this causes issues. I think: > > > lock order ">lock"(rwlock) -> ">n_lock"(rrwlock) first seen at: > > is the "right" lock order. Unfortunately data for the "wrong" order > is missing... Some of these "missing" entries may be caused by transitive lock order relations that are not handled by the lock order printer. I have somewhere a diff that improves the situation. Let's see if I can find it...
Re: witness with full regress
> Date: Sat, 11 Dec 2021 01:13:32 +0100 > From: Alexander Bluhm > > Hi, > > I have turned on witness during a full regress run on amd64. It > found two issues. Basically I am posting this as baseline, so I > can see if things get better or worse. If someone wants to fix > them, I can dig into the test logs to see which regress triggered > it. > > bluhm > > witness: lock order reversal: > 1st 0xfd8774b19310 vmmaplk (>lock) > 2nd 0xfd872022be68 inode (>i_lock) > lock order ">i_lock"(rrwlock) -> ">lock"(rwlock) first seen at: > #0 rw_enter_read+0x38 > #1 uvmfault_lookup+0x8a > #2 uvm_fault_check+0x32 > #3 uvm_fault+0xfc > #4 kpageflttrap+0x12b > #5 kerntrap+0x91 > #6 alltraps_kern_meltdown+0x7b > #7 copyout+0x53 > #8 ffs_read+0x1f6 > #9 VOP_READ+0x41 > #10 vn_rdwr+0xa1 > #11 vmcmd_map_readvn+0xa6 > #12 exec_process_vmcmds+0x84 > #13 sys_execve+0x77d > #14 start_init+0x29f > #15 proc_trampoline+0x1c > lock order ">lock"(rwlock) -> ">i_lock"(rrwlock) first seen at: > #0 rw_enter+0x65 > #1 rrw_enter+0x56 > #2 VOP_LOCK+0x5b > #3 vn_lock+0xad > #4 uvn_io+0x1cc > #5 uvm_pager_put+0xe6 > #6 uvn_flush+0x250 > #7 uvm_map_clean+0x1ff > #8 syscall+0x374 > #9 Xsyscall+0x128 This one may be harmless. The first backtrace is from executing init(8), which only happens once and happens in a somewhat strange manner. > witness: lock order reversal: > 1st 0xfd886921d8d8 vmmaplk (>lock) > 2nd 0x800022c54130 nfsnode (>n_lock) > lock order data w2 -> w1 missing > lock order ">lock"(rwlock) -> ">n_lock"(rrwlock) first seen at: > #0 rw_enter+0x65 > #1 rrw_enter+0x56 > #2 VOP_LOCK+0x5b > #3 vn_lock+0xad > #4 vn_rdwr+0x7f > #5 vndstrategy+0x2e6 > #6 physio+0x227 > #7 spec_write+0x95 > #8 VOP_WRITE+0x41 > #9 vn_write+0xfc > #10 dofilewritev+0x14d > #11 sys_pwrite+0x5c > #12 syscall+0x374 > #13 Xsyscall+0x128 so this is accessing a vnd whichis backed by a file on NFS. Not terribly surprised that this causes issues. I think: > lock order ">lock"(rwlock) -> ">n_lock"(rrwlock) first seen at: is the "right" lock order. Unfortunately data for the "wrong" order is missing...
