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. 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? 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.... Cheers, Dave. -- Dave Chinner david@xxxxxxxxxxxxx
