| blob | b11a2c655269bd583e066a29614adf8a28b605ff |
1 ext4: debugging patches for the bio code
3 ---
4 block/blk-core.c | 17 ++++++++++
5 fs/buffer.c | 36 ++++++++++++++++++++++
6 fs/ext4/inode.c | 18 +++++++++++
7 fs/ext4/mballoc.c | 8 ++++-
8 fs/ext4/page-io.c | 80 +++++++++++++++++++++++++++++++++++++++++++++++-
9 fs/jbd2/commit.c | 18 +++++++++++
10 fs/jbd2/transaction.c | 5 +++
11 mm/filemap.c | 7 ++++
12 8 files changed, 186 insertions(+), 3 deletions(-)
14 diff --git a/block/blk-core.c b/block/blk-core.c
15 index 32a1c12..115574b 100644
16 --- a/block/blk-core.c
17 +++ b/block/blk-core.c
18 @@ -248,6 +248,9 @@ int blk_remove_plug(struct request_queue *q)
19 if (!queue_flag_test_and_clear(QUEUE_FLAG_PLUGGED, q))
20 return 0;
22 +#if 1 /* PDEBUG */
23 + trace_printk("del timer %s\n", q->backing_dev_info.name);
24 +#endif
25 del_timer(&q->unplug_timer);
26 return 1;
27 }
28 @@ -379,6 +382,9 @@ EXPORT_SYMBOL(blk_stop_queue);
29 */
30 void blk_sync_queue(struct request_queue *q)
31 {
32 +#if 1 /* PDEBUG */
33 + trace_printk("del timer %s\n", q->backing_dev_info.name);
34 +#endif
35 del_timer_sync(&q->unplug_timer);
36 del_timer_sync(&q->timeout);
37 cancel_work_sync(&q->unplug_work);
38 @@ -1525,6 +1531,17 @@ static inline void __generic_make_request(struct bio *bio)
39 trace_block_bio_queue(q, bio);
41 ret = q->make_request_fn(q, bio);
42 +
43 +#if 1 /* PDEBUG */
44 + {
45 + char str[KSYM_SYMBOL_LEN];
46 +
47 + kallsyms_lookup((unsigned long) q->make_request_fn,
48 + NULL, NULL, NULL, str);
49 + trace_printk("returned from %s (pid %d)\n",
50 + str, task_pid_nr(current));
51 + }
52 +#endif
53 } while (ret);
55 return;
56 diff --git a/fs/buffer.c b/fs/buffer.c
57 index 3e7dca2..ed188f5 100644
58 --- a/fs/buffer.c
59 +++ b/fs/buffer.c
60 @@ -70,6 +70,19 @@ static int sync_buffer(void *word)
62 void __lock_buffer(struct buffer_head *bh)
63 {
64 +#if 1 /* PDEBUG */
65 + void *ip = __builtin_return_address(0);
66 + char str[KSYM_SYMBOL_LEN];
67 + char b[BDEVNAME_SIZE];
68 +
69 + if (buffer_locked(bh)) {
70 + kallsyms_lookup((unsigned long) ip, NULL, NULL, NULL, str);
71 + trace_printk("lock bh %s blk %lu, ret_pc %p (%s) pid %d\n",
72 + bdevname(bh->b_bdev, b),
73 + (unsigned long) bh->b_blocknr, ip, str,
74 + task_pid_nr(current));
75 + }
76 +#endif
77 wait_on_bit_lock(&bh->b_state, BH_Lock, sync_buffer,
78 TASK_UNINTERRUPTIBLE);
79 }
80 @@ -90,6 +103,17 @@ EXPORT_SYMBOL(unlock_buffer);
81 */
82 void __wait_on_buffer(struct buffer_head * bh)
83 {
84 +#if 1 /* PDEBUG */
85 + void *ip = __builtin_return_address(0);
86 + char str[KSYM_SYMBOL_LEN];
87 + char b[BDEVNAME_SIZE];
88 +
89 + kallsyms_lookup((unsigned long) ip, NULL, NULL, NULL, str);
90 + trace_printk("dev %s blk %lu, ret_pc %p (%s) pid %d\n",
91 + bdevname(bh->b_bdev, b),
92 + (unsigned long) bh->b_blocknr, ip, str,
93 + task_pid_nr(current));
94 +#endif
95 wait_on_bit(&bh->b_state, BH_Lock, sync_buffer, TASK_UNINTERRUPTIBLE);
96 }
97 EXPORT_SYMBOL(__wait_on_buffer);
98 @@ -2906,6 +2930,18 @@ int submit_bh(int rw, struct buffer_head * bh)
99 struct bio *bio;
100 int ret = 0;
102 +#if 1 /* PDEBUG */
103 + void *ip = __builtin_return_address(0);
104 + char str[KSYM_SYMBOL_LEN];
105 + char b[BDEVNAME_SIZE];
106 +
107 + kallsyms_lookup((unsigned long) ip, NULL, NULL, NULL, str);
108 + trace_printk("dev %s blk %lu, ret_pc %p (%s) pid %d\n",
109 + bdevname(bh->b_bdev, b),
110 + (unsigned long) bh->b_blocknr, ip, str,
111 + task_pid_nr(current));
112 +#endif
113 +
114 BUG_ON(!buffer_locked(bh));
115 BUG_ON(!buffer_mapped(bh));
116 BUG_ON(!bh->b_end_io);
117 diff --git a/fs/ext4/inode.c b/fs/ext4/inode.c
118 index 79fdace..82eafb9 100644
119 --- a/fs/ext4/inode.c
120 +++ b/fs/ext4/inode.c
121 @@ -2029,6 +2029,11 @@ static int mpage_da_submit_io(struct mpage_da_data *mpd,
122 index = mpd->first_page;
123 end = mpd->next_page - 1;
125 +#if 1 /* PDEBUG */
126 + trace_printk("%s: ino %lu index %lu end %lu size %lu\n",
127 + inode->i_sb->s_id, inode->i_ino,
128 + index, end, (unsigned long) size);
129 +#endif
130 pagevec_init(&pvec, 0);
131 while (index <= end) {
132 nr_pages = pagevec_lookup(&pvec, mapping, index, PAGEVEC_SIZE);
133 @@ -3654,6 +3659,9 @@ int flush_completed_IO(struct inode *inode)
134 if (list_empty(&ei->i_completed_io_list))
135 return ret;
137 +#if 1 /* PDEBUG */
138 + trace_printk("%s: ino %lu\n", inode->i_sb->s_id, inode->i_ino);
139 +#endif
140 dump_completed_IO(inode);
141 spin_lock_irqsave(&ei->i_completed_io_lock, flags);
142 while (!list_empty(&ei->i_completed_io_list)){
143 @@ -3694,6 +3702,16 @@ static void ext4_end_io_dio(struct kiocb *iocb, loff_t offset,
144 unsigned long flags;
145 struct ext4_inode_info *ei;
147 +#if 1 /* PDEBUG */
148 + if (io_end)
149 + trace_printk("%s: ino %lu io_end %p size %lu\n",
150 + io_end->inode->i_sb->s_id,
151 + io_end->inode->i_ino, io_end,
152 + (unsigned long) size);
153 + else
154 + trace_printk("null io_end\n");
155 +#endif
156 +
157 /* if not async direct IO or dio with 0 bytes write, just return */
158 if (!io_end || !size)
159 goto out;
160 diff --git a/fs/ext4/mballoc.c b/fs/ext4/mballoc.c
161 index d732ef5..d1b68b7 100644
162 --- a/fs/ext4/mballoc.c
163 +++ b/fs/ext4/mballoc.c
164 @@ -861,8 +861,14 @@ static int ext4_mb_init_cache(struct page *page, char *incore)
165 }
167 /* wait for I/O completion */
168 - for (i = 0; i < groups_per_page && bh[i]; i++)
169 + for (i = 0; i < groups_per_page && bh[i]; i++) {
170 +#if 1 /* PDEBUG */
171 + if (buffer_locked(bh[i]))
172 + trace_printk("%s: wait on %lu\n", sb->s_id,
173 + (unsigned long) bh[i]->b_blocknr);
174 +#endif
175 wait_on_buffer(bh[i]);
176 + }
178 err = -EIO;
179 for (i = 0; i < groups_per_page && bh[i]; i++)
180 diff --git a/fs/ext4/page-io.c b/fs/ext4/page-io.c
181 index ccce2c6..c2f42e0 100644
182 --- a/fs/ext4/page-io.c
183 +++ b/fs/ext4/page-io.c
184 @@ -30,6 +30,8 @@
185 #include "acl.h"
186 #include "ext4_extents.h"
188 +#define PDEBUG
189 +
190 static struct kmem_cache *io_page_cachep, *io_end_cachep;
192 int __init init_ext4_pageio(void)
193 @@ -56,6 +58,9 @@ void ext4_free_io_end(ext4_io_end_t *io)
194 {
195 int i;
197 +#ifdef PDEBUG
198 + trace_printk("%p\n", io);
199 +#endif
200 BUG_ON(!io);
201 if (io->page)
202 put_page(io->page);
203 @@ -63,6 +68,11 @@ void ext4_free_io_end(ext4_io_end_t *io)
204 if (--io->pages[i]->p_count == 0) {
205 struct page *page = io->pages[i]->p_page;
207 +#ifdef PDEBUG
208 + trace_printk("%s: end_page_writeback for %lu:%lu\n",
209 + io->inode->i_sb->s_id, io->inode->i_ino,
210 + (unsigned long) page->index);
211 +#endif
212 end_page_writeback(page);
213 put_page(page);
214 kmem_cache_free(io_page_cachep, io->pages[i]);
215 @@ -121,6 +131,9 @@ static void ext4_end_io_work(struct work_struct *work)
216 int ret;
218 mutex_lock(&inode->i_mutex);
219 +#ifdef PDEBUG
220 + trace_printk("%p\n", io);
221 +#endif
222 ret = ext4_end_io_nolock(io);
223 if (ret < 0) {
224 mutex_unlock(&inode->i_mutex);
225 @@ -147,6 +160,9 @@ ext4_io_end_t *ext4_init_io_end(struct inode *inode, gfp_t flags)
226 INIT_WORK(&io->work, ext4_end_io_work);
227 INIT_LIST_HEAD(&io->list);
228 }
229 +#ifdef PDEBUG
230 + trace_printk("%p\n", io);
231 +#endif
232 return io;
233 }
235 @@ -175,6 +191,12 @@ static void ext4_end_bio(struct bio *bio, int error)
237 BUG_ON(!io_end);
238 inode = io_end->inode;
239 +#ifdef PDEBUG
240 + trace_printk("%s: enter: ino %lu offset %lu size %ld io_end=%p\n",
241 + inode->i_sb->s_id, inode->i_ino,
242 + (unsigned long) io_end->offset,
243 + (long) io_end->size, io_end);
244 +#endif
245 bio->bi_private = NULL;
246 bio->bi_end_io = NULL;
247 if (test_bit(BIO_UPTODATE, &bio->bi_flags))
248 @@ -235,6 +257,12 @@ static void ext4_end_bio(struct bio *bio, int error)
249 if (--io_end->pages[i]->p_count == 0) {
250 struct page *page = io_end->pages[i]->p_page;
252 +#ifdef PDEBUG
253 + trace_printk("%s: end_page_writeback for %lu:%lu\n",
254 + io_end->inode->i_sb->s_id,
255 + io_end->inode->i_ino,
256 + (unsigned long) page->index);
257 +#endif
258 end_page_writeback(page);
259 put_page(page);
260 kmem_cache_free(io_page_cachep, io_end->pages[i]);
261 @@ -261,12 +289,24 @@ static void ext4_end_bio(struct bio *bio, int error)
262 wq = EXT4_SB(inode->i_sb)->dio_unwritten_wq;
263 /* queue the work to convert unwritten extents to written */
264 queue_work(wq, &io_end->work);
265 +#ifdef PDEBUG
266 + trace_printk("%s: exit: ino %lu\n", inode->i_sb->s_id,
267 + io_end->inode->i_ino);
268 +#endif
269 }
271 void ext4_io_submit(struct ext4_io_submit *io)
272 {
273 struct bio *bio = io->io_bio;
275 +#ifdef PDEBUG
276 + if (io->io_end)
277 + trace_printk("%s: io submitted io_end %p\n",
278 + io->io_end->inode->i_sb->s_id, io->io_end);
279 + else
280 + trace_printk("io submitted io_end %p\n",
281 + io->io_end);
282 +#endif
283 if (bio) {
284 bio_get(io->io_bio);
285 submit_bio(io->io_op, io->io_bio);
286 @@ -308,10 +348,14 @@ static int io_submit_init(struct ext4_io_submit *io,
287 io->io_op = (wbc->sync_mode == WB_SYNC_ALL ?
288 WRITE_SYNC_PLUG : WRITE);
289 io->io_next_block = bh->b_blocknr;
290 +#ifdef PDEBUG
291 + trace_printk("%s: io_submit_init for ino %lu, nvecs = %d\n",
292 + inode->i_sb->s_id, inode->i_ino, nvecs);
293 +#endif
294 return 0;
295 }
297 -static int io_submit_add_bh(struct ext4_io_submit *io,
298 +static noinline int io_submit_add_bh(struct ext4_io_submit *io,
299 struct ext4_io_page *io_page,
300 struct inode *inode,
301 struct writeback_control *wbc,
302 @@ -320,6 +364,14 @@ static int io_submit_add_bh(struct ext4_io_submit *io,
303 ext4_io_end_t *io_end;
304 int ret;
306 +#ifdef PDEBUG
307 + trace_printk("%s enter: ino %lu blk %lu %s%s%s%s\n", inode->i_sb->s_id,
308 + inode->i_ino, (unsigned long) bh->b_blocknr,
309 + buffer_new(bh) ? "N" : "",
310 + buffer_mapped(bh) ? "M" : "",
311 + buffer_delay(bh) ? "D" : "",
312 + buffer_dirty(bh) ? "d" : "");
313 +#endif
314 if (buffer_new(bh)) {
315 clear_buffer_new(bh);
316 unmap_underlying_metadata(bh->b_bdev, bh->b_blocknr);
317 @@ -351,13 +403,29 @@ submit_and_retry:
318 io->io_end->size += bh->b_size;
319 io->io_next_block++;
320 ret = bio_add_page(io->io_bio, bh->b_page, bh->b_size, bh_offset(bh));
321 - if (ret != bh->b_size)
322 + if (ret != bh->b_size) {
323 +#ifdef PDEBUG
324 + trace_printk("%s: submit and retry (ret = %d, size=%d, "
325 + "offset=%lu)\n", inode->i_sb->s_id, ret,
326 + bh->b_size, bh_offset(bh));
327 +#endif
328 goto submit_and_retry;
329 + }
330 if ((io_end->num_io_pages == 0) ||
331 (io_end->pages[io_end->num_io_pages-1] != io_page)) {
332 io_end->pages[io_end->num_io_pages++] = io_page;
333 io_page->p_count++;
334 }
335 +#ifdef PDEBUG
336 + if (io->io_end)
337 + trace_printk("%s: exit: ino %lu offset %lu size %ld\n",
338 + inode->i_sb->s_id, inode->i_ino,
339 + (unsigned long) io->io_end->offset,
340 + (unsigned long) io->io_end->size);
341 + else
342 + trace_printk("%s: exit: ino %lu no_io_end\n",
343 + inode->i_sb->s_id, inode->i_ino);
344 +#endif
345 return 0;
346 }
348 @@ -372,6 +440,10 @@ int ext4_bio_write_page(struct ext4_io_submit *io,
349 struct buffer_head *bh, *head;
350 int ret = 0;
352 +#ifdef PDEBUG
353 + trace_printk("%s: enter: ino %lu page %lu len %d\n", inode->i_sb->s_id,
354 + inode->i_ino, page->index, len);
355 +#endif
356 blocksize = 1 << inode->i_blkbits;
358 BUG_ON(PageWriteback(page));
359 @@ -422,5 +494,9 @@ int ext4_bio_write_page(struct ext4_io_submit *io,
360 end_page_writeback(page);
361 kmem_cache_free(io_page_cachep, io_page);
362 }
363 +#ifdef PDEBUG
364 + trace_printk("%s: exit: for ino %lu\n", inode->i_sb->s_id,
365 + inode->i_ino);
366 +#endif
367 return ret;
368 }
369 diff --git a/fs/jbd2/commit.c b/fs/jbd2/commit.c
370 index 6494c81..d3f8634 100644
371 --- a/fs/jbd2/commit.c
372 +++ b/fs/jbd2/commit.c
373 @@ -631,6 +631,10 @@ void jbd2_journal_commit_transaction(journal_t *journal)
374 * (which is of type BJ_IO)
375 */
376 JBUFFER_TRACE(jh, "ph3: write metadata");
377 +#if 1 /* PDEBUG */
378 + trace_printk("@635 %s block %llu\n", journal->j_devname,
379 + blocknr);
380 +#endif
381 flags = jbd2_journal_write_metadata_buffer(commit_transaction,
382 jh, &new_jh, blocknr);
383 if (flags < 0) {
384 @@ -693,6 +697,11 @@ start_journal_io:
385 clear_buffer_dirty(bh);
386 set_buffer_uptodate(bh);
387 bh->b_end_io = journal_end_buffer_io_sync;
388 +#if 1 /* PDEBUG */
389 + trace_printk("@700 %s block %llu\n",
390 + journal->j_devname,
391 + bh->b_blocknr);
392 +#endif
393 submit_bh(write_op, bh);
394 }
395 cond_resched();
396 @@ -762,6 +771,10 @@ wait_for_iobuf:
397 jh = commit_transaction->t_iobuf_list->b_tprev;
398 bh = jh2bh(jh);
399 if (buffer_locked(bh)) {
400 +#if 1 /* PDEBUG */
401 + trace_printk("jbd wait_on_buffer@765: %lu\n",
402 + (unsigned long) bh->b_blocknr);
403 +#endif
404 wait_on_buffer(bh);
405 goto wait_for_iobuf;
406 }
407 @@ -818,6 +831,11 @@ wait_for_iobuf:
408 jh = commit_transaction->t_log_list->b_tprev;
409 bh = jh2bh(jh);
410 if (buffer_locked(bh)) {
411 +#if 1 /* PDEBUG */
412 + trace_printk("%s: jbd wait_on_buffer@823: %lu\n",
413 + journal->j_devname,
414 + (unsigned long) bh->b_blocknr);
415 +#endif
416 wait_on_buffer(bh);
417 goto wait_for_ctlbuf;
418 }
419 diff --git a/fs/jbd2/transaction.c b/fs/jbd2/transaction.c
420 index 6bf0a24..8873caa 100644
421 --- a/fs/jbd2/transaction.c
422 +++ b/fs/jbd2/transaction.c
423 @@ -701,6 +701,11 @@ repeat:
424 for ( ; ; ) {
425 prepare_to_wait(wqh, &wait.wait,
426 TASK_UNINTERRUPTIBLE);
427 +#if 1 /* PDEBUG */
428 + trace_printk("%s: BJ shadow waiting on %lu\n",
429 + journal->j_devname,
430 + (unsigned long) bh->b_blocknr);
431 +#endif
432 if (jh->b_jlist != BJ_Shadow)
433 break;
434 schedule();
435 diff --git a/mm/filemap.c b/mm/filemap.c
436 index 3d4df44..e0c7061 100644
437 --- a/mm/filemap.c
438 +++ b/mm/filemap.c
439 @@ -295,6 +295,13 @@ int filemap_fdatawait_range(struct address_space *mapping, loff_t start_byte,
440 if (page->index > end)
441 continue;
443 +#if 1 /* PDEBUG */
444 + if (PageWriteback(page))
445 + trace_printk("pid %d waiting on %lu:%lu\n",
446 + task_pid_nr(current),
447 + mapping->host->i_ino,
448 + (unsigned long) page->index);
449 +#endif
450 wait_on_page_writeback(page);
451 if (PageError(page))
452 ret = -EIO;