On Tue, May 26, 2020 at 06:06:44PM +1000, Dave Chinner wrote: > On Tue, May 26, 2020 at 05:23:16PM +1000, Dave Chinner wrote: > > HI folks, > > > > Just noticed this interesting thing when looking at a trace or an > > rm -rf worklaod of fsstress directories (generic/051 cleanup, FWIW). > > The trace fragment is this, trimmed for brevity: > > > > 255.854202: xfs_ail_insert: lip 0xffff888136421540 old lsn 0/0 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854202: xfs_ail_insert: lip 0xffff888216cc8848 old lsn 0/0 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854203: xfs_ail_insert: lip 0xffff8881364217e8 old lsn 0/0 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854203: xfs_ail_insert: lip 0xffff888216cc86a0 old lsn 0/0 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854204: xfs_ail_insert: lip 0xffff888834e71090 old lsn 0/0 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854204: xfs_ail_insert: lip 0xffff8885ca67e120 old lsn 0/0 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854205: xfs_ail_insert: lip 0xffff888800660ff0 old lsn 0/0 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854205: xfs_ail_insert: lip 0xffff888828bee618 old lsn 0/0 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854206: xfs_ail_insert: lip 0xffff888800661298 old lsn 0/0 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854206: xfs_ail_insert: lip 0xffff888828bee7c0 old lsn 0/0 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854207: xfs_ail_insert: lip 0xffff8885ca67e2c8 old lsn 0/0 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854207: xfs_ail_insert: lip 0xffff888834e71238 old lsn 0/0 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854208: xfs_ail_insert: lip 0xffff888136421a90 old lsn 0/0 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854208: xfs_ail_insert: lip 0xffff888216cc84f8 old lsn 0/0 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854208: xfs_ail_insert: lip 0xffff888136421d38 old lsn 0/0 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854209: xfs_ail_insert: lip 0xffff888216cc8350 old lsn 0/0 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854209: xfs_ail_insert: lip 0xffff888834e713e0 old lsn 0/0 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854210: xfs_ail_insert: lip 0xffff8885ca67e470 old lsn 0/0 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854210: xfs_ail_insert: lip 0xffff8885ca67e618 old lsn 0/0 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854211: xfs_ail_insert: lip 0xffff888800661540 old lsn 0/0 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854211: xfs_ail_insert: lip 0xffff888828bee968 old lsn 0/0 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854212: xfs_ail_insert: lip 0xffff8888006617e8 old lsn 0/0 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854213: xfs_ail_insert: lip 0xffff888828beeb10 old lsn 0/0 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854214: xfs_ail_insert: lip 0xffff888834e71588 old lsn 0/0 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854215: xfs_ail_insert: lip 0xffff888136421fe0 old lsn 0/0 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854215: xfs_ail_insert: lip 0xffff888216cc81a8 old lsn 0/0 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854215: xfs_ail_insert: lip 0xffff888136422288 old lsn 0/0 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854216: xfs_ail_insert: lip 0xffff88810deefd48 old lsn 0/0 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854216: xfs_ail_insert: lip 0xffff888834e71730 old lsn 0/0 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854217: xfs_ail_insert: lip 0xffff8885ca67e7c0 old lsn 0/0 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854217: xfs_ail_insert: lip 0xffff888800661a90 old lsn 0/0 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854218: xfs_ail_insert: lip 0xffff888828beecb8 old lsn 0/0 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854219: xfs_ail_delete: lip 0xffff888136421540 old lsn 75/28128 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854220: xfs_ail_delete: lip 0xffff888216cc8848 old lsn 75/28128 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854220: xfs_ail_delete: lip 0xffff8881364217e8 old lsn 75/28128 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854221: xfs_ail_delete: lip 0xffff888216cc86a0 old lsn 75/28128 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854222: xfs_ail_delete: lip 0xffff888834e71090 old lsn 75/28128 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854223: xfs_ail_delete: lip 0xffff8885ca67e120 old lsn 75/28128 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854224: xfs_ail_delete: lip 0xffff888800660ff0 old lsn 75/28128 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854224: xfs_ail_delete: lip 0xffff888828bee618 old lsn 75/28128 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854225: xfs_ail_delete: lip 0xffff888800661298 old lsn 75/28128 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854226: xfs_ail_delete: lip 0xffff888828bee7c0 old lsn 75/28128 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854227: xfs_ail_delete: lip 0xffff8885ca67e2c8 old lsn 75/28128 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854227: xfs_ail_delete: lip 0xffff888834e71238 old lsn 75/28128 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854228: xfs_ail_delete: lip 0xffff888136421a90 old lsn 75/28128 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854229: xfs_ail_delete: lip 0xffff888216cc84f8 old lsn 75/28128 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854229: xfs_ail_delete: lip 0xffff888136421d38 old lsn 75/28128 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854230: xfs_ail_delete: lip 0xffff888216cc8350 old lsn 75/28128 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854231: xfs_ail_delete: lip 0xffff888834e713e0 old lsn 75/28128 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854231: xfs_ail_delete: lip 0xffff8885ca67e470 old lsn 75/28128 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854232: xfs_ail_delete: lip 0xffff8885ca67e618 old lsn 75/28128 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854233: xfs_ail_delete: lip 0xffff888800661540 old lsn 75/28128 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854234: xfs_ail_delete: lip 0xffff888828bee968 old lsn 75/28128 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854234: xfs_ail_delete: lip 0xffff8888006617e8 old lsn 75/28128 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854235: xfs_ail_delete: lip 0xffff888828beeb10 old lsn 75/28128 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854235: xfs_ail_delete: lip 0xffff888834e71588 old lsn 75/28128 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854236: xfs_ail_delete: lip 0xffff888136421fe0 old lsn 75/28128 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854237: xfs_ail_delete: lip 0xffff888216cc81a8 old lsn 75/28128 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854238: xfs_ail_delete: lip 0xffff888136422288 old lsn 75/28128 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854239: xfs_ail_delete: lip 0xffff888834e71730 old lsn 75/28128 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854240: xfs_ail_delete: lip 0xffff88810deefd48 old lsn 75/28128 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > 255.854242: xfs_ail_delete: lip 0xffff888800661a90 old lsn 75/28128 new lsn 76/296 type XFS_LI_RUI flags IN_AIL > > 255.854243: xfs_ail_delete: lip 0xffff8885ca67e7c0 old lsn 75/28128 new lsn 76/296 type XFS_LI_EFI flags IN_AIL > > 255.854244: xfs_ail_delete: lip 0xffff888828beecb8 old lsn 75/28128 new lsn 76/296 type XFS_LI_CUI flags IN_AIL > > > > It's part of a checkpoint commit completion item processing > > intent and intent done items in the checkpoint. > > > > Basically, that series of inserts is exactly a batch of 32 inserts, > > followed by exactly a batch of 32 deletes. journal item completion > > batches processing into groups of 32 items, so this is two > > consecutive batches. > > > > So what makes this interesting? The interesting thing is the two > > batches contain -exactly the same intents-. > > > > IOWs, this is a series of intents, followed instantly in the same > > commit by their Done counterparts that remove the intents from the > > AIL. > > > > So why am I pointing this out? > > > > Well, if both the intent and the intent done are in the same > > checkpoint (we can see they are as teh "new lsn" is the current > > commit lsn), why did we bother to insert the intent into the AIL? > > We just did a -heap- of unnecessary processing - we can simply just > > free both the intent and the intent done without even putting them > > into the AIL in this situation. > ISTM this is part historical and perhaps part interface limitation (i.e. the ->iop_*() callbacks pre-date the CIL). Presumably it never made sense to remove dirty objects (outside of an abort) from the logging pipeline before the CIL was introduced. The iop_*() interface is also pretty rigid in terms of allowing items to react to log subsystem events as opposed to controlling them. > Follow up question, after a bit of time with this rattling around my > empty skull: if the intent and intent done are in the same CIL > checkpoint, do they even need to be written to the journal? > Hmm... that sounds reasonable in theory. Some thoughts that come to mind: 1.) We don't have to worry about crashing mid-checkpoint where the intent might have been written to the log and the done item not since we lose the entire checkpoint in that case, right? 2.) It's not immediately clear to me if relog would play well with such an optimization. That said, with relog having fairly isolated use cases and this being more of an optimization, we could always come up with a bypass mechanism if we wanted to ensure certain intents are always logged (outside of ops like quotaoff that IIRC uses sync transactions). 3.) What happens to implicit resources like the log reservation and log vectors associated with the intent items if they are committed in transactions as normal, but pulled out of the log pipeline "halfway through?" At a glance it looks like reservation could just remain associated with the CIL context, but we might need to do something to clean up log vectors. > i.e. can we cull in-memory intents from the CIL as soon as the > intent done is committed in memory to the CIL? > > Given that everything that the intent is supposed to replay is > committed to the same CIL context, I don't see why the intent and > the intent done actually need to be written to the log. If they are > written to the log, then all that will happen is log recovery will > read, process and cancel them as there is nothing to replay.... > The question to me is just how to implement it properly. The current done item implementation(s) look like we act on the log completion event of the done item, so we should expect to find the associated intent in the AIL by that point. I suppose we could leave the intent items as is and then wire up the ->iop_committing() for the done items. The latter could check for CIL residency of the intent, remove both if found, or otherwise fall back to the current logic. Hm? Brian > Cheers, > > Dave. > -- > Dave Chinner > david@xxxxxxxxxxxxx >
