From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754771Ab0FAKXX (ORCPT ); Tue, 1 Jun 2010 06:23:23 -0400 Received: from 0122700014.0.fullrate.dk ([95.166.99.235]:55138 "EHLO kernel.dk" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752915Ab0FAKXV (ORCPT ); Tue, 1 Jun 2010 06:23:21 -0400 Date: Tue, 1 Jun 2010 12:23:19 +0200 From: Jens Axboe To: David John Cc: Divyesh Shah , "linux-kernel@vger.kernel.org" Subject: Re: [2.6.35-rc1 BUG]: Calling sched_clock causes stack trace with DEBUG_PREEMPT Message-ID: <20100601102319.GL3564@kernel.dk> References: <4C04AC78.3020702@xenontk.org> <4C04BB3F.2030707@xenontk.org> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <4C04BB3F.2030707@xenontk.org> Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Tue, Jun 01 2010, David John wrote: > On 06/01/2010 12:15 PM, David John wrote: > > Hi, > > > > I get stack traces like the following: > > > > BUG: using smp_processor_id() in preemptible [00000000] code: init/1 > > caller is native_sched_clock+0x37/0x6d > > Pid: 1, comm: init Not tainted 2.6.35-rc1 #99 > > Call Trace: > > [] debug_smp_processor_id+0xd3/0xec > > [] native_sched_clock+0x37/0x6d > > [] blk_rq_init+0x92/0x9e > > [] get_request+0x1c8/0x27e > > [] get_request_wait+0x2d/0x13c > > [] ? get_parent_ip+0x11/0x42 > > [] ? add_preempt_count+0xad/0xb1 > > [] __make_request+0x293/0x3b8 > > [] ? mempool_alloc_slab+0x10/0x12 > > [] generic_make_request+0x187/0x1ea > > [] ? get_parent_ip+0x11/0x42 > > [] submit_bio+0xbe/0xc7 > > [] submit_bh+0xef/0x111 > > [] block_read_full_page+0x1ec/0x20c > > [] ? blkdev_get_block+0x0/0x5e > > [] ? sub_preempt_count+0x92/0xa5 > > [] ? __lru_cache_add+0x73/0x93 > > [] blkdev_readpage+0x13/0x15 > > [] __do_page_cache_readahead+0x161/0x194 > > [] ra_submit+0x1c/0x20 > > [] ondemand_readahead+0x1bb/0x1ce > > [] ? rcu_read_unlock+0xe/0x29 > > [] page_cache_sync_readahead+0x38/0x3a > > [] generic_file_aio_read+0x24d/0x57f > > [] ? __mem_cgroup_try_charge+0x78/0x46c > > [] do_sync_read+0xc6/0x103 > > [] ? get_parent_ip+0x11/0x42 > > [] ? handle_mm_fault+0x7cb/0x7e5 > > [] ? block_ioctl+0x32/0x36 > > [] ? selinux_file_permission+0x57/0xae > > [] ? security_file_permission+0x11/0x13 > > [] vfs_read+0xa6/0x103 > > [] sys_read+0x45/0x69 > > [] system_call_fastpath+0x16/0x1b > > > > Since with commit 9195291e you call 'set_start_time_ns' from > > 'blk_rq_init' which in turn calls 'sched_clock' with preempt enabled. > > There are other calls to sched_clock in blk-cgroup.c. Maybe they should > > be checked as well? > > > > Regards, > > David. > > > > I see this has been reported. Never mind. This should fix it for now, if you have time to test, then that would not hurt. diff --git a/include/linux/blkdev.h b/include/linux/blkdev.h index 8b7f5e0..09a8402 100644 --- a/include/linux/blkdev.h +++ b/include/linux/blkdev.h @@ -1211,14 +1211,23 @@ struct work_struct; int kblockd_schedule_work(struct request_queue *q, struct work_struct *work); #ifdef CONFIG_BLK_CGROUP +/* + * This should not be using sched_clock(). A real patch is in progress + * to fix this up, until that is in place we need to disable preemption + * around sched_clock() in this function and set_io_start_time_ns(). + */ static inline void set_start_time_ns(struct request *req) { + preempt_disable(); req->start_time_ns = sched_clock(); + preempt_enable(); } static inline void set_io_start_time_ns(struct request *req) { + preempt_disable(); req->io_start_time_ns = sched_clock(); + preempt_enable(); } static inline uint64_t rq_start_time_ns(struct request *req) -- Jens Axboe