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.
In the trace which is removing about 25,000 files and about a
million filesystem blocks, there are this many intents logged:
$ grep ail_insert: s.t |wc -l
244547
$ grep ail_insert: s.t |grep "CUI\|EFI\|RUI" |wc -l
203906
So >80% of the items being inserted into the AIL are intents, and a
large number of them have this "intent and done in the same
checkpoint" pattern associated with them. We should be catching this
during the CIL formatting (i.e. catching that the intent and the
intent done in teh same CIL checkpoint) and making sure we don't put
these anywhere near the AIL checkpoint completion....
Cheers,
Dave.
--
Dave Chinner
david@xxxxxxxxxxxxx
