Dropped non-XFS cc's, probably no need to spam other lists at this point... On Wed, May 11, 2016 at 04:03:16PM +0200, Stefan Priebe - Profihost AG wrote: > > Am 11.05.2016 um 15:34 schrieb Brian Foster: > > On Wed, May 11, 2016 at 02:26:48PM +0200, Stefan Priebe - Profihost AG wrote: > >> Hi Brian, > >> > >> i'm still unable to grab anything to the trace file? Is there anything > >> to check if it's working at all? > >> > > > > See my previous mail: > > > > http://oss.sgi.com/pipermail/xfs/2016-March/047793.html > > > > E.g., something like this should work after writing to and removing a > > new file: > > > > # trace-cmd start -e "xfs:xfs_releasepage" > > # cat /sys/kernel/debug/tracing/trace_pipe > > ... > > rm-8198 [000] .... 9445.774070: xfs_releasepage: dev 253:4 ino 0x69 pgoff 0x9ff000 size 0xa00000 offset 0 length 0 delalloc 0 unwritten 0 > > arg sorry yes that's working but delalloc is always 0. > Hrm, Ok. That is strange. > May be i have to hook that into my initramfs to be fast enough? > Not sure that would matter.. you said it occurs within 48 hours? I take that to mean it doesn't occur immediately on boot. You should be able to tell from the logs or dmesg if it happens before you get a chance to start the tracing. Well, the options I can think of are: - Perhaps I botched matching up the line number to the warning, in which case we might want to try 'grep -v "delalloc 0 unwritten 0"' to catch any delalloc or unwritten blocks at releasepage() time. - Perhaps there's a race that the tracepoint doesn't catch. The warnings are based on local vars, so we could instrument the code to print a warning[1] to try and get the inode number. Brian [1] - compile tested diff: diff --git a/fs/xfs/xfs_aops.c b/fs/xfs/xfs_aops.c index 40645a4..94738ea 100644 --- a/fs/xfs/xfs_aops.c +++ b/fs/xfs/xfs_aops.c @@ -1038,11 +1038,18 @@ xfs_vm_releasepage( gfp_t gfp_mask) { int delalloc, unwritten; + struct xfs_inode *ip = XFS_I(page->mapping->host); trace_xfs_releasepage(page->mapping->host, page, 0, 0); xfs_count_page_state(page, &delalloc, &unwritten); + if (delalloc || unwritten) + xfs_warn(ip->i_mount, + "ino 0x%llx delalloc %d unwritten %d pgoff 0x%llx size 0x%llx", + ip->i_ino, delalloc, unwritten, page_offset(page), + i_size_read(page->mapping->host)); + if (WARN_ON_ONCE(delalloc)) return 0; if (WARN_ON_ONCE(unwritten)) > Stefan > > > Once that is working, add the grep command to filter out "delalloc 0" > > instances, etc. For example: > > > > cat .../trace_pipe | grep -v "delalloc 0" > ~/trace.out > > > > Brian > > > >> This still happens in the first 48 hours after a fresh reboot. > >> > >> Stefan > >> > >> Am 24.03.2016 um 13:24 schrieb Brian Foster: > >>> On Thu, Mar 24, 2016 at 01:17:15PM +0100, Stefan Priebe - Profihost AG wrote: > >>>> > >>>> Am 24.03.2016 um 12:17 schrieb Brian Foster: > >>>>> On Thu, Mar 24, 2016 at 09:15:15AM +0100, Stefan Priebe - Profihost AG wrote: > >>>>>> > >>>>>> Am 24.03.2016 um 09:10 schrieb Stefan Priebe - Profihost AG: > >>>>>>> > >>>>>>> Am 23.03.2016 um 15:07 schrieb Brian Foster: > >>>>>>>> On Wed, Mar 23, 2016 at 02:28:03PM +0100, Stefan Priebe - Profihost AG wrote: > >>>>>>>>> sorry new one the last one got mangled. Comments inside. > >>>>>>>>> > >>>>>>>>> Am 05.03.2016 um 23:48 schrieb Dave Chinner: > >>>>>>>>>> On Fri, Mar 04, 2016 at 04:03:42PM -0500, Brian Foster wrote: > >>>>>>>>>>> On Fri, Mar 04, 2016 at 09:02:06PM +0100, Stefan Priebe wrote: > >>>>>>>>>>>> Am 04.03.2016 um 20:13 schrieb Brian Foster: > >>>>>>>>>>>>> On Fri, Mar 04, 2016 at 07:47:16PM +0100, Stefan Priebe wrote: > >>>>>>>>>>>>>> Am 20.02.2016 um 19:02 schrieb Stefan Priebe - Profihost AG: > >>>>>>>>>>>>>>> > >>>>>>>>>>>>>>>> Am 20.02.2016 um 15:45 schrieb Brian Foster <bfoster@xxxxxxxxxx>: > >>>>>>>>>>>>>>>> > >>>>>>>>>>>>>>>>> On Sat, Feb 20, 2016 at 09:02:28AM +0100, Stefan Priebe wrote: > >>>>>>>> ... > >>>>>>>>> > >>>>>>>>> This has happened again on 8 different hosts in the last 24 hours > >>>>>>>>> running 4.4.6. > >>>>>>>>> > >>>>>>>>> All of those are KVM / Qemu hosts and are doing NO I/O except the normal > >>>>>>>>> OS stuff as the VMs have remote storage. So no database, no rsync on > >>>>>>>>> those hosts - just the OS doing nearly nothing. > >>>>>>>>> > >>>>>>>>> All those show: > >>>>>>>>> [153360.287040] WARNING: CPU: 0 PID: 109 at fs/xfs/xfs_aops.c:1234 > >>>>>>>>> xfs_vm_releasepage+0xe2/0xf0() > >>>>>>>>> > >>>>>>>> > >>>>>>>> Ok, well at this point the warning isn't telling us anything beyond > >>>>>>>> you're reproducing the problem. We can't really make progress without > >>>>>>>> more information. We don't necessarily know what application or > >>>>>>>> operations caused this by the time it occurs, but perhaps knowing what > >>>>>>>> file is affected could give us a hint. > >>>>>>>> > >>>>>>>> We have the xfs_releasepage tracepoint, but that's unconditional and so > >>>>>>>> might generate a lot of noise by default. Could you enable the > >>>>>>>> xfs_releasepage tracepoint and hunt for instances where delalloc != 0? > >>>>>>>> E.g., we could leave a long running 'trace-cmd record -e > >>>>>>>> "xfs:xfs_releasepage" <cmd>' command on several boxes and wait for the > >>>>>>>> problem to occur. Alternatively (and maybe easier), run 'trace-cmd start > >>>>>>>> -e "xfs:xfs_releasepage"' and leave something like 'cat > >>>>>>>> /sys/kernel/debug/tracing/trace_pipe | grep -v "delalloc 0" > > >>>>>>>> ~/trace.out' running to capture instances. > >>>>>> > >>>>>> Isn't the trace a WARN_ONCE? So it does not reoccur or can i check the > >>>>>> it in the trace.out even the WARN_ONCE was already triggered? > >>>>>> > >>>>> > >>>>> The tracepoint is independent from the warning (see > >>>>> xfs_vm_releasepage()), so the tracepoint will fire every invocation of > >>>>> the function regardless of whether delalloc blocks still exist at that > >>>>> point. That creates the need to filter the entries. > >>>>> > >>>>> With regard to performance, I believe the tracepoints are intended to be > >>>>> pretty lightweight. I don't think it should hurt to try it on a box, > >>>>> observe for a bit and make sure there isn't a huge impact. Note that the > >>>>> 'trace-cmd record' approach will save everything to file, so that's > >>>>> something to consider I suppose. > >>>> > >>>> Tests / cat is running. Is there any way to test if it works? Or is it > >>>> enough that cat prints stuff from time to time but does not match -v > >>>> delalloc 0 > >>>> > >>> > >>> What is it printing where delalloc != 0? You could always just cat > >>> trace_pipe and make sure the event is firing, it's just that I suspect > >>> most entries will have delalloc == unwritten == 0. > >>> > >>> Also, while the tracepoint fires independent of the warning, it might > >>> not be a bad idea to restart a system that has already seen the warning > >>> since boot, just to provide some correlation or additional notification > >>> when the problem occurs. > >>> > >>> Brian > >>> > >>>> Stefan > >>>> > >>>> _______________________________________________ > >>>> xfs mailing list > >>>> xfs@xxxxxxxxxxx > >>>> http://oss.sgi.com/mailman/listinfo/xfs > >> > >> _______________________________________________ > >> xfs mailing list > >> xfs@xxxxxxxxxxx > >> http://oss.sgi.com/mailman/listinfo/xfs > > _______________________________________________ > xfs mailing list > xfs@xxxxxxxxxxx > http://oss.sgi.com/mailman/listinfo/xfs _______________________________________________ xfs mailing list xfs@xxxxxxxxxxx http://oss.sgi.com/mailman/listinfo/xfs
