hello Dave, On Fri, Dec 31, 2010 at 11:13:23AM +1100, Dave Chinner wrote: > On Mon, Dec 27, 2010 at 07:19:39PM +0200, Petre Rodan wrote: > > > > Hello Dave, > > > > On Tue, Dec 28, 2010 at 01:07:50AM +1100, Dave Chinner wrote: > > > Turn on the XFS tracing so we can see what is being written every > > > 36s. When the problem shows up: > > > > > > # echo 1 > /sys/kernel/debug/tracing/events/xfs/enable > > > # sleep 100 > > > # cat /sys/kernel/debug/tracing/trace > trace.out > > > # echo 0 > /sys/kernel/debug/tracing/events/xfs/enable > > > > > > And post the trace.out file for us to look at. > > > > attached. > > > > you can disregard all the lvm partitions ('dev 254:.*') since they are on a different drive, probably only 8:17 is of interest. > > Ok, I can see the problem. The original patch I tested: > > http://oss.sgi.com/archives/xfs/2010-08/msg00026.html > > Made the log covering dummy transaction a synchronous transaction so > that the log was written and the superblock unpinned immediately to > allow the xfsbufd to write back the superblock and empty the AIL > before the next log covering check. > > On review, the log covering dummy transaction got changed to an > async transaction, so the superblock buffer is not unpinned > immediately. This was the patch committed: > > http://oss.sgi.com/archives/xfs/2010-08/msg00197.html > > As a result, the success of log covering and idling is then > dependent on whether the log gets written to disk to unpin the > superblock buffer before the next xfssyncd run. It seems that there > is a large chance that this log write does not happen, so the > filesystem never idles correctly. I've reproduced it here, and only > in one test out of ten did the filesystem enter an idle state > correctly. I guess I was unlucky enough to hit that 1-in-10 case > when I tested the modified patch. > > I'll cook up a patch to make the log covering behave like the > original patch I sent... I presume that the new fix should be provided by "xfs: ensure log covering transactions are synchronous", so I tested 2.6.37 patched with it and then 2.6.38_rc1 that has it included. instead of having xfssyncd write to the drive every 36s, we now have this: 8,32 0 162 828.393976164 1413 A WS 977599761 + 2 <- (8,33) 977597713 8,32 0 163 828.393977820 1413 Q WS 977599761 + 2 [xfssyncd/sdc1] 8,32 0 167 846.401286530 1407 A W 2048 + 1 <- (8,33) 0 8,32 0 168 846.401288007 1407 Q W 2048 + 1 [xfsbufd/sdc1] 8,32 0 174 864.412155132 1413 A WS 977599763 + 2 <- (8,33) 977597715 8,32 0 175 864.412156637 1413 Q WS 977599763 + 2 [xfssyncd/sdc1] 8,32 1 240 882.467053566 1407 A W 2048 + 1 <- (8,33) 0 8,32 1 241 882.467055152 1407 Q W 2048 + 1 [xfsbufd/sdc1] 8,32 0 179 900.426084634 1413 A WS 977599765 + 2 <- (8,33) 977597717 8,32 0 180 900.426086076 1413 Q WS 977599765 + 2 [xfssyncd/sdc1] 8,32 0 185 918.457066312 1407 A W 2048 + 1 <- (8,33) 0 8,32 0 186 918.457068003 1407 Q W 2048 + 1 [xfsbufd/sdc1] 8,32 1 252 936.448120095 1413 A WS 977599767 + 2 <- (8,33) 977597719 8,32 1 253 936.448121740 1413 Q WS 977599767 + 2 [xfssyncd/sdc1] 8,32 0 192 954.447207652 1407 A W 2048 + 1 <- (8,33) 0 8,32 0 193 954.447209114 1407 Q W 2048 + 1 [xfsbufd/sdc1] 8,32 0 199 972.458423873 1413 A WS 977599769 + 2 <- (8,33) 977597721 8,32 0 200 972.458425189 1413 Q WS 977599769 + 2 [xfssyncd/sdc1] 8,32 1 266 990.457562449 1407 A W 2048 + 1 <- (8,33) 0 8,32 1 267 990.457563909 1407 Q W 2048 + 1 [xfsbufd/sdc1] 8,32 0 204 1008.476781955 1413 A WS 977599771 + 2 <- (8,33) 977597723 8,32 0 205 1008.476783410 1413 Q WS 977599771 + 2 [xfssyncd/sdc1] 8,32 1 278 1026.531988963 1407 A W 2048 + 1 <- (8,33) 0 8,32 1 279 1026.531990718 1407 Q W 2048 + 1 [xfsbufd/sdc1] 8,32 0 209 1044.491342417 1413 A WS 977599773 + 2 <- (8,33) 977597725 8,32 0 210 1044.491344042 1413 Q WS 977599773 + 2 [xfssyncd/sdc1] 8,32 0 214 1062.502603664 1407 A W 2048 + 1 <- (8,33) 0 8,32 0 215 1062.502605117 1407 Q W 2048 + 1 [xfsbufd/sdc1] 8,32 0 216 1062.502611005 1407 G W 2048 + 1 [xfsbufd/sdc1] in other words xfsyncd and xfsbufd now alternate at 18s intervals keeping the drive busy with nothing constructive hours after the last write to the drive. to add to the misfortune, 'mount -o remount ' is no longer able to bring the drive to a quiet state since 2.6.37, so now the only way to achieve an idle drive is to fully umount and then remount the partition. just for the record, this is a different drive then at the beginning of the thread, and it has these parameters: meta-data=/dev/sdc1 isize=256 agcount=4, agsize=61047552 blks = sectsz=512 attr=2 data = bsize=4096 blocks=244190208, imaxpct=25 = sunit=0 swidth=0 blks naming =version 2 bsize=4096 ascii-ci=0 log =internal bsize=4096 blocks=119233, version=2 = sectsz=512 sunit=0 blks, lazy-count=0 realtime =none extsz=4096 blocks=0, rtextents=0 attached you'll find the trace (with accesses to other drives filtered out). cheers, peter > > Cheers, > > Dave. > -- > Dave Chinner > david@xxxxxxxxxxxxx -- petre rodan <petre.rodan@xxxxxxxxxx> Technical Manager Simplex SRL, Bucharest
# tracer: nop # # TASK-PID CPU# TIMESTAMP FUNCTION # | | | | | xfsbufd/sdc1-1407 [000] 3328.516937: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3328.516942: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3329.715360: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3329.715364: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3330.913851: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3330.913856: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3332.112309: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3332.112314: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3333.310767: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3333.310771: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3334.509225: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3334.509229: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3335.707682: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3335.707686: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3336.906140: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3336.906145: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3338.104598: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3338.104602: xfs_buf_delwri_split: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfsbufd xfsbufd/sdc1-1407 [000] 3338.104605: xfs_buf_iorequest: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_bdstrat_cb xfsbufd/sdc1-1407 [000] 3338.104606: xfs_buf_hold: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iorequest xfsbufd/sdc1-1407 [000] 3338.104628: xfs_buf_rele: dev 8:33 bno 0x0 len 0x200 hold 4 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iorequest <idle>-0 [001] 3338.105096: xfs_buf_ioerror: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 error 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_buf_bio_end_io <idle>-0 [001] 3338.105100: xfs_buf_iodone: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller _xfs_buf_ioend kworker/1:0-2942 [001] 3338.105137: xfs_buf_rele: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone kworker/1:0-2942 [001] 3338.105139: xfs_buf_iodone: dev 8:33 bno 0x0 len 0x200 hold 2 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone_callbacks kworker/1:0-2942 [001] 3338.105141: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 2 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone_work kworker/1:0-2942 [001] 3338.105141: xfs_buf_rele: dev 8:33 bno 0x0 len 0x200 hold 2 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone_work xfssyncd/sdc1-1413 [000] 3356.093456: xfs_log_reserve: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 1 t_curr_res 2740 t_unit_res 2740 t_flags XLOG_TIC_INITED reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428523008 grant_write_cycle 2 grant_write_bytes 428523008 curr_cycle 2 curr_block 836959 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3356.093462: xfs_log_grant_enter: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 1 t_curr_res 2740 t_unit_res 2740 t_flags XLOG_TIC_INITED reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428523008 grant_write_cycle 2 grant_write_bytes 428523008 curr_cycle 2 curr_block 836959 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3356.093463: xfs_log_grant_exit: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 1 t_curr_res 2740 t_unit_res 2740 t_flags XLOG_TIC_INITED reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428525748 grant_write_cycle 2 grant_write_bytes 428525748 curr_cycle 2 curr_block 836959 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3356.093465: xfs_buf_lock: dev 8:33 bno 0x0 len 0x200 hold 1 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|PAGES caller xfs_getsb xfssyncd/sdc1-1413 [000] 3356.093467: xfs_buf_lock_done: dev 8:33 bno 0x0 len 0x200 hold 1 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_getsb xfssyncd/sdc1-1413 [000] 3356.093468: xfs_buf_hold: dev 8:33 bno 0x0 len 0x200 hold 1 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_getsb xfssyncd/sdc1-1413 [000] 3356.093470: xfs_buf_hold: dev 8:33 bno 0x0 len 0x200 hold 2 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_item_init xfssyncd/sdc1-1413 [000] 3356.093472: xfs_trans_getsb: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags |MAPPED|ASYNC|DONE|PAGES recur 0 refcount 1 bliflags lidesc 0xffff8800dd23f8f0 liflags xfssyncd/sdc1-1413 [000] 3356.093474: xfs_trans_log_buf: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES recur 0 refcount 1 bliflags lidesc 0xffff8800dd23f8f0 liflags xfssyncd/sdc1-1413 [000] 3356.093477: xfs_buf_item_size: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES recur 0 refcount 1 bliflags |DIRTY|LOGGED lidesc 0xffff8800dd23f8f0 liflags xfssyncd/sdc1-1413 [000] 3356.093479: xfs_buf_item_format: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES recur 0 refcount 1 bliflags |DIRTY|LOGGED lidesc 0xffff8800dd23f8f0 liflags xfssyncd/sdc1-1413 [000] 3356.093480: xfs_buf_item_pin: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES recur 0 refcount 1 bliflags |DIRTY|LOGGED lidesc 0xffff8800dd23f8f0 liflags xfssyncd/sdc1-1413 [000] 3356.093487: xfs_log_done_nonperm: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 1 t_curr_res 2000 t_unit_res 2740 t_flags reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428525748 grant_write_cycle 2 grant_write_bytes 428525748 curr_cycle 2 curr_block 836959 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3356.093488: xfs_log_ungrant_enter: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 0 t_curr_res 2000 t_unit_res 2740 t_flags reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428525748 grant_write_cycle 2 grant_write_bytes 428525748 curr_cycle 2 curr_block 836959 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3356.093489: xfs_log_ungrant_sub: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 0 t_curr_res 2000 t_unit_res 2740 t_flags reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428525748 grant_write_cycle 2 grant_write_bytes 428525748 curr_cycle 2 curr_block 836959 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3356.093489: xfs_log_ungrant_exit: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 0 t_curr_res 2000 t_unit_res 2740 t_flags reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428523748 grant_write_cycle 2 grant_write_bytes 428523748 curr_cycle 2 curr_block 836959 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3356.093492: xfs_trans_commit_lsn: dev 8:33 trans 0xffff8800dd2b7ea0 commit_lsn 0x2000cc55f xfssyncd/sdc1-1413 [000] 3356.093495: xfs_buf_item_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 1 lock 0 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES recur 0 refcount 2 bliflags |DIRTY lidesc 0x (null) liflags xfssyncd/sdc1-1413 [000] 3356.093496: xfs_buf_delwri_queue: dev 8:33 bno 0x0 len 0x200 hold 4 pincount 1 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES caller xfs_buf_unlock xfssyncd/sdc1-1413 [000] 3356.093501: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 4 pincount 1 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_item_unlock xfssyncd/sdc1-1413 [000] 3356.093502: xfs_buf_rele: dev 8:33 bno 0x0 len 0x200 hold 4 pincount 1 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_item_unlock xfssyncd/sdc1-1413 [000] 3356.093506: xfs_buf_iorequest: dev 8:33 bno 0x3a44f57f len 0x8000 hold 1 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|ORDERED|PAGES|RUN_QUEUES|0x2000 caller xlog_bdstrat xfssyncd/sdc1-1413 [000] 3356.093507: xfs_buf_hold: dev 8:33 bno 0x3a44f57f len 0x8000 hold 1 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|ORDERED|PAGES|RUN_QUEUES|0x2000 caller xfs_buf_iorequest xfssyncd/sdc1-1413 [000] 3356.093541: xfs_buf_rele: dev 8:33 bno 0x3a44f57f len 0x8000 hold 2 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|ORDERED|PAGES|RUN_QUEUES|0x2000 caller xfs_buf_iorequest <idle>-0 [001] 3356.113311: xfs_buf_ioerror: dev 8:33 bno 0x3a44f57f len 0x8000 hold 1 pincount 0 lock 0 error 0 flags WRITE|MAPPED|ASYNC|DONE|ORDERED|PAGES|RUN_QUEUES|0x2000 caller xfs_buf_bio_end_io <idle>-0 [001] 3356.113316: xfs_buf_iodone: dev 8:33 bno 0x3a44f57f len 0x8000 hold 1 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|ORDERED|PAGES|RUN_QUEUES|0x2000 caller _xfs_buf_ioend kworker/1:0-2942 [001] 3356.113359: xfs_buf_item_committed: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 1 lock 1 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q recur 0 refcount 1 bliflags |DIRTY lidesc 0x (null) liflags kworker/1:0-2942 [001] 3356.113362: xfs_buf_item_unpin: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 1 lock 1 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q recur 0 refcount 1 bliflags |DIRTY lidesc 0x (null) liflags IN_AIL xfsbufd/sdc1-1407 [001] 3357.291895: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3357.291899: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3358.490410: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3358.490415: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3359.688802: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3359.688806: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3360.887269: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3360.887273: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3362.085688: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3362.085692: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3363.284175: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3363.284180: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3364.482639: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3364.482644: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3365.681096: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3365.681100: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3366.879566: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3366.879571: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3368.078025: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3368.078030: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3369.276482: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3369.276486: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3370.474939: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3370.474944: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3371.673391: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3371.673395: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3372.871848: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3372.871853: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3374.070306: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3374.070310: xfs_buf_delwri_split: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfsbufd xfsbufd/sdc1-1407 [000] 3374.070312: xfs_buf_iorequest: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_bdstrat_cb xfsbufd/sdc1-1407 [000] 3374.070314: xfs_buf_hold: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iorequest xfsbufd/sdc1-1407 [000] 3374.070331: xfs_buf_rele: dev 8:33 bno 0x0 len 0x200 hold 4 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iorequest <idle>-0 [001] 3374.070797: xfs_buf_ioerror: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 error 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_buf_bio_end_io <idle>-0 [001] 3374.070801: xfs_buf_iodone: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller _xfs_buf_ioend kworker/1:0-2942 [001] 3374.070839: xfs_buf_rele: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone kworker/1:0-2942 [001] 3374.070841: xfs_buf_iodone: dev 8:33 bno 0x0 len 0x200 hold 2 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone_callbacks kworker/1:0-2942 [001] 3374.070843: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 2 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone_work kworker/1:0-2942 [001] 3374.070843: xfs_buf_rele: dev 8:33 bno 0x0 len 0x200 hold 2 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone_work xfssyncd/sdc1-1413 [000] 3392.067122: xfs_log_reserve: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 1 t_curr_res 2740 t_unit_res 2740 t_flags XLOG_TIC_INITED reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428524032 grant_write_cycle 2 grant_write_bytes 428524032 curr_cycle 2 curr_block 836961 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3392.067127: xfs_log_grant_enter: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 1 t_curr_res 2740 t_unit_res 2740 t_flags XLOG_TIC_INITED reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428524032 grant_write_cycle 2 grant_write_bytes 428524032 curr_cycle 2 curr_block 836961 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3392.067129: xfs_log_grant_exit: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 1 t_curr_res 2740 t_unit_res 2740 t_flags XLOG_TIC_INITED reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428526772 grant_write_cycle 2 grant_write_bytes 428526772 curr_cycle 2 curr_block 836961 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3392.067131: xfs_buf_lock: dev 8:33 bno 0x0 len 0x200 hold 1 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|PAGES caller xfs_getsb xfssyncd/sdc1-1413 [000] 3392.067133: xfs_buf_lock_done: dev 8:33 bno 0x0 len 0x200 hold 1 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_getsb xfssyncd/sdc1-1413 [000] 3392.067134: xfs_buf_hold: dev 8:33 bno 0x0 len 0x200 hold 1 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_getsb xfssyncd/sdc1-1413 [000] 3392.067138: xfs_buf_hold: dev 8:33 bno 0x0 len 0x200 hold 2 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_item_init xfssyncd/sdc1-1413 [000] 3392.067140: xfs_trans_getsb: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags |MAPPED|ASYNC|DONE|PAGES recur 0 refcount 1 bliflags lidesc 0xffff8800dca401f0 liflags xfssyncd/sdc1-1413 [000] 3392.067142: xfs_trans_log_buf: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES recur 0 refcount 1 bliflags lidesc 0xffff8800dca401f0 liflags xfssyncd/sdc1-1413 [000] 3392.067145: xfs_buf_item_size: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES recur 0 refcount 1 bliflags |DIRTY|LOGGED lidesc 0xffff8800dca401f0 liflags xfssyncd/sdc1-1413 [000] 3392.067147: xfs_buf_item_format: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES recur 0 refcount 1 bliflags |DIRTY|LOGGED lidesc 0xffff8800dca401f0 liflags xfssyncd/sdc1-1413 [000] 3392.067148: xfs_buf_item_pin: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES recur 0 refcount 1 bliflags |DIRTY|LOGGED lidesc 0xffff8800dca401f0 liflags xfssyncd/sdc1-1413 [000] 3392.067154: xfs_log_done_nonperm: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 1 t_curr_res 2000 t_unit_res 2740 t_flags reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428526772 grant_write_cycle 2 grant_write_bytes 428526772 curr_cycle 2 curr_block 836961 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3392.067155: xfs_log_ungrant_enter: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 0 t_curr_res 2000 t_unit_res 2740 t_flags reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428526772 grant_write_cycle 2 grant_write_bytes 428526772 curr_cycle 2 curr_block 836961 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3392.067156: xfs_log_ungrant_sub: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 0 t_curr_res 2000 t_unit_res 2740 t_flags reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428526772 grant_write_cycle 2 grant_write_bytes 428526772 curr_cycle 2 curr_block 836961 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3392.067156: xfs_log_ungrant_exit: dev 8:33 type DUMMY1 t_ocnt 1 t_cnt 0 t_curr_res 2000 t_unit_res 2740 t_flags reserveq empty writeq empty grant_reserve_cycle 2 grant_reserve_bytes 428524772 grant_write_cycle 2 grant_write_bytes 428524772 curr_cycle 2 curr_block 836961 tail_cycle 2 tail_block 810683 xfssyncd/sdc1-1413 [000] 3392.067159: xfs_trans_commit_lsn: dev 8:33 trans 0xffff8800dca3a4c8 commit_lsn 0x2000cc561 xfssyncd/sdc1-1413 [000] 3392.067161: xfs_buf_item_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 1 lock 0 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES recur 0 refcount 2 bliflags |DIRTY lidesc 0x (null) liflags xfssyncd/sdc1-1413 [000] 3392.067163: xfs_buf_delwri_queue: dev 8:33 bno 0x0 len 0x200 hold 4 pincount 1 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES caller xfs_buf_unlock xfssyncd/sdc1-1413 [000] 3392.067168: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 4 pincount 1 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_item_unlock xfssyncd/sdc1-1413 [000] 3392.067169: xfs_buf_rele: dev 8:33 bno 0x0 len 0x200 hold 4 pincount 1 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_item_unlock xfssyncd/sdc1-1413 [000] 3392.067173: xfs_buf_iorequest: dev 8:33 bno 0x3a44f581 len 0x8000 hold 1 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|ORDERED|PAGES|RUN_QUEUES|0x2000 caller xlog_bdstrat xfssyncd/sdc1-1413 [000] 3392.067174: xfs_buf_hold: dev 8:33 bno 0x3a44f581 len 0x8000 hold 1 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|ORDERED|PAGES|RUN_QUEUES|0x2000 caller xfs_buf_iorequest xfssyncd/sdc1-1413 [000] 3392.067211: xfs_buf_rele: dev 8:33 bno 0x3a44f581 len 0x8000 hold 2 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|ORDERED|PAGES|RUN_QUEUES|0x2000 caller xfs_buf_iorequest <idle>-0 [001] 3392.084946: xfs_buf_ioerror: dev 8:33 bno 0x3a44f581 len 0x8000 hold 1 pincount 0 lock 0 error 0 flags WRITE|MAPPED|ASYNC|DONE|ORDERED|PAGES|RUN_QUEUES|0x2000 caller xfs_buf_bio_end_io <idle>-0 [001] 3392.084951: xfs_buf_iodone: dev 8:33 bno 0x3a44f581 len 0x8000 hold 1 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|ORDERED|PAGES|RUN_QUEUES|0x2000 caller _xfs_buf_ioend kworker/1:0-2942 [001] 3392.084986: xfs_buf_item_committed: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 1 lock 1 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q recur 0 refcount 1 bliflags |DIRTY lidesc 0x (null) liflags kworker/1:0-2942 [001] 3392.084989: xfs_buf_item_unpin: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 1 lock 1 flags |MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q recur 0 refcount 1 bliflags |DIRTY lidesc 0x (null) liflags IN_AIL xfsbufd/sdc1-1407 [001] 3393.269554: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3393.269558: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3394.472001: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3394.472006: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3395.674456: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3395.674460: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3396.872917: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [001] 3396.872921: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3398.071397: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3398.071401: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3399.269841: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3399.269845: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3400.468299: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3400.468304: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3401.666718: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3401.666722: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3402.865235: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3402.865239: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3404.063706: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3404.063710: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3405.262163: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3405.262167: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3406.460622: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3406.460626: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3407.659078: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3407.659083: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3408.857536: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3408.857540: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3410.055988: xfs_buf_cond_lock: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|DELWRI|PAGES|DELWRI_Q caller xfs_buf_delwri_split xfsbufd/sdc1-1407 [000] 3410.055992: xfs_buf_delwri_split: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfsbufd xfsbufd/sdc1-1407 [000] 3410.055995: xfs_buf_iorequest: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_bdstrat_cb xfsbufd/sdc1-1407 [000] 3410.055996: xfs_buf_hold: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iorequest xfsbufd/sdc1-1407 [000] 3410.056014: xfs_buf_rele: dev 8:33 bno 0x0 len 0x200 hold 4 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iorequest <idle>-0 [001] 3410.056482: xfs_buf_ioerror: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 error 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller xfs_buf_bio_end_io <idle>-0 [001] 3410.056486: xfs_buf_iodone: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags WRITE|MAPPED|ASYNC|DONE|PAGES caller _xfs_buf_ioend kworker/1:0-2942 [001] 3410.056524: xfs_buf_rele: dev 8:33 bno 0x0 len 0x200 hold 3 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone kworker/1:0-2942 [001] 3410.056526: xfs_buf_iodone: dev 8:33 bno 0x0 len 0x200 hold 2 pincount 0 lock 0 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone_callbacks kworker/1:0-2942 [001] 3410.056527: xfs_buf_unlock: dev 8:33 bno 0x0 len 0x200 hold 2 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone_work kworker/1:0-2942 [001] 3410.056528: xfs_buf_rele: dev 8:33 bno 0x0 len 0x200 hold 2 pincount 0 lock 1 flags MAPPED|ASYNC|DONE|PAGES caller xfs_buf_iodone_work
Attachment:
pgplqmgdzM7Wn.pgp
Description: PGP signature
_______________________________________________ xfs mailing list xfs@xxxxxxxxxxx http://oss.sgi.com/mailman/listinfo/xfs