)]}'
{
  "commit": "80168676ebfe4af51407d30f336d67f082d45201",
  "tree": "30f12022ffadd153cec05f460bdaa620690d7b12",
  "parents": [
    "899611ee7d373e5eeda08e9a8632684e1ebbbf00"
  ],
  "author": {
    "name": "Dave Chinner",
    "email": "dchinner@redhat.com",
    "time": "Fri Sep 24 18:13:44 2010 +1000"
  },
  "committer": {
    "name": "Alex Elder",
    "email": "aelder@sgi.com",
    "time": "Wed Sep 29 07:51:03 2010 -0500"
  },
  "message": "xfs: force background CIL push under sustained load\n\nI have been seeing occasional pauses in transaction throughput up to\n30s long under heavy parallel workloads. The only notable thing was\nthat the xfsaild was trying to be active during the pauses, but\nmaking no progress. It was running exactly 20 times a second (on the\n50ms no-progress backoff), and the number of pushbuf events was\nconstant across this time as well.  IOWs, the xfsaild appeared to be\nstuck on buffers that it could not push out.\n\nFurther investigation indicated that it was trying to push out inode\nbuffers that were pinned and/or locked. The xfsbufd was also getting\nwoken at the same frequency (by the xfsaild, no doubt) to push out\ndelayed write buffers. The xfsbufd was not making any progress\nbecause all the buffers in the delwri queue were pinned. This scan-\nand-make-no-progress dance went one in the trace for some seconds,\nbefore the xfssyncd came along an issued a log force, and then\nthings started going again.\n\nHowever, I noticed something strange about the log force - there\nwere way too many IO\u0027s issued. 516 log buffers were written, to be\nexact. That added up to 129MB of log IO, which got me very\ninterested because it\u0027s almost exactly 25% of the size of the log.\nHe delayed logging code is suppose to aggregate the minimum of 25%\nof the log or 8MB worth of changes before flushing. That\u0027s what\nreally puzzled me - why did a log force write 129MB instead of only\n8MB?\n\nEssentially what has happened is that no CIL pushes had occurred\nsince the previous tail push which cleared out 25% of the log space.\nThat caused all the new transactions to block because there wasn\u0027t\nlog space for them, but they kick the xfsaild to push the tail.\nHowever, the xfsaild was not making progress because there were\nbuffers it could not lock and flush, and the xfsbufd could not flush\nthem because they were pinned. As a result, both the xfsaild and the\nxfsbufd could not move the tail of the log forward without the CIL\nfirst committing.\n\nThe cause of the problem was that the background CIL push, which\nshould happen when 8MB of aggregated changes have been committed, is\nbeing held off by the concurrent transaction commit load. The\nbackground push does a down_write_trylock() which will fail if there\nis a concurrent transaction commit holding the push lock in read\nmode. With 8 CPUs all doing transactions as fast as they can, there\nwas enough concurrent transaction commits to hold off the background\npush until tail-pushing could no longer free log space, and the halt\nwould occur.\n\nIt should be noted that there is no reason why it would halt at 25%\nof log space used by a single CIL checkpoint. This bug could\ndefinitely violate the \"no transaction should be larger than half\nthe log\" requirement and hence result in corruption if the system\ncrashed under heavy load. This sort of bug is exactly the reason why\ndelayed logging was tagged as experimental....\n\nThe fix is to start blocking background pushes once the threshold\nhas been exceeded. Rework the threshold calculations to keep the\namount of log space a CIL checkpoint can use to below that of the\nAIL push threshold to avoid the problem completely.\n\nSigned-off-by: Dave Chinner \u003cdchinner@redhat.com\u003e\nReviewed-by: Alex Elder \u003caelder@sgi.com\u003e\nReviewed-by: Christoph Hellwig \u003chch@lst.de\u003e\n",
  "tree_diff": [
    {
      "type": "modify",
      "old_id": "ed575fb4b49597806200f676680ff787d5be9d12",
      "old_mode": 33188,
      "old_path": "fs/xfs/xfs_log_cil.c",
      "new_id": "7e206fc1fa362ed4bb761a8f5ad11ef39c2dd5c0",
      "new_mode": 33188,
      "new_path": "fs/xfs/xfs_log_cil.c"
    },
    {
      "type": "modify",
      "old_id": "ced52b98b322e3eb1be0e0c7dfc70f6096d0cd80",
      "old_mode": 33188,
      "old_path": "fs/xfs/xfs_log_priv.h",
      "new_id": "edcdfe01617f673bc1047caca3acc243f66a0658",
      "new_mode": 33188,
      "new_path": "fs/xfs/xfs_log_priv.h"
    }
  ]
}