Hi,
just a note: the most difficult part in the implementation of this
patch has been how to handle the fact that the requeue and finish
hooks of the active elevator get invoked even for requests that are
not referred in that elevator any longer. You can find details in the
comments introduced by the patch. This note is just to point out this
unexpected fact (for me), in case it is not intentional.
Thanks,
Paolo
Paolo Valente (1):
block, bfq: add requeue-request hook
block/bfq-iosched.c | 101 +++++++++++++++++++++++++++++++++++++++-------------
1 file changed, 76 insertions(+), 25 deletions(-)
--
2.15.1
Commit 'a6a252e64914 ("blk-mq-sched: decide how to handle flush rq via
RQF_FLUSH_SEQ")' makes all non-flush re-prepared requests for a device
be re-inserted into the active I/O scheduler for that device. As a
consequence, I/O schedulers may get the same request inserted again,
even several times, without a finish_request invoked on that request
before each re-insertion.
This fact is the cause of the failure reported in [1]. For an I/O
scheduler, every re-insertion of the same re-prepared request is
equivalent to the insertion of a new request. For schedulers like
mq-deadline or kyber, this fact causes no harm. In contrast, it
confuses a stateful scheduler like BFQ, which keeps state for an I/O
request, until the finish_request hook is invoked on the request. In
particular, BFQ may get stuck, waiting forever for the number of
request dispatches, of the same request, to be balanced by an equal
number of request completions (while there will be one completion for
that request). In this state, BFQ may refuse to serve I/O requests
from other bfq_queues. The hang reported in [1] then follows.
However, the above re-prepared requests undergo a requeue, thus the
requeue_request hook of the active elevator is invoked for these
requests, if set. This commit then addresses the above issue by
properly implementing the hook requeue_request in BFQ.
[1] https://marc.info/?l=linux-block&m=151211117608676
Reported-by: Ivan Kozik <[email protected]>
Reported-by: Alban Browaeys <[email protected]>
Signed-off-by: Paolo Valente <[email protected]>
Signed-off-by: Serena Ziviani <[email protected]>
---
block/bfq-iosched.c | 101 +++++++++++++++++++++++++++++++++++++++-------------
1 file changed, 76 insertions(+), 25 deletions(-)
diff --git a/block/bfq-iosched.c b/block/bfq-iosched.c
index 47e6ec7427c4..343452488515 100644
--- a/block/bfq-iosched.c
+++ b/block/bfq-iosched.c
@@ -3823,24 +3823,26 @@ static struct request *__bfq_dispatch_request(struct blk_mq_hw_ctx *hctx)
}
/*
- * We exploit the bfq_finish_request hook to decrement
- * rq_in_driver, but bfq_finish_request will not be
- * invoked on this request. So, to avoid unbalance,
- * just start this request, without incrementing
- * rq_in_driver. As a negative consequence,
- * rq_in_driver is deceptively lower than it should be
- * while this request is in service. This may cause
- * bfq_schedule_dispatch to be invoked uselessly.
+ * We exploit the bfq_finish_requeue_request hook to
+ * decrement rq_in_driver, but
+ * bfq_finish_requeue_request will not be invoked on
+ * this request. So, to avoid unbalance, just start
+ * this request, without incrementing rq_in_driver. As
+ * a negative consequence, rq_in_driver is deceptively
+ * lower than it should be while this request is in
+ * service. This may cause bfq_schedule_dispatch to be
+ * invoked uselessly.
*
* As for implementing an exact solution, the
- * bfq_finish_request hook, if defined, is probably
- * invoked also on this request. So, by exploiting
- * this hook, we could 1) increment rq_in_driver here,
- * and 2) decrement it in bfq_finish_request. Such a
- * solution would let the value of the counter be
- * always accurate, but it would entail using an extra
- * interface function. This cost seems higher than the
- * benefit, being the frequency of non-elevator-private
+ * bfq_finish_requeue_request hook, if defined, is
+ * probably invoked also on this request. So, by
+ * exploiting this hook, we could 1) increment
+ * rq_in_driver here, and 2) decrement it in
+ * bfq_finish_requeue_request. Such a solution would
+ * let the value of the counter be always accurate,
+ * but it would entail using an extra interface
+ * function. This cost seems higher than the benefit,
+ * being the frequency of non-elevator-private
* requests very low.
*/
goto start_rq;
@@ -4515,6 +4517,8 @@ static inline void bfq_update_insert_stats(struct request_queue *q,
unsigned int cmd_flags) {}
#endif
+static void bfq_prepare_request(struct request *rq, struct bio *bio);
+
static void bfq_insert_request(struct blk_mq_hw_ctx *hctx, struct request *rq,
bool at_head)
{
@@ -4541,6 +4545,20 @@ static void bfq_insert_request(struct blk_mq_hw_ctx *hctx, struct request *rq,
else
list_add_tail(&rq->queuelist, &bfqd->dispatch);
} else {
+ if (!bfqq) {
+ /*
+ * This should never happen. Most likely rq is
+ * a requeued regular request, being
+ * re-inserted without being first
+ * re-prepared. Do a prepare, to avoid
+ * failure.
+ */
+ pr_warn("Regular request associated with no queue");
+ WARN_ON(1);
+ bfq_prepare_request(rq, rq->bio);
+ bfqq = RQ_BFQQ(rq);
+ }
+
idle_timer_disabled = __bfq_insert_request(bfqd, rq);
/*
* Update bfqq, because, if a queue merge has occurred
@@ -4697,22 +4715,36 @@ static void bfq_completed_request(struct bfq_queue *bfqq, struct bfq_data *bfqd)
bfq_schedule_dispatch(bfqd);
}
-static void bfq_finish_request_body(struct bfq_queue *bfqq)
+static void bfq_finish_requeue_request_body(struct bfq_queue *bfqq)
{
bfqq->allocated--;
bfq_put_queue(bfqq);
}
-static void bfq_finish_request(struct request *rq)
+/*
+ * Handle either a requeue or a finish for rq. The things to do are
+ * the same in both cases: all references to rq are to be dropped. In
+ * particular, rq is considered completed from the point of view of
+ * the scheduler.
+ */
+static void bfq_finish_requeue_request(struct request *rq)
{
- struct bfq_queue *bfqq;
+ struct bfq_queue *bfqq = RQ_BFQQ(rq);
struct bfq_data *bfqd;
- if (!rq->elv.icq)
+ /*
+ * The following checks makes this function exit in case of
+ * spurious invocations, for which there is nothing to do. One
+ * example is if rq is an already requeued request, which has
+ * not (yet) been re-inserted into a bfq_queue. In fact,
+ * requeue and finish hooks of elevators are invoked in blk-mq
+ * without checking whether the involved request is actually
+ * still referenced in the scheduler.
+ */
+ if (!rq->elv.icq || !bfqq)
return;
- bfqq = RQ_BFQQ(rq);
bfqd = bfqq->bfqd;
if (rq->rq_flags & RQF_STARTED)
@@ -4727,13 +4759,14 @@ static void bfq_finish_request(struct request *rq)
spin_lock_irqsave(&bfqd->lock, flags);
bfq_completed_request(bfqq, bfqd);
- bfq_finish_request_body(bfqq);
+ bfq_finish_requeue_request_body(bfqq);
spin_unlock_irqrestore(&bfqd->lock, flags);
} else {
/*
* Request rq may be still/already in the scheduler,
- * in which case we need to remove it. And we cannot
+ * in which case we need to remove it (this should
+ * never happen in case of requeue). And we cannot
* defer such a check and removal, to avoid
* inconsistencies in the time interval from the end
* of this function to the start of the deferred work.
@@ -4748,9 +4781,26 @@ static void bfq_finish_request(struct request *rq)
bfqg_stats_update_io_remove(bfqq_group(bfqq),
rq->cmd_flags);
}
- bfq_finish_request_body(bfqq);
+ bfq_finish_requeue_request_body(bfqq);
}
+ /*
+ * Reset private fields. In case of a requeue, this allows
+ * this function to correctly do nothing if it is spuriously
+ * invoked again on this same request (see the check at the
+ * beginning of the function). Probably, a better general
+ * design would be to prevent blk-mq from invoking the requeue
+ * or finish hooks of an elevator, for a request that is not
+ * referred by that elevator.
+ *
+ * Resetting the following fields would break the
+ * request-insertion logic if rq is re-inserted into a bfq
+ * internal queue, without a re-preparation. Here we assume
+ * that re-insertions of requeued requests, without
+ * re-preparation, can happen only for pass_through or at_head
+ * requests (which are not re-inserted into bfq internal
+ * queues).
+ */
rq->elv.priv[0] = NULL;
rq->elv.priv[1] = NULL;
}
@@ -5426,7 +5476,8 @@ static struct elevator_type iosched_bfq_mq = {
.ops.mq = {
.limit_depth = bfq_limit_depth,
.prepare_request = bfq_prepare_request,
- .finish_request = bfq_finish_request,
+ .requeue_request = bfq_finish_requeue_request,
+ .finish_request = bfq_finish_requeue_request,
.exit_icq = bfq_exit_icq,
.insert_requests = bfq_insert_requests,
.dispatch_request = bfq_dispatch_request,
--
2.15.1
Hi Paolo,
I applied this to master.today, flipped udev back to bfq and took it
for a spin. ?Unfortunately, box fairly quickly went boom under load.
[ 454.739975] ------------[ cut here ]------------
[ 454.739979] list_add corruption. prev->next should be next (000000005f99a42a), but was (null). (prev=00000000fc569ec9).
[ 454.739989] WARNING: CPU: 3 PID: 0 at lib/list_debug.c:28 __list_add_valid+0x6a/0x70
[ 454.739990] Modules linked in: fuse(E) ebtable_filter(E) ebtables(E) af_packet(E) bridge(E) stp(E) llc(E) iscsi_ibft(E) iscsi_boot_sysfs(E) nf_conntrack_ipv6(E) nf_defrag_ipv6(E) ipt_REJECT(E) xt_tcpudp(E) iptable_filter(E) ip6table_mangle(E) nf_conntrack_netbios_ns(E) nf_conntrack_broadcast(E) nf_conntrack_ipv4(E) nf_defrag_ipv4(E) ip_tables(E) xt_conntrack(E) nf_conntrack(E) ip6table_filter(E) ip6_tables(E) x_tables(E) nls_iso8859_1(E) nls_cp437(E) intel_rapl(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) snd_hda_codec_hdmi(E) coretemp(E) snd_hda_codec_realtek(E) snd_hda_codec_generic(E) kvm_intel(E) kvm(E) snd_hda_intel(E) snd_hda_codec(E) snd_hwdep(E) snd_hda_core(E) snd_pcm(E) irqbypass(E) snd_timer(E) joydev(E) crct10dif_pclmul(E) snd(E) r8169(E) crc32_pclmul(E) mii(E) mei_me(E) soundcore(E)
[ 454.740011] crc32c_intel(E) iTCO_wdt(E) ghash_clmulni_intel(E) iTCO_vendor_support(E) pcbc(E) mei(E) lpc_ich(E) aesni_intel(E) i2c_i801(E) mfd_core(E) aes_x86_64(E) shpchp(E) intel_smartconnect(E) crypto_simd(E) glue_helper(E) cryptd(E) pcspkr(E) fan(E) thermal(E) nfsd(E) auth_rpcgss(E) nfs_acl(E) lockd(E) grace(E) sunrpc(E) sr_mod(E) cdrom(E) hid_logitech_hidpp(E) hid_logitech_dj(E) uas(E) usb_storage(E) hid_generic(E) usbhid(E) nouveau(E) wmi(E) i2c_algo_bit(E) drm_kms_helper(E) syscopyarea(E) sysfillrect(E) sysimgblt(E) fb_sys_fops(E) ahci(E) xhci_pci(E) ttm(E) libahci(E) ehci_pci(E) xhci_hcd(E) ehci_hcd(E) libata(E) drm(E) usbcore(E) video(E) button(E) sd_mod(E) vfat(E) fat(E) virtio_blk(E) virtio_mmio(E) virtio_pci(E) virtio_ring(E) virtio(E) ext4(E) crc16(E) mbcache(E) jbd2(E) loop(E) sg(E)
[ 454.740038] dm_multipath(E) dm_mod(E) scsi_dh_rdac(E) scsi_dh_emc(E) scsi_dh_alua(E) scsi_mod(E) efivarfs(E) autofs4(E)
[ 454.740043] CPU: 3 PID: 0 Comm: swapper/3 Tainted: G E 4.15.0.ge237f98-master #605
[ 454.740044] Hardware name: MEDION MS-7848/MS-7848, BIOS M7848W08.20C 09/23/2013
[ 454.740046] RIP: 0010:__list_add_valid+0x6a/0x70
[ 454.740047] RSP: 0018:ffff88041ecc3ca8 EFLAGS: 00010096
[ 454.740048] RAX: 0000000000000075 RBX: ffff8803f33fa8c0 RCX: 0000000000000006
[ 454.740049] RDX: 0000000000000000 RSI: 0000000000000082 RDI: ffff88041ecd5570
[ 454.740050] RBP: ffff8803f596d7e0 R08: 0000000000000000 R09: 0000000000000368
[ 454.740051] R10: 0000000000000000 R11: ffff88041ecc3a30 R12: ffff8803eb1c8828
[ 454.740052] R13: ffff8803f33fa940 R14: ffff8803f5852600 R15: ffff8803f596d810
[ 454.740053] FS: 0000000000000000(0000) GS:ffff88041ecc0000(0000) knlGS:0000000000000000
[ 454.740054] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 454.740055] CR2: 00000000014d9788 CR3: 0000000001e0a006 CR4: 00000000001606e0
[ 454.740056] Call Trace:
[ 454.740058] <IRQ>
[ 454.740062] blk_flush_complete_seq+0x2b1/0x370
[ 454.740065] flush_end_io+0x18c/0x280
[ 454.740074] scsi_end_request+0x95/0x1e0 [scsi_mod]
[ 454.740079] scsi_io_completion+0xbb/0x5d0 [scsi_mod]
[ 454.740082] __blk_mq_complete_request+0xb7/0x180
[ 454.740084] blk_mq_complete_request+0x50/0x90
[ 454.740087] ? scsi_vpd_tpg_id+0x90/0x90 [scsi_mod]
[ 454.740095] ata_scsi_qc_complete+0x1d8/0x470 [libata]
[ 454.740100] ata_qc_complete_multiple+0x87/0xd0 [libata]
[ 454.740103] ahci_handle_port_interrupt+0xd4/0x4e0 [libahci]
[ 454.740105] ahci_handle_port_intr+0x6f/0xb0 [libahci]
[ 454.740107] ahci_single_level_irq_intr+0x3b/0x60 [libahci]
[ 454.740110] __handle_irq_event_percpu+0x40/0x1a0
[ 454.740112] handle_irq_event_percpu+0x20/0x50
[ 454.740114] handle_irq_event+0x36/0x60
[ 454.740116] handle_edge_irq+0x90/0x190
[ 454.740118] handle_irq+0x1c/0x30
[ 454.740120] do_IRQ+0x43/0xd0
[ 454.740122] common_interrupt+0xa2/0xa2
[ 454.740123] </IRQ>
[ 454.740125] RIP: 0010:cpuidle_enter_state+0xec/0x250
[ 454.740126] RSP: 0018:ffff880187febec0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffdd
[ 454.740127] RAX: ffff88041ece0040 RBX: ffff88041ece77e8 RCX: 000000000000001f
[ 454.740128] RDX: 0000000000000000 RSI: fffffffd9cb7bc38 RDI: 0000000000000000
[ 454.740129] RBP: 0000000000000005 R08: 0000000000000006 R09: 000000000000024f
[ 454.740130] R10: 0000000000000205 R11: 0000000000000018 R12: 0000000000000003
[ 454.740131] R13: 00000069e09a3c87 R14: 0000000000000003 R15: 00000069e09d450c
[ 454.740134] do_idle+0x16a/0x1d0
[ 454.740136] cpu_startup_entry+0x19/0x20
[ 454.740138] start_secondary+0x14e/0x190
[ 454.740140] secondary_startup_64+0xa5/0xb0
[ 454.740141] Code: fe 31 c0 48 c7 c7 a0 61 bf 81 e8 12 f7 d8 ff 0f ff 31 c0 c3 48 89 d1 48 c7 c7 50 61 bf 81 48 89 f2 48 89 c6 31 c0 e8 f6 f6 d8 ff <0f> ff 31 c0 c3 90 48 8b 07 48 b9 00 01 00 00 00 00 ad de 48 8b
[ 454.740159] ---[ end trace c2b6ab81731e93a0 ]---
[ 454.740278] ------------[ cut here ]------------
[ 454.740281] list_del corruption. prev->next should be 0000000056dbdea8, but was 00000000577efd13
[ 454.740286] WARNING: CPU: 3 PID: 0 at lib/list_debug.c:53 __list_del_entry_valid+0x7c/0xa0
[ 454.740287] Modules linked in: fuse(E) ebtable_filter(E) ebtables(E) af_packet(E) bridge(E) stp(E) llc(E) iscsi_ibft(E) iscsi_boot_sysfs(E) nf_conntrack_ipv6(E) nf_defrag_ipv6(E) ipt_REJECT(E) xt_tcpudp(E) iptable_filter(E) ip6table_mangle(E) nf_conntrack_netbios_ns(E) nf_conntrack_broadcast(E) nf_conntrack_ipv4(E) nf_defrag_ipv4(E) ip_tables(E) xt_conntrack(E) nf_conntrack(E) ip6table_filter(E) ip6_tables(E) x_tables(E) nls_iso8859_1(E) nls_cp437(E) intel_rapl(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) snd_hda_codec_hdmi(E) coretemp(E) snd_hda_codec_realtek(E) snd_hda_codec_generic(E) kvm_intel(E) kvm(E) snd_hda_intel(E) snd_hda_codec(E) snd_hwdep(E) snd_hda_core(E) snd_pcm(E) irqbypass(E) snd_timer(E) joydev(E) crct10dif_pclmul(E) snd(E) r8169(E) crc32_pclmul(E) mii(E) mei_me(E) soundcore(E)
[ 454.740302] crc32c_intel(E) iTCO_wdt(E) ghash_clmulni_intel(E) iTCO_vendor_support(E) pcbc(E) mei(E) lpc_ich(E) aesni_intel(E) i2c_i801(E) mfd_core(E) aes_x86_64(E) shpchp(E) intel_smartconnect(E) crypto_simd(E) glue_helper(E) cryptd(E) pcspkr(E) fan(E) thermal(E) nfsd(E) auth_rpcgss(E) nfs_acl(E) lockd(E) grace(E) sunrpc(E) sr_mod(E) cdrom(E) hid_logitech_hidpp(E) hid_logitech_dj(E) uas(E) usb_storage(E) hid_generic(E) usbhid(E) nouveau(E) wmi(E) i2c_algo_bit(E) drm_kms_helper(E) syscopyarea(E) sysfillrect(E) sysimgblt(E) fb_sys_fops(E) ahci(E) xhci_pci(E) ttm(E) libahci(E) ehci_pci(E) xhci_hcd(E) ehci_hcd(E) libata(E) drm(E) usbcore(E) video(E) button(E) sd_mod(E) vfat(E) fat(E) virtio_blk(E) virtio_mmio(E) virtio_pci(E) virtio_ring(E) virtio(E) ext4(E) crc16(E) mbcache(E) jbd2(E) loop(E) sg(E)
[ 454.740321] dm_multipath(E) dm_mod(E) scsi_dh_rdac(E) scsi_dh_emc(E) scsi_dh_alua(E) scsi_mod(E) efivarfs(E) autofs4(E)
[ 454.740324] CPU: 3 PID: 0 Comm: swapper/3 Tainted: G W E 4.15.0.ge237f98-master #605
[ 454.740325] Hardware name: MEDION MS-7848/MS-7848, BIOS M7848W08.20C 09/23/2013
[ 454.740327] RIP: 0010:__list_del_entry_valid+0x7c/0xa0
[ 454.740328] RSP: 0018:ffff88041ecc3cb8 EFLAGS: 00010096
[ 454.740329] RAX: 0000000000000054 RBX: ffff8803f33fa8c0 RCX: 0000000000000006
[ 454.740330] RDX: 0000000000000000 RSI: 0000000000000082 RDI: ffff88041ecd5570
[ 454.740331] RBP: ffff8803f596d7e0 R08: 0000000000000101 R09: 000000000000039d
[ 454.740332] R10: 0000000000000000 R11: ffff88041ecc3a40 R12: ffff8803eb1c8828
[ 454.740333] R13: ffff8803f596d7f0 R14: 0000000000000000 R15: ffff8803f33fa940
[ 454.740334] FS: 0000000000000000(0000) GS:ffff88041ecc0000(0000) knlGS:0000000000000000
[ 454.740335] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 454.740336] CR2: 00000000014d9788 CR3: 0000000001e0a006 CR4: 00000000001606e0
[ 454.740337] Call Trace:
[ 454.740338] <IRQ>
[ 454.740340] blk_flush_complete_seq+0x16e/0x370
[ 454.740343] mq_flush_data_end_io+0xb0/0x110
[ 454.740348] scsi_end_request+0x95/0x1e0 [scsi_mod]
[ 454.740352] scsi_io_completion+0x10b/0x5d0 [scsi_mod]
[ 454.740354] __blk_mq_complete_request+0xb7/0x180
[ 454.740355] blk_mq_complete_request+0x50/0x90
[ 454.740359] ? scsi_vpd_tpg_id+0x90/0x90 [scsi_mod]
[ 454.740364] ata_scsi_qc_complete+0x1d8/0x470 [libata]
[ 454.740368] ata_qc_complete_multiple+0x87/0xd0 [libata]
[ 454.740371] ahci_handle_port_interrupt+0xd4/0x4e0 [libahci]
[ 454.740373] ahci_handle_port_intr+0x6f/0xb0 [libahci]
[ 454.740374] ahci_single_level_irq_intr+0x3b/0x60 [libahci]
[ 454.740377] __handle_irq_event_percpu+0x40/0x1a0
[ 454.740379] handle_irq_event_percpu+0x20/0x50
[ 454.740380] handle_irq_event+0x36/0x60
[ 454.740382] handle_edge_irq+0x90/0x190
[ 454.740383] handle_irq+0x1c/0x30
[ 454.740385] do_IRQ+0x43/0xd0
[ 454.740386] common_interrupt+0xa2/0xa2
[ 454.740387] </IRQ>
[ 454.740389] RIP: 0010:cpuidle_enter_state+0xec/0x250
[ 454.740389] RSP: 0018:ffff880187febec0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffdd
[ 454.740391] RAX: ffff88041ece0040 RBX: ffff88041ece77e8 RCX: 000000000000001f
[ 454.740392] RDX: 0000000000000000 RSI: fffffffd9cb7bc38 RDI: 0000000000000000
[ 454.740393] RBP: 0000000000000005 R08: 0000000000000006 R09: 000000000000024f
[ 454.740393] R10: 0000000000000205 R11: 0000000000000018 R12: 0000000000000003
[ 454.740394] R13: 00000069e0a06158 R14: 0000000000000003 R15: 00000069e0a1e8c6
[ 454.740397] do_idle+0x16a/0x1d0
[ 454.740399] cpu_startup_entry+0x19/0x20
[ 454.740400] start_secondary+0x14e/0x190
[ 454.740402] secondary_startup_64+0xa5/0xb0
[ 454.740403] Code: ff 31 c0 c3 48 89 fe 31 c0 48 c7 c7 80 62 bf 81 e8 8a f6 d8 ff 0f ff 31 c0 c3 48 89 fe 31 c0 48 c7 c7 40 62 bf 81 e8 74 f6 d8 ff <0f> ff 31 c0 c3 48 89 fe 31 c0 48 c7 c7 08 62 bf 81 e8 5e f6 d8
[ 454.740421] ---[ end trace c2b6ab81731e93a1 ]---
[ 454.740429] BUG: unable to handle kernel NULL pointer dereference at (null)
[ 454.740980] IP: __list_del_entry_valid+0x25/0xa0
[ 454.741509] PGD 0 P4D 0
[ 454.742026] Oops: 0000 [#1] SMP PTI
[ 454.742525] Dumping ftrace buffer:
[ 454.743040] (ftrace buffer empty)
[ 454.743529] Modules linked in: fuse(E) ebtable_filter(E) ebtables(E) af_packet(E) bridge(E) stp(E) llc(E) iscsi_ibft(E) iscsi_boot_sysfs(E) nf_conntrack_ipv6(E) nf_defrag_ipv6(E) ipt_REJECT(E) xt_tcpudp(E) iptable_filter(E) ip6table_mangle(E) nf_conntrack_netbios_ns(E) nf_conntrack_broadcast(E) nf_conntrack_ipv4(E) nf_defrag_ipv4(E) ip_tables(E) xt_conntrack(E) nf_conntrack(E) ip6table_filter(E) ip6_tables(E) x_tables(E) nls_iso8859_1(E) nls_cp437(E) intel_rapl(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) snd_hda_codec_hdmi(E) coretemp(E) snd_hda_codec_realtek(E) snd_hda_codec_generic(E) kvm_intel(E) kvm(E) snd_hda_intel(E) snd_hda_codec(E) snd_hwdep(E) snd_hda_core(E) snd_pcm(E) irqbypass(E) snd_timer(E) joydev(E) crct10dif_pclmul(E) snd(E) r8169(E) crc32_pclmul(E) mii(E) mei_me(E) soundcore(E)
[ 454.745917] crc32c_intel(E) iTCO_wdt(E) ghash_clmulni_intel(E) iTCO_vendor_support(E) pcbc(E) mei(E) lpc_ich(E) aesni_intel(E) i2c_i801(E) mfd_core(E) aes_x86_64(E) shpchp(E) intel_smartconnect(E) crypto_simd(E) glue_helper(E) cryptd(E) pcspkr(E) fan(E) thermal(E) nfsd(E) auth_rpcgss(E) nfs_acl(E) lockd(E) grace(E) sunrpc(E) sr_mod(E) cdrom(E) hid_logitech_hidpp(E) hid_logitech_dj(E) uas(E) usb_storage(E) hid_generic(E) usbhid(E) nouveau(E) wmi(E) i2c_algo_bit(E) drm_kms_helper(E) syscopyarea(E) sysfillrect(E) sysimgblt(E) fb_sys_fops(E) ahci(E) xhci_pci(E) ttm(E) libahci(E) ehci_pci(E) xhci_hcd(E) ehci_hcd(E) libata(E) drm(E) usbcore(E) video(E) button(E) sd_mod(E) vfat(E) fat(E) virtio_blk(E) virtio_mmio(E) virtio_pci(E) virtio_ring(E) virtio(E) ext4(E) crc16(E) mbcache(E) jbd2(E) loop(E) sg(E)
[ 454.748901] dm_multipath(E) dm_mod(E) scsi_dh_rdac(E) scsi_dh_emc(E) scsi_dh_alua(E) scsi_mod(E) efivarfs(E) autofs4(E)
[ 454.749679] CPU: 3 PID: 0 Comm: swapper/3 Tainted: G W E 4.15.0.ge237f98-master #605
[ 454.750472] Hardware name: MEDION MS-7848/MS-7848, BIOS M7848W08.20C 09/23/2013
[ 454.751273] RIP: 0010:__list_del_entry_valid+0x25/0xa0
[ 454.752057] RSP: 0018:ffff88041ecc3cb8 EFLAGS: 00010007
[ 454.752842] RAX: 0000000000000000 RBX: ffff8803f5852580 RCX: dead000000000200
[ 454.753633] RDX: 0000000000000000 RSI: ffff8803f596d7e0 RDI: ffff8803f5852600
[ 454.754427] RBP: ffff8803f596d7e0 R08: 0000000000000004 R09: 0000000000000000
[ 454.755220] R10: ffff8803f71583d0 R11: 0000000000001000 R12: ffff8803eb1c8828
[ 454.756010] R13: ffff8803f596d800 R14: 0000000000000000 R15: ffff8803f5852600
[ 454.756798] FS: 0000000000000000(0000) GS:ffff88041ecc0000(0000) knlGS:0000000000000000
[ 454.757591] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 454.758383] CR2: 0000000000000000 CR3: 0000000001e0a006 CR4: 00000000001606e0
[ 454.759194] Call Trace:
[ 454.760012] <IRQ>
[ 454.760802] blk_flush_complete_seq+0x16e/0x370
[ 454.761636] mq_flush_data_end_io+0xb0/0x110
[ 454.762488] scsi_end_request+0x95/0x1e0 [scsi_mod]
[ 454.763295] scsi_io_completion+0x10b/0x5d0 [scsi_mod]
[ 454.764099] __blk_mq_complete_request+0xb7/0x180
[ 454.764906] blk_mq_complete_request+0x50/0x90
[ 454.765715] ? scsi_vpd_tpg_id+0x90/0x90 [scsi_mod]
[ 454.766528] ata_scsi_qc_complete+0x1d8/0x470 [libata]
[ 454.767357] ata_qc_complete_multiple+0x87/0xd0 [libata]
[ 454.768187] ahci_handle_port_interrupt+0xd4/0x4e0 [libahci]
[ 454.769001] ahci_handle_port_intr+0x6f/0xb0 [libahci]
[ 454.769812] ahci_single_level_irq_intr+0x3b/0x60 [libahci]
[ 454.770625] __handle_irq_event_percpu+0x40/0x1a0
[ 454.771437] handle_irq_event_percpu+0x20/0x50
[ 454.772248] handle_irq_event+0x36/0x60
[ 454.773053] handle_edge_irq+0x90/0x190
[ 454.773857] handle_irq+0x1c/0x30
[ 454.774660] do_IRQ+0x43/0xd0
[ 454.775460] common_interrupt+0xa2/0xa2
[ 454.776283] </IRQ>
[ 454.777075] RIP: 0010:cpuidle_enter_state+0xec/0x250
[ 454.777870] RSP: 0018:ffff880187febec0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffdd
[ 454.778678] RAX: ffff88041ece0040 RBX: ffff88041ece77e8 RCX: 000000000000001f
[ 454.779487] RDX: 0000000000000000 RSI: fffffffd9cb7bc38 RDI: 0000000000000000
[ 454.780299] RBP: 0000000000000005 R08: 0000000000000006 R09: 000000000000024f
[ 454.781110] R10: 0000000000000205 R11: 0000000000000018 R12: 0000000000000003
[ 454.781919] R13: 00000069e0a06158 R14: 0000000000000003 R15: 00000069e0a1e8c6
[ 454.782729] do_idle+0x16a/0x1d0
[ 454.783533] cpu_startup_entry+0x19/0x20
[ 454.784339] start_secondary+0x14e/0x190
[ 454.785146] secondary_startup_64+0xa5/0xb0
[ 454.785954] Code: 0f ff 31 c0 c3 90 48 8b 07 48 b9 00 01 00 00 00 00 ad de 48 8b 57 08 48 39 c8 74 26 48 b9 00 02 00 00 00 00 ad de 48 39 ca 74 5c <48> 8b 12 48 39 d7 75 3e 48 8b 50 08 48 39 d7 75 1f b8 01 00 00
[ 454.786836] RIP: __list_del_entry_valid+0x25/0xa0 RSP: ffff88041ecc3cb8
[ 454.787704] CR2: 0000000000000000
Hi, Paolo.
I can confirm that this patch fixes cfdisk hang for me. I've also tried
to trigger the issue Mike has encountered, but with no luck (maybe, I
wasn't insistent enough, just was doing dd on usb-storage device in the
VM).
So, with regard to cfdisk hang on usb-storage:
Tested-by: Oleksandr Natalenko <[email protected]>
Thank you.
On Tue, 2018-02-06 at 08:44 +0100, Oleksandr Natalenko wrote:
> Hi, Paolo.
>
> I can confirm that this patch fixes cfdisk hang for me. I've also tried
> to trigger the issue Mike has encountered, but with no luck (maybe, I
> wasn't insistent enough, just was doing dd on usb-storage device in the
> VM).
I was doing kbuilds, and it blew up on me twice. Switching back to cfq
seemed to confirm it was indeed the patch causing trouble, but that's
by no means a certainty.
-Mike
Hi.
06.02.2018 08:56, Mike Galbraith wrote:
> I was doing kbuilds, and it blew up on me twice. Switching back to cfq
> seemed to confirm it was indeed the patch causing trouble, but that's
> by no means a certainty.
Just to note, I was using v4.15.1, not the latest git HEAD. Are you able
to reproduce it on the stable kernel? Also, assuming this issue might be
unrelated to the BFQ itself, did you manage to reproduce the trouble
with another blk-mq scheduler (not CFQ, but mq-deadline/Kyber)?
Regards,
Oleksandr
On Tue, 2018-02-06 at 09:37 +0100, Oleksandr Natalenko wrote:
> Hi.
>
> 06.02.2018 08:56, Mike Galbraith wrote:
> > I was doing kbuilds, and it blew up on me twice. Switching back to cfq
> > seemed to confirm it was indeed the patch causing trouble, but that's
> > by no means a certainty.
>
> Just to note, I was using v4.15.1, not the latest git HEAD. Are you able
> to reproduce it on the stable kernel?
I didn't even try to wedge it into 4.15.1, tested it as posted.
> Also, assuming this issue might be
> unrelated to the BFQ itself, did you manage to reproduce the trouble
> with another blk-mq scheduler (not CFQ, but mq-deadline/Kyber)?
I can give another scheduler a go this afternoon.
-Mike
> Il giorno 06 feb 2018, alle ore 08:56, Mike Galbraith <[email protected]> ha scritto:
>
> On Tue, 2018-02-06 at 08:44 +0100, Oleksandr Natalenko wrote:
>> Hi, Paolo.
>>
>> I can confirm that this patch fixes cfdisk hang for me. I've also tried
>> to trigger the issue Mike has encountered, but with no luck (maybe, I
>> wasn't insistent enough, just was doing dd on usb-storage device in the
>> VM).
>
> I was doing kbuilds, and it blew up on me twice. Switching back to cfq
> seemed to confirm it was indeed the patch causing trouble, but that's
> by no means a certainty.
>
Hi Mike,
as you can imagine, I didn't get any failure in my pre-submission
tests on this patch. In addition, it is not that easy to link this
patch, which just adds some internal bfq housekeeping in case of a
requeue, with a corruption of external lists for general I/O
management.
In this respect, as Oleksandr comments point out, by switching from
cfq to bfq, you switch between much more than two schedulers. Anyway,
who knows ...
Maybe this report will ring a bell with some block-layer expert, or,
hopefully, next feedback will help puzzle this out.
Thanks,
Paolo
> -Mike
On Tue, 2018-02-06 at 10:38 +0100, Paolo Valente wrote:
>
> Hi Mike,
> as you can imagine, I didn't get any failure in my pre-submission
> tests on this patch. In addition, it is not that easy to link this
> patch, which just adds some internal bfq housekeeping in case of a
> requeue, with a corruption of external lists for general I/O
> management.
>
> In this respect, as Oleksandr comments point out, by switching from
> cfq to bfq, you switch between much more than two schedulers. Anyway,
> who knows ...
Not me. ?Box seems to be fairly sure that it is bfq. Twice again box
went belly up on me in fairly short order with bfq, but seemed fine
with deadline. I'm currently running deadline again, and box again
seems solid, thought I won't say _is_ solid until it's been happily
trundling along with deadline for a quite a bit longer.
I was ssh'd in during the last episode, got this out. I should be
getting crash dumps, but seems kdump is only working intermittently
atm. ?I did get one earlier, but 3 of 4 times not. ?Hohum.
[ 484.179292] BUG: unable to handle kernel paging request at ffffffffa0817000
[ 484.179436] IP: __trace_note_message+0x1f/0xd0
[ 484.179576] PGD 1e0c067 P4D 1e0c067 PUD 1e0d063 PMD 3faff2067 PTE 0
[ 484.179719] Oops: 0000 [#1] SMP PTI
[ 484.179861] Dumping ftrace buffer:
[ 484.180011] (ftrace buffer empty)
[ 484.180138] Modules linked in: fuse(E) ebtable_filter(E) ebtables(E) af_packet(E) bridge(E) stp(E) llc(E) iscsi_ibft(E) iscsi_boot_sysfs(E) nf_conntrack_ipv6(E) nf_defrag_ipv6(E) ipt_REJECT(E) xt_tcpudp(E) iptable_filter(E) ip6table_mangle(E) nf_conntrack_netbios_ns(E) nf_conntrack_broadcast(E) nf_conntrack_ipv4(E) nf_defrag_ipv4(E) ip_tables(E) xt_conntrack(E) nf_conntrack(E) ip6table_filter(E) ip6_tables(E) x_tables(E) nls_iso8859_1(E) nls_cp437(E) intel_rapl(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) snd_hda_codec_hdmi(E) coretemp(E) kvm_intel(E) snd_hda_codec_realtek(E) kvm(E) snd_hda_codec_generic(E) snd_hda_intel(E) snd_hda_codec(E) sr_mod(E) snd_hwdep(E) cdrom(E) joydev(E) snd_hda_core(E) snd_pcm(E) snd_timer(E) irqbypass(E) snd(E) crct10dif_pclmul(E) crc32_pclmul(E) crc32c_intel(E) r8169(E)
[ 484.180740] iTCO_wdt(E) ghash_clmulni_intel(E) mii(E) iTCO_vendor_support(E) pcbc(E) aesni_intel(E) soundcore(E) aes_x86_64(E) shpchp(E) crypto_simd(E) lpc_ich(E) glue_helper(E) i2c_i801(E) mei_me(E) mfd_core(E) mei(E) cryptd(E) intel_smartconnect(E) pcspkr(E) fan(E) thermal(E) nfsd(E) auth_rpcgss(E) nfs_acl(E) lockd(E) grace(E) sunrpc(E) hid_logitech_hidpp(E) hid_logitech_dj(E) uas(E) usb_storage(E) hid_generic(E) usbhid(E) nouveau(E) wmi(E) i2c_algo_bit(E) drm_kms_helper(E) syscopyarea(E) sysfillrect(E) sysimgblt(E) fb_sys_fops(E) ahci(E) xhci_pci(E) ehci_pci(E) libahci(E) ttm(E) ehci_hcd(E) xhci_hcd(E) libata(E) drm(E) usbcore(E) video(E) button(E) sd_mod(E) vfat(E) fat(E) virtio_blk(E) virtio_mmio(E) virtio_pci(E) virtio_ring(E) virtio(E) ext4(E) crc16(E) mbcache(E) jbd2(E) loop(E) sg(E) dm_multipath(E)
[ 484.181421] dm_mod(E) scsi_dh_rdac(E) scsi_dh_emc(E) scsi_dh_alua(E) scsi_mod(E) efivarfs(E) autofs4(E)
[ 484.181583] CPU: 3 PID: 500 Comm: kworker/3:1H Tainted: G E 4.15.0.ge237f98-master #609
[ 484.181746] Hardware name: MEDION MS-7848/MS-7848, BIOS M7848W08.20C 09/23/2013
[ 484.181910] Workqueue: kblockd blk_mq_requeue_work
[ 484.182076] RIP: 0010:__trace_note_message+0x1f/0xd0
[ 484.182250] RSP: 0018:ffff8803f45bfc20 EFLAGS: 00010282
[ 484.182436] RAX: 0000000000000000 RBX: ffffffffa0817000 RCX: 00000000ffff8803
[ 484.182622] RDX: ffffffff81bf514d RSI: 0000000000000000 RDI: ffffffffa0817000
[ 484.182810] RBP: ffff8803f45bfc80 R08: 0000000000000041 R09: ffff8803f69cc5d0
[ 484.182998] R10: ffff8803f80b47d0 R11: 0000000000001000 R12: ffff8803f45e8000
[ 484.183185] R13: 000000000000000d R14: 0000000000000000 R15: ffff8803fba112c0
[ 484.183372] FS: 0000000000000000(0000) GS:ffff88041ecc0000(0000) knlGS:0000000000000000
[ 484.183561] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 484.183747] CR2: ffffffffa0817000 CR3: 0000000001e0a006 CR4: 00000000001606e0
[ 484.183934] Call Trace:
[ 484.184122] bfq_put_queue+0xd3/0xe0
[ 484.184305] bfq_finish_requeue_request+0x72/0x350
[ 484.184493] __blk_mq_requeue_request+0x8f/0x120
[ 484.184678] blk_mq_dispatch_rq_list+0x342/0x550
[ 484.184866] ? kyber_dispatch_request+0xd0/0xd0
[ 484.185053] blk_mq_sched_dispatch_requests+0xf7/0x180
[ 484.185238] __blk_mq_run_hw_queue+0x58/0xd0
[ 484.185429] __blk_mq_delay_run_hw_queue+0x99/0xa0
[ 484.185614] blk_mq_run_hw_queue+0x54/0xf0
[ 484.185805] blk_mq_run_hw_queues+0x4b/0x60
[ 484.185994] blk_mq_requeue_work+0x13a/0x150
[ 484.186192] process_one_work+0x147/0x350
[ 484.186383] worker_thread+0x47/0x3e0
[ 484.186572] kthread+0xf8/0x130
[ 484.186760] ? rescuer_thread+0x360/0x360
[ 484.186948] ? kthread_stop+0x120/0x120
[ 484.187137] ret_from_fork+0x35/0x40
[ 484.187321] Code: ff 48 89 44 24 10 e9 58 fd ff ff 90 55 48 89 e5 41 55 41 54 53 48 89 fb 48 83 ec 48 48 89 4c 24 30 4c 89 44 24 38 4c 89 4c 24 40 <83> 3f 02 0f 85 87 00 00 00 f6 43 21 04 75 0b 48 83 c4 48 5b 41
[ 484.187525] RIP: __trace_note_message+0x1f/0xd0 RSP: ffff8803f45bfc20
[ 484.187727] CR2: ffffffffa0817000
Hi.
06.02.2018 12:57, Mike Galbraith wrote:
> Not me. Box seems to be fairly sure that it is bfq. Twice again box
> went belly up on me in fairly short order with bfq, but seemed fine
> with deadline. I'm currently running deadline again, and box again
> seems solid, thought I won't say _is_ solid until it's been happily
> trundling along with deadline for a quite a bit longer.
Sorry for the noise, but just to make it clear, are we talking about
"deadline" or "mq-deadline" now?
> Il giorno 06 feb 2018, alle ore 12:57, Mike Galbraith <[email protected]> ha scritto:
>
> On Tue, 2018-02-06 at 10:38 +0100, Paolo Valente wrote:
>>
>> Hi Mike,
>> as you can imagine, I didn't get any failure in my pre-submission
>> tests on this patch. In addition, it is not that easy to link this
>> patch, which just adds some internal bfq housekeeping in case of a
>> requeue, with a corruption of external lists for general I/O
>> management.
>>
>> In this respect, as Oleksandr comments point out, by switching from
>> cfq to bfq, you switch between much more than two schedulers. Anyway,
>> who knows ...
>
> Not me. Box seems to be fairly sure that it is bfq.
Yeah, sorry for the too short comment: what I meant is that cfq (and
deadline) are in legacy blk, while bfq is in blk-mq. So, to use bfq,
you must also switch from legacy-blk I/O stack to blk-mq I/O stack.
> Twice again box
> went belly up on me in fairly short order with bfq, but seemed fine
> with deadline. I'm currently running deadline again, and box again
> seems solid, thought I won't say _is_ solid until it's been happily
> trundling along with deadline for a quite a bit longer.
>
As Oleksadr asked too, is it deadline or mq-deadline?
> I was ssh'd in during the last episode, got this out. I should be
> getting crash dumps, but seems kdump is only working intermittently
> atm. I did get one earlier, but 3 of 4 times not. Hohum.
>
> [ 484.179292] BUG: unable to handle kernel paging request at ffffffffa0817000
> [ 484.179436] IP: __trace_note_message+0x1f/0xd0
> [ 484.179576] PGD 1e0c067 P4D 1e0c067 PUD 1e0d063 PMD 3faff2067 PTE 0
> [ 484.179719] Oops: 0000 [#1] SMP PTI
> [ 484.179861] Dumping ftrace buffer:
> [ 484.180011] (ftrace buffer empty)
> [ 484.180138] Modules linked in: fuse(E) ebtable_filter(E) ebtables(E) af_packet(E) bridge(E) stp(E) llc(E) iscsi_ibft(E) iscsi_boot_sysfs(E) nf_conntrack_ipv6(E) nf_defrag_ipv6(E) ipt_REJECT(E) xt_tcpudp(E) iptable_filter(E) ip6table_mangle(E) nf_conntrack_netbios_ns(E) nf_conntrack_broadcast(E) nf_conntrack_ipv4(E) nf_defrag_ipv4(E) ip_tables(E) xt_conntrack(E) nf_conntrack(E) ip6table_filter(E) ip6_tables(E) x_tables(E) nls_iso8859_1(E) nls_cp437(E) intel_rapl(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) snd_hda_codec_hdmi(E) coretemp(E) kvm_intel(E) snd_hda_codec_realtek(E) kvm(E) snd_hda_codec_generic(E) snd_hda_intel(E) snd_hda_codec(E) sr_mod(E) snd_hwdep(E) cdrom(E) joydev(E) snd_hda_core(E) snd_pcm(E) snd_timer(E) irqbypass(E) snd(E) crct10dif_pclmul(E) crc32_pclmul(E) crc32c_intel(E) r8169(E)
> [ 484.180740] iTCO_wdt(E) ghash_clmulni_intel(E) mii(E) iTCO_vendor_support(E) pcbc(E) aesni_intel(E) soundcore(E) aes_x86_64(E) shpchp(E) crypto_simd(E) lpc_ich(E) glue_helper(E) i2c_i801(E) mei_me(E) mfd_core(E) mei(E) cryptd(E) intel_smartconnect(E) pcspkr(E) fan(E) thermal(E) nfsd(E) auth_rpcgss(E) nfs_acl(E) lockd(E) grace(E) sunrpc(E) hid_logitech_hidpp(E) hid_logitech_dj(E) uas(E) usb_storage(E) hid_generic(E) usbhid(E) nouveau(E) wmi(E) i2c_algo_bit(E) drm_kms_helper(E) syscopyarea(E) sysfillrect(E) sysimgblt(E) fb_sys_fops(E) ahci(E) xhci_pci(E) ehci_pci(E) libahci(E) ttm(E) ehci_hcd(E) xhci_hcd(E) libata(E) drm(E) usbcore(E) video(E) button(E) sd_mod(E) vfat(E) fat(E) virtio_blk(E) virtio_mmio(E) virtio_pci(E) virtio_ring(E) virtio(E) ext4(E) crc16(E) mbcache(E) jbd2(E) loop(E) sg(E) dm_multipath(E)
> [ 484.181421] dm_mod(E) scsi_dh_rdac(E) scsi_dh_emc(E) scsi_dh_alua(E) scsi_mod(E) efivarfs(E) autofs4(E)
> [ 484.181583] CPU: 3 PID: 500 Comm: kworker/3:1H Tainted: G E 4.15.0.ge237f98-master #609
> [ 484.181746] Hardware name: MEDION MS-7848/MS-7848, BIOS M7848W08.20C 09/23/2013
> [ 484.181910] Workqueue: kblockd blk_mq_requeue_work
> [ 484.182076] RIP: 0010:__trace_note_message+0x1f/0xd0
> [ 484.182250] RSP: 0018:ffff8803f45bfc20 EFLAGS: 00010282
> [ 484.182436] RAX: 0000000000000000 RBX: ffffffffa0817000 RCX: 00000000ffff8803
> [ 484.182622] RDX: ffffffff81bf514d RSI: 0000000000000000 RDI: ffffffffa0817000
> [ 484.182810] RBP: ffff8803f45bfc80 R08: 0000000000000041 R09: ffff8803f69cc5d0
> [ 484.182998] R10: ffff8803f80b47d0 R11: 0000000000001000 R12: ffff8803f45e8000
> [ 484.183185] R13: 000000000000000d R14: 0000000000000000 R15: ffff8803fba112c0
> [ 484.183372] FS: 0000000000000000(0000) GS:ffff88041ecc0000(0000) knlGS:0000000000000000
> [ 484.183561] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 484.183747] CR2: ffffffffa0817000 CR3: 0000000001e0a006 CR4: 00000000001606e0
> [ 484.183934] Call Trace:
> [ 484.184122] bfq_put_queue+0xd3/0xe0
> [ 484.184305] bfq_finish_requeue_request+0x72/0x350
> [ 484.184493] __blk_mq_requeue_request+0x8f/0x120
> [ 484.184678] blk_mq_dispatch_rq_list+0x342/0x550
> [ 484.184866] ? kyber_dispatch_request+0xd0/0xd0
> [ 484.185053] blk_mq_sched_dispatch_requests+0xf7/0x180
> [ 484.185238] __blk_mq_run_hw_queue+0x58/0xd0
> [ 484.185429] __blk_mq_delay_run_hw_queue+0x99/0xa0
> [ 484.185614] blk_mq_run_hw_queue+0x54/0xf0
> [ 484.185805] blk_mq_run_hw_queues+0x4b/0x60
> [ 484.185994] blk_mq_requeue_work+0x13a/0x150
> [ 484.186192] process_one_work+0x147/0x350
> [ 484.186383] worker_thread+0x47/0x3e0
> [ 484.186572] kthread+0xf8/0x130
> [ 484.186760] ? rescuer_thread+0x360/0x360
> [ 484.186948] ? kthread_stop+0x120/0x120
> [ 484.187137] ret_from_fork+0x35/0x40
> [ 484.187321] Code: ff 48 89 44 24 10 e9 58 fd ff ff 90 55 48 89 e5 41 55 41 54 53 48 89 fb 48 83 ec 48 48 89 4c 24 30 4c 89 44 24 38 4c 89 4c 24 40 <83> 3f 02 0f 85 87 00 00 00 f6 43 21 04 75 0b 48 83 c4 48 5b 41
> [ 484.187525] RIP: __trace_note_message+0x1f/0xd0 RSP: ffff8803f45bfc20
> [ 484.187727] CR2: ffffffffa0817000
ok, right in the middle of bfq this time ... Was this the first OOPS in your kernel log?
Thanks,
Paolo
> Il giorno 06 feb 2018, alle ore 13:26, Paolo Valente <[email protected]> ha scritto:
>
>
>
>> Il giorno 06 feb 2018, alle ore 12:57, Mike Galbraith <[email protected]> ha scritto:
>>
>> On Tue, 2018-02-06 at 10:38 +0100, Paolo Valente wrote:
>>>
>>> Hi Mike,
>>> as you can imagine, I didn't get any failure in my pre-submission
>>> tests on this patch. In addition, it is not that easy to link this
>>> patch, which just adds some internal bfq housekeeping in case of a
>>> requeue, with a corruption of external lists for general I/O
>>> management.
>>>
>>> In this respect, as Oleksandr comments point out, by switching from
>>> cfq to bfq, you switch between much more than two schedulers. Anyway,
>>> who knows ...
>>
>> Not me. Box seems to be fairly sure that it is bfq.
>
> Yeah, sorry for the too short comment: what I meant is that cfq (and
> deadline) are in legacy blk, while bfq is in blk-mq. So, to use bfq,
> you must also switch from legacy-blk I/O stack to blk-mq I/O stack.
>
>
>> Twice again box
>> went belly up on me in fairly short order with bfq, but seemed fine
>> with deadline. I'm currently running deadline again, and box again
>> seems solid, thought I won't say _is_ solid until it's been happily
>> trundling along with deadline for a quite a bit longer.
>>
>
> As Oleksadr asked too, is it deadline or mq-deadline?
>
>> I was ssh'd in during the last episode, got this out. I should be
>> getting crash dumps, but seems kdump is only working intermittently
>> atm. I did get one earlier, but 3 of 4 times not. Hohum.
>>
>> [ 484.179292] BUG: unable to handle kernel paging request at ffffffffa0817000
>> [ 484.179436] IP: __trace_note_message+0x1f/0xd0
>> [ 484.179576] PGD 1e0c067 P4D 1e0c067 PUD 1e0d063 PMD 3faff2067 PTE 0
>> [ 484.179719] Oops: 0000 [#1] SMP PTI
>> [ 484.179861] Dumping ftrace buffer:
>> [ 484.180011] (ftrace buffer empty)
>> [ 484.180138] Modules linked in: fuse(E) ebtable_filter(E) ebtables(E) af_packet(E) bridge(E) stp(E) llc(E) iscsi_ibft(E) iscsi_boot_sysfs(E) nf_conntrack_ipv6(E) nf_defrag_ipv6(E) ipt_REJECT(E) xt_tcpudp(E) iptable_filter(E) ip6table_mangle(E) nf_conntrack_netbios_ns(E) nf_conntrack_broadcast(E) nf_conntrack_ipv4(E) nf_defrag_ipv4(E) ip_tables(E) xt_conntrack(E) nf_conntrack(E) ip6table_filter(E) ip6_tables(E) x_tables(E) nls_iso8859_1(E) nls_cp437(E) intel_rapl(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) snd_hda_codec_hdmi(E) coretemp(E) kvm_intel(E) snd_hda_codec_realtek(E) kvm(E) snd_hda_codec_generic(E) snd_hda_intel(E) snd_hda_codec(E) sr_mod(E) snd_hwdep(E) cdrom(E) joydev(E) snd_hda_core(E) snd_pcm(E) snd_timer(E) irqbypass(E) snd(E) crct10dif_pclmul(E) crc32_pclmul(E) crc32c_intel(E) r8169(E)
>> [ 484.180740] iTCO_wdt(E) ghash_clmulni_intel(E) mii(E) iTCO_vendor_support(E) pcbc(E) aesni_intel(E) soundcore(E) aes_x86_64(E) shpchp(E) crypto_simd(E) lpc_ich(E) glue_helper(E) i2c_i801(E) mei_me(E) mfd_core(E) mei(E) cryptd(E) intel_smartconnect(E) pcspkr(E) fan(E) thermal(E) nfsd(E) auth_rpcgss(E) nfs_acl(E) lockd(E) grace(E) sunrpc(E) hid_logitech_hidpp(E) hid_logitech_dj(E) uas(E) usb_storage(E) hid_generic(E) usbhid(E) nouveau(E) wmi(E) i2c_algo_bit(E) drm_kms_helper(E) syscopyarea(E) sysfillrect(E) sysimgblt(E) fb_sys_fops(E) ahci(E) xhci_pci(E) ehci_pci(E) libahci(E) ttm(E) ehci_hcd(E) xhci_hcd(E) libata(E) drm(E) usbcore(E) video(E) button(E) sd_mod(E) vfat(E) fat(E) virtio_blk(E) virtio_mmio(E) virtio_pci(E) virtio_ring(E) virtio(E) ext4(E) crc16(E) mbcache(E) jbd2(E) loop(E) sg(E) dm_multipath(E)
>> [ 484.181421] dm_mod(E) scsi_dh_rdac(E) scsi_dh_emc(E) scsi_dh_alua(E) scsi_mod(E) efivarfs(E) autofs4(E)
>> [ 484.181583] CPU: 3 PID: 500 Comm: kworker/3:1H Tainted: G E 4.15.0.ge237f98-master #609
>> [ 484.181746] Hardware name: MEDION MS-7848/MS-7848, BIOS M7848W08.20C 09/23/2013
>> [ 484.181910] Workqueue: kblockd blk_mq_requeue_work
>> [ 484.182076] RIP: 0010:__trace_note_message+0x1f/0xd0
>> [ 484.182250] RSP: 0018:ffff8803f45bfc20 EFLAGS: 00010282
>> [ 484.182436] RAX: 0000000000000000 RBX: ffffffffa0817000 RCX: 00000000ffff8803
>> [ 484.182622] RDX: ffffffff81bf514d RSI: 0000000000000000 RDI: ffffffffa0817000
>> [ 484.182810] RBP: ffff8803f45bfc80 R08: 0000000000000041 R09: ffff8803f69cc5d0
>> [ 484.182998] R10: ffff8803f80b47d0 R11: 0000000000001000 R12: ffff8803f45e8000
>> [ 484.183185] R13: 000000000000000d R14: 0000000000000000 R15: ffff8803fba112c0
>> [ 484.183372] FS: 0000000000000000(0000) GS:ffff88041ecc0000(0000) knlGS:0000000000000000
>> [ 484.183561] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [ 484.183747] CR2: ffffffffa0817000 CR3: 0000000001e0a006 CR4: 00000000001606e0
>> [ 484.183934] Call Trace:
>> [ 484.184122] bfq_put_queue+0xd3/0xe0
>> [ 484.184305] bfq_finish_requeue_request+0x72/0x350
>> [ 484.184493] __blk_mq_requeue_request+0x8f/0x120
>> [ 484.184678] blk_mq_dispatch_rq_list+0x342/0x550
>> [ 484.184866] ? kyber_dispatch_request+0xd0/0xd0
>> [ 484.185053] blk_mq_sched_dispatch_requests+0xf7/0x180
>> [ 484.185238] __blk_mq_run_hw_queue+0x58/0xd0
>> [ 484.185429] __blk_mq_delay_run_hw_queue+0x99/0xa0
>> [ 484.185614] blk_mq_run_hw_queue+0x54/0xf0
>> [ 484.185805] blk_mq_run_hw_queues+0x4b/0x60
>> [ 484.185994] blk_mq_requeue_work+0x13a/0x150
>> [ 484.186192] process_one_work+0x147/0x350
>> [ 484.186383] worker_thread+0x47/0x3e0
>> [ 484.186572] kthread+0xf8/0x130
>> [ 484.186760] ? rescuer_thread+0x360/0x360
>> [ 484.186948] ? kthread_stop+0x120/0x120
>> [ 484.187137] ret_from_fork+0x35/0x40
>> [ 484.187321] Code: ff 48 89 44 24 10 e9 58 fd ff ff 90 55 48 89 e5 41 55 41 54 53 48 89 fb 48 83 ec 48 48 89 4c 24 30 4c 89 44 24 38 4c 89 4c 24 40 <83> 3f 02 0f 85 87 00 00 00 f6 43 21 04 75 0b 48 83 c4 48 5b 41
>> [ 484.187525] RIP: __trace_note_message+0x1f/0xd0 RSP: ffff8803f45bfc20
>> [ 484.187727] CR2: ffffffffa0817000
>
> ok, right in the middle of bfq this time ... Was this the first OOPS in your kernel log?
>
I've just tried a
list *(__trace_note_message+0x1f)
with gdb, hoping that your image is close enough to mine. But the
output doesn't say much.
Thanks,
Paolo
> Thanks,
> Paolo
>
> --
> You received this message because you are subscribed to the Google Groups "bfq-iosched" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to [email protected].
> For more options, visit https://groups.google.com/d/optout.
On 02/06/18 13:26, Paolo Valente wrote:
(..)
> As Oleksadr asked too, is it deadline or mq-deadline?
You can use deadline as alias as long as blk-mq is active.
This doesn't work when mq-deadline is built as a module, but that
doesn't seem to be the problem here.
>> [ 484.179292] BUG: unable to handle kernel paging request at ffffffffa0817000
>> [ 484.179436] IP: __trace_note_message+0x1f/0xd0
>> [ 484.179576] PGD 1e0c067 P4D 1e0c067 PUD 1e0d063 PMD 3faff2067 PTE 0
>> [ 484.179719] Oops: 0000 [#1] SMP PTI
>> [ 484.179861] Dumping ftrace buffer:
>> [ 484.180011] (ftrace buffer empty)
>> [ 484.180138] Modules linked in: fuse(E) ebtable_filter(E) ebtables(E) af_packet(E) bridge(E) stp(E) llc(E) iscsi_ibft(E) iscsi_boot_sysfs(E) nf_conntrack_ipv6(E) nf_defrag_ipv6(E) ipt_REJECT(E) xt_tcpudp(E) iptable_filter(E) ip6table_mangle(E) nf_conntrack_netbios_ns(E) nf_conntrack_broadcast(E) nf_conntrack_ipv4(E) nf_defrag_ipv4(E) ip_tables(E) xt_conntrack(E) nf_conntrack(E) ip6table_filter(E) ip6_tables(E) x_tables(E) nls_iso8859_1(E) nls_cp437(E) intel_rapl(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) snd_hda_codec_hdmi(E) coretemp(E) kvm_intel(E) snd_hda_codec_realtek(E) kvm(E) snd_hda_codec_generic(E) snd_hda_intel(E) snd_hda_codec(E) sr_mod(E) snd_hwdep(E) cdrom(E) joydev(E) snd_hda_core(E) snd_pcm(E) snd_timer(E) irqbypass(E) snd(E) crct10dif_pclmul(E) crc32_pclmul(E) crc32c_intel(E) r8169(E)
>> [ 484.180740] iTCO_wdt(E) ghash_clmulni_intel(E) mii(E) iTCO_vendor_support(E) pcbc(E) aesni_intel(E) soundcore(E) aes_x86_64(E) shpchp(E) crypto_simd(E) lpc_ich(E) glue_helper(E) i2c_i801(E) mei_me(E) mfd_core(E) mei(E) cryptd(E) intel_smartconnect(E) pcspkr(E) fan(E) thermal(E) nfsd(E) auth_rpcgss(E) nfs_acl(E) lockd(E) grace(E) sunrpc(E) hid_logitech_hidpp(E) hid_logitech_dj(E) uas(E) usb_storage(E) hid_generic(E) usbhid(E) nouveau(E) wmi(E) i2c_algo_bit(E) drm_kms_helper(E) syscopyarea(E) sysfillrect(E) sysimgblt(E) fb_sys_fops(E) ahci(E) xhci_pci(E) ehci_pci(E) libahci(E) ttm(E) ehci_hcd(E) xhci_hcd(E) libata(E) drm(E) usbcore(E) video(E) button(E) sd_mod(E) vfat(E) fat(E) virtio_blk(E) virtio_mmio(E) virtio_pci(E) virtio_ring(E) virtio(E) ext4(E) crc16(E) mbcache(E) jbd2(E) loop(E) sg(E) dm_multipath(E)
>> [ 484.181421] dm_mod(E) scsi_dh_rdac(E) scsi_dh_emc(E) scsi_dh_alua(E) scsi_mod(E) efivarfs(E) autofs4(E)
>> [ 484.181583] CPU: 3 PID: 500 Comm: kworker/3:1H Tainted: G E 4.15.0.ge237f98-master #609
>> [ 484.181746] Hardware name: MEDION MS-7848/MS-7848, BIOS M7848W08.20C 09/23/2013
>> [ 484.181910] Workqueue: kblockd blk_mq_requeue_work
>> [ 484.182076] RIP: 0010:__trace_note_message+0x1f/0xd0
>> [ 484.182250] RSP: 0018:ffff8803f45bfc20 EFLAGS: 00010282
>> [ 484.182436] RAX: 0000000000000000 RBX: ffffffffa0817000 RCX: 00000000ffff8803
>> [ 484.182622] RDX: ffffffff81bf514d RSI: 0000000000000000 RDI: ffffffffa0817000
>> [ 484.182810] RBP: ffff8803f45bfc80 R08: 0000000000000041 R09: ffff8803f69cc5d0
>> [ 484.182998] R10: ffff8803f80b47d0 R11: 0000000000001000 R12: ffff8803f45e8000
>> [ 484.183185] R13: 000000000000000d R14: 0000000000000000 R15: ffff8803fba112c0
>> [ 484.183372] FS: 0000000000000000(0000) GS:ffff88041ecc0000(0000) knlGS:0000000000000000
>> [ 484.183561] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [ 484.183747] CR2: ffffffffa0817000 CR3: 0000000001e0a006 CR4: 00000000001606e0
>> [ 484.183934] Call Trace:
>> [ 484.184122] bfq_put_queue+0xd3/0xe0
>> [ 484.184305] bfq_finish_requeue_request+0x72/0x350
>> [ 484.184493] __blk_mq_requeue_request+0x8f/0x120
>> [ 484.184678] blk_mq_dispatch_rq_list+0x342/0x550
>> [ 484.184866] ? kyber_dispatch_request+0xd0/0xd0
>> [ 484.185053] blk_mq_sched_dispatch_requests+0xf7/0x180
>> [ 484.185238] __blk_mq_run_hw_queue+0x58/0xd0
>> [ 484.185429] __blk_mq_delay_run_hw_queue+0x99/0xa0
>> [ 484.185614] blk_mq_run_hw_queue+0x54/0xf0
>> [ 484.185805] blk_mq_run_hw_queues+0x4b/0x60
>> [ 484.185994] blk_mq_requeue_work+0x13a/0x150
>> [ 484.186192] process_one_work+0x147/0x350
>> [ 484.186383] worker_thread+0x47/0x3e0
>> [ 484.186572] kthread+0xf8/0x130
>> [ 484.186760] ? rescuer_thread+0x360/0x360
>> [ 484.186948] ? kthread_stop+0x120/0x120
>> [ 484.187137] ret_from_fork+0x35/0x40
>> [ 484.187321] Code: ff 48 89 44 24 10 e9 58 fd ff ff 90 55 48 89 e5 41 55 41 54 53 48 89 fb 48 83 ec 48 48 89 4c 24 30 4c 89 44 24 38 4c 89 4c 24 40 <83> 3f 02 0f 85 87 00 00 00 f6 43 21 04 75 0b 48 83 c4 48 5b 41
>> [ 484.187525] RIP: __trace_note_message+0x1f/0xd0 RSP: ffff8803f45bfc20
>> [ 484.187727] CR2: ffffffffa0817000
>
> ok, right in the middle of bfq this time ... Was this the first OOPS in your kernel log?
A much more interesting question to me is why there is kyber in the middle. :)
Holger
The plot thickens!
Just as I was about to post that I didn't have any problems - because
I didn't have any - I decided to do a second test, activated bfq on my
workstation, on a hunch typed "sync" and .. the machine locked up, hard.
Rebooted, activated bfq, typed sync..sync hangs. Luckily this time
a second terminal was still alive, so I could capture a trace for
your enjoyment:
Feb 6 14:28:17 ragnarok kernel: io scheduler bfq registered
Feb 6 14:28:20 ragnarok kernel: BUG: unable to handle kernel NULL pointer dereference at 0000000000000030
Feb 6 14:28:20 ragnarok kernel: IP: bfq_put_queue+0x10b/0x130 [bfq]
Feb 6 14:28:20 ragnarok kernel: PGD 0 P4D 0
Feb 6 14:28:20 ragnarok kernel: Oops: 0000 [#1] SMP PTI
Feb 6 14:28:20 ragnarok kernel: Modules linked in: bfq lz4 lz4_compress lz4_decompress nfs lockd grace sunrpc autofs4 sch_fq_codel it87 hwmon_vid x86_pkg_temp_thermal snd_hda_codec_realtek coretemp radeon crc32_pclmul snd_hda_codec_generic crc32c_intel pcbc snd_hda_codec_hdmi i2c_algo_bit aesni_intel drm_kms_helper aes_x86_64 uvcvideo syscopyarea crypto_simd snd_hda_intel sysfillrect cryptd snd_usb_audio sysimgblt videobuf2_vmalloc glue_helper fb_sys_fops snd_hda_codec snd_hwdep videobuf2_memops ttm videobuf2_v4l2 snd_usbmidi_lib videobuf2_core snd_rawmidi snd_hda_core drm snd_seq_device videodev snd_pcm i2c_i801 usbhid snd_timer i2c_core snd backlight soundcore r8169 parport_pc mii parport
Feb 6 14:28:20 ragnarok kernel: CPU: 0 PID: 4 Comm: kworker/0:0H Not tainted 4.14.18 #1
Feb 6 14:28:20 ragnarok kernel: Hardware name: Gigabyte Technology Co., Ltd. P67-DS3-B3/P67-DS3-B3, BIOS F1 05/06/2011
Feb 6 14:28:20 ragnarok kernel: Workqueue: kblockd blk_mq_requeue_work
Feb 6 14:28:20 ragnarok kernel: task: ffff88060395a1c0 task.stack: ffffc90000044000
Feb 6 14:28:20 ragnarok kernel: RIP: 0010:bfq_put_queue+0x10b/0x130 [bfq]
Feb 6 14:28:20 ragnarok kernel: RSP: 0018:ffffc90000047ca0 EFLAGS: 00010286
Feb 6 14:28:20 ragnarok kernel: RAX: 0000000000000008 RBX: ffff8806023db690 RCX: 0000000000000000
Feb 6 14:28:20 ragnarok kernel: RDX: 0000000000000000 RSI: ffff880601bb39b0 RDI: ffff880601a56400
Feb 6 14:28:20 ragnarok kernel: RBP: 0000000001bb3980 R08: 0000000000000053 R09: ffff8806023db690
Feb 6 14:28:20 ragnarok kernel: R10: 000000001dd0f11e R11: 00000000080a011b R12: ffff880601a56400
Feb 6 14:28:20 ragnarok kernel: R13: ffff8806023dbed0 R14: 0000000000000053 R15: 0000000000000000
Feb 6 14:28:20 ragnarok kernel: FS: 0000000000000000(0000) GS:ffff88061f400000(0000) knlGS:0000000000000000
Feb 6 14:28:20 ragnarok kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Feb 6 14:28:20 ragnarok kernel: CR2: 0000000000000030 CR3: 000000000200a002 CR4: 00000000000606f0
Feb 6 14:28:20 ragnarok kernel: Call Trace:
Feb 6 14:28:20 ragnarok kernel: bfq_finish_requeue_request+0x4b/0x370 [bfq]
Feb 6 14:28:20 ragnarok kernel: __blk_mq_requeue_request+0x57/0x130
Feb 6 14:28:20 ragnarok kernel: blk_mq_dispatch_rq_list+0x1b3/0x510
Feb 6 14:28:20 ragnarok kernel: ? __bfq_bfqd_reset_in_service+0x20/0x70 [bfq]
Feb 6 14:28:20 ragnarok kernel: ? bfq_bfqq_expire+0x212/0x740 [bfq]
Feb 6 14:28:20 ragnarok kernel: blk_mq_sched_dispatch_requests+0xf0/0x170
Feb 6 14:28:20 ragnarok kernel: __blk_mq_run_hw_queue+0x4e/0x90
Feb 6 14:28:20 ragnarok kernel: __blk_mq_delay_run_hw_queue+0x73/0x80
Feb 6 14:28:20 ragnarok kernel: blk_mq_run_hw_queue+0x53/0x150
Feb 6 14:28:20 ragnarok kernel: blk_mq_run_hw_queues+0x3a/0x50
Feb 6 14:28:20 ragnarok kernel: blk_mq_requeue_work+0x104/0x110
Feb 6 14:28:20 ragnarok kernel: process_one_work+0x1d4/0x3d0
Feb 6 14:28:20 ragnarok kernel: worker_thread+0x2b/0x3c0
Feb 6 14:28:20 ragnarok kernel: ? process_one_work+0x3d0/0x3d0
Feb 6 14:28:20 ragnarok kernel: kthread+0x117/0x130
Feb 6 14:28:20 ragnarok kernel: ? kthread_create_on_node+0x40/0x40
Feb 6 14:28:20 ragnarok kernel: ret_from_fork+0x1f/0x30
Feb 6 14:28:20 ragnarok kernel: Code: c1 e8 06 83 e0 01 48 83 f8 01 45 19 f6 e8 ce 3a 00 00 41 83 e6 ee 48 89 c7 41 83 c6 53 e8 9e 3a 00 00 49 89 d9 45 89 f0 44 89 f9 <48> 8b 70 28 48 c7 c2 d8 00 25 a0 55 4c 89 ef e8 11 ba ea e0 8b
Feb 6 14:28:20 ragnarok kernel: RIP: bfq_put_queue+0x10b/0x130 [bfq] RSP: ffffc90000047ca0
Feb 6 14:28:20 ragnarok kernel: CR2: 0000000000000030
Feb 6 14:28:20 ragnarok kernel: ---[ end trace 8b782ace30a4e7d8 ]---
Yes, this is 4.14.x but with most-of block/4.16, rock-solid otherwise (in daily use).
Looks like there is something wrong with this patch after all..
cheers
Holger
On Tue, 2018-02-06 at 13:16 +0100, Oleksandr Natalenko wrote:
> Hi.
>
> 06.02.2018 12:57, Mike Galbraith wrote:
> > Not me. ?Box seems to be fairly sure that it is bfq. Twice again box
> > went belly up on me in fairly short order with bfq, but seemed fine
> > with deadline. I'm currently running deadline again, and box again
> > seems solid, thought I won't say _is_ solid until it's been happily
> > trundling along with deadline for a quite a bit longer.
>
> Sorry for the noise, but just to make it clear, are we talking about
> "deadline" or "mq-deadline" now?
mq-deadline.
On Tue, 2018-02-06 at 13:26 +0100, Paolo Valente wrote:
>
> ok, right in the middle of bfq this time ... Was this the first OOPS in your kernel log?
Yeah.
Hi.
06.02.2018 14:46, Mike Galbraith wrote:
>> Sorry for the noise, but just to make it clear, are we talking about
>> "deadline" or "mq-deadline" now?
>
> mq-deadline.
Okay, I've spent a little bit more time on stressing the VM with BFQ +
this patch enabled, and managed to get it crashed relatively easy just
by traversing through all the files in the /usr and reading them. 3
stacktraces from different boots are below:
===
[ 33.147909] BUG: unable to handle kernel NULL pointer dereference at
(null)
[ 33.156874] IP: blk_flush_complete_seq+0x20a/0x300
[ 33.160400] PGD 0 P4D 0
[ 33.162682] Oops: 0002 [#1] PREEMPT SMP PTI
[ 33.166091] Modules linked in: crct10dif_pclmul crc32_pclmul
ghash_clmulni_intel pcbc nls_iso8859_1 nls_cp437 aesni_intel vfat
aes_x86_64 crypto_simd fat glue_helper cryptd bochs_drm ttm iTCO_wdt
drm_kms_helper iTCO_vendor_support ppdev psmouse drm input_leds
led_class syscopyarea intel_agp parport_pc joydev parport evdev rtc_cmos
mousedev intel_gtt mac_hid i2c_i801 sysfillrect lpc_ich sysimgblt
agpgart fb_sys_fops qemu_fw_cfg sch_fq_codel ip_tables x_tables
hid_generic usbhid hid xfs libcrc32c crc32c_generic dm_mod raid10 md_mod
sr_mod cdrom sd_mod uhci_hcd ahci libahci xhci_pci serio_raw atkbd
libata ehci_pci virtio_net libps2 xhci_hcd ehci_hcd crc32c_intel
scsi_mod virtio_pci usbcore virtio_ring usb_common virtio i8042 serio
[ 33.226238] CPU: 0 PID: 0 Comm: BFS/0 Not tainted 4.15.0-pf2 #1
[ 33.232823] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS
0.0.0 02/06/2015
[ 33.245062] RIP: 0010:blk_flush_complete_seq+0x20a/0x300
[ 33.247781] RSP: 0018:ffff88001f803ed0 EFLAGS: 00010086
[ 33.250184] RAX: ffff8800199b5e00 RBX: ffff8800199b5de0 RCX:
ffff8800197f72a8
[ 33.253220] RDX: 0000000000000000 RSI: ffff8800199b5e10 RDI:
ffff8800197f7200
[ 33.257429] RBP: ffff8800194090a0 R08: ffff8800199b5df0 R09:
0000000000000000
[ 33.260756] R10: ffff88001df2b600 R11: ffff88001f803ce8 R12:
0000000000000000
[ 33.268840] R13: ffff8800199b5e30 R14: 0000000000000046 R15:
ffff8800199b5de0
[ 33.272722] FS: 0000000000000000(0000) GS:ffff88001f800000(0000)
knlGS:0000000000000000
[ 33.276798] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 33.278981] CR2: 0000000000000000 CR3: 0000000004008003 CR4:
00000000003606f0
[ 33.282078] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[ 33.285566] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7:
0000000000000400
[ 33.289322] Call Trace:
[ 33.291094] <IRQ>
[ 33.294208] mq_flush_data_end_io+0xb3/0xf0
[ 33.301226] scsi_end_request+0x90/0x1e0 [scsi_mod]
[ 33.303660] scsi_io_completion+0x237/0x650 [scsi_mod]
[ 33.306833] flush_smp_call_function_queue+0x7c/0xf0
[ 33.311369] smp_call_function_single_interrupt+0x32/0xf0
[ 33.314245] call_function_single_interrupt+0xa2/0xb0
[ 33.316755] </IRQ>
[ 33.318365] RIP: 0010:native_safe_halt+0x2/0x10
[ 33.321988] RSP: 0018:ffffffff82003ea0 EFLAGS: 00000202 ORIG_RAX:
ffffffffffffff04
[ 33.324995] RAX: 0000000000000000 RBX: 0000000000000000 RCX:
0000000000000000
[ 33.334532] RDX: 0000000000000000 RSI: ffffffff81e43850 RDI:
ffffffff81e43a9d
[ 33.336643] RBP: ffffffff82128080 R08: 0000000e7441b6ce R09:
ffff88001a4c2c00
[ 33.339282] R10: 0000000000000000 R11: ffff88001bceb7f0 R12:
ffffffff81ea5c92
[ 33.344597] R13: 0000000000000000 R14: 0000000000000000 R15:
000000001e07cd69
[ 33.346526] default_idle+0x18/0x130
[ 33.347929] do_idle+0x167/0x1d0
[ 33.349201] cpu_startup_entry+0x6f/0x80
[ 33.350553] start_kernel+0x4c2/0x4e2
[ 33.351822] secondary_startup_64+0xa5/0xb0
[ 33.354470] Code: 39 d0 0f 84 8f 00 00 00 48 8b 97 b0 00 00 00 49 c1
e0 04 45 31 e4 48 8b b7 a8 00 00 00 49 01 d8 48 8d 8f a8 00 00 00 48 89
56 08 <48> 89 32 49 8b 50 18 49 89 48 18 48 89 87 a8 00 00 00 48 89 97
[ 33.364997] RIP: blk_flush_complete_seq+0x20a/0x300 RSP:
ffff88001f803ed0
[ 33.366759] CR2: 0000000000000000
[ 33.367921] ---[ end trace 5179c1a9cbc4eaa2 ]---
[ 33.369413] Kernel panic - not syncing: Fatal exception in interrupt
[ 33.372089] Kernel Offset: disabled
[ 33.374413] ---[ end Kernel panic - not syncing: Fatal exception in
interrupt
===
===
[ 30.937747] BUG: unable to handle kernel NULL pointer dereference at
0000000000000028
[ 30.940984] IP: bfq_put_queue+0x10b/0x130
[ 30.941609] PGD 0 P4D 0
[ 30.941976] Oops: 0000 [#1] PREEMPT SMP PTI
[ 30.942560] Modules linked in: crct10dif_pclmul crc32_pclmul
ghash_clmulni_intel nls_iso8859_1 bochs_drm pcbc nls_cp437 vfat ttm
aesni_intel fat aes_x86_64 crypto_simd glue_helper cryptd drm_kms_helper
iTCO_wdt drm ppdev iTCO_vendor_support input_leds psmouse led_class
intel_agp parport_pc joydev mousedev intel_gtt syscopyarea parport
rtc_cmos evdev sysfillrect sysimgblt agpgart fb_sys_fops i2c_i801
mac_hid qemu_fw_cfg lpc_ich sch_fq_codel ip_tables x_tables xfs
libcrc32c crc32c_generic dm_mod raid10 md_mod hid_generic usbhid hid
sr_mod cdrom sd_mod uhci_hcd ahci libahci serio_raw virtio_net xhci_pci
ehci_pci atkbd libata libps2 xhci_hcd virtio_pci ehci_hcd virtio_ring
crc32c_intel scsi_mod usbcore i8042 usb_common virtio serio
[ 30.955195] CPU: 2 PID: 181 Comm: kworker/2:1H Not tainted 4.15.0-pf2
#1
[ 30.956649] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS
0.0.0 02/06/2015
[ 30.958404] Workqueue: kblockd blk_mq_requeue_work
[ 30.959128] RIP: 0010:bfq_put_queue+0x10b/0x130
[ 30.960330] RSP: 0018:ffffc90000617c98 EFLAGS: 00010282
[ 30.961574] RAX: 0000000000000000 RBX: ffff88001d537210 RCX:
00000000ffffffff
[ 30.962990] RDX: 0000000000000000 RSI: ffff880018a300d8 RDI:
ffff88001d537240
[ 30.964114] RBP: 0000000018a300a8 R08: 0000000000000041 R09:
ffff88001d537210
[ 30.965449] R10: 0000000000432a7f R11: 000000000002000b R12:
ffff88001d537240
[ 30.966798] R13: ffff88001941d6d9 R14: 0000000000000041 R15:
00000000ffffffff
[ 30.969154] FS: 0000000000000000(0000) GS:ffff88001f900000(0000)
knlGS:0000000000000000
[ 30.972781] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 30.974310] CR2: 0000000000000028 CR3: 0000000004008004 CR4:
00000000003606e0
[ 30.975544] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[ 30.976963] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7:
0000000000000400
[ 30.980515] Call Trace:
[ 30.981893] bfq_finish_requeue_request+0x54/0x380
[ 30.983499] __blk_mq_requeue_request+0x5c/0x140
[ 30.988010] blk_mq_dispatch_rq_list+0x1b4/0x4c0
[ 30.989621] ? __switch_to_asm+0x34/0x70
[ 30.991699] ? __switch_to_asm+0x40/0x70
[ 30.994801] ? stub_ptregs_64+0x11/0x30
[ 30.996506] blk_mq_sched_dispatch_requests+0x105/0x190
[ 30.998842] __blk_mq_run_hw_queue+0x80/0x90
[ 31.002840] __blk_mq_delay_run_hw_queue+0x92/0xe0
[ 31.004873] blk_mq_run_hw_queue+0x25/0x90
[ 31.006766] blk_mq_run_hw_queues+0x3a/0x50
[ 31.008725] blk_mq_requeue_work+0x116/0x140
[ 31.011034] process_one_work+0x1df/0x420
[ 31.012841] worker_thread+0x2b/0x3d0
[ 31.014371] ? process_one_work+0x420/0x420
[ 31.016165] kthread+0x113/0x130
[ 31.018432] ? kthread_create_on_node+0x70/0x70
[ 31.020638] ? do_group_exit+0x33/0xa0
[ 31.022188] ret_from_fork+0x35/0x40
[ 31.024845] Code: c1 e8 06 83 e0 01 48 83 f8 01 45 19 f6 e8 be 3b 00
00 41 83 e6 ee 48 89 c7 41 83 c6 53 e8 8e 3b 00 00 49 89 d9 45 89 f0 44
89 f9 <48> 8b 70 28 48 c7 c2 12 be e5 81 55 4c 89 ef e8 11 0f e0 ff 8b
[ 31.037915] RIP: bfq_put_queue+0x10b/0x130 RSP: ffffc90000617c98
[ 31.040346] CR2: 0000000000000028
[ 31.042889] ---[ end trace 11f85b2ea2b00253 ]---
[ 31.046478] note: kworker/2:1H[181] exited with preempt_count 1
===
===
[ 48.629969] BUG: unable to handle kernel NULL pointer dereference at
(null)
[ 48.632678] IP: blk_flush_complete_seq+0x20a/0x300
[ 48.637504] PGD 0 P4D 0
[ 48.639647] Oops: 0002 [#1] PREEMPT SMP PTI
[ 48.641496] Modules linked in: nls_iso8859_1 nls_cp437 vfat fat
crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc aesni_intel
aes_x86_64 crypto_simd glue_helper bochs_drm cryptd ttm ppdev
drm_kms_helper iTCO_wdt iTCO_vendor_support input_leds led_class
intel_agp psmouse joydev drm intel_gtt parport_pc mousedev syscopyarea
sysfillrect sysimgblt evdev fb_sys_fops parport lpc_ich agpgart mac_hid
i2c_i801 qemu_fw_cfg rtc_cmos sch_fq_codel ip_tables x_tables xfs
libcrc32c crc32c_generic dm_mod raid10 hid_generic md_mod usbhid hid
sr_mod cdrom sd_mod uhci_hcd ahci xhci_pci libahci serio_raw ehci_pci
atkbd xhci_hcd ehci_hcd virtio_net libps2 libata crc32c_intel scsi_mod
virtio_pci usbcore virtio_ring usb_common virtio i8042 serio
[ 48.663536] CPU: 3 PID: 175 Comm: kworker/3:1H Not tainted 4.15.0-pf2
#1
[ 48.668487] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS
0.0.0 02/06/2015
[ 48.672290] Workqueue: kblockd blk_mq_run_work_fn
[ 48.674271] RIP: 0010:blk_flush_complete_seq+0x20a/0x300
[ 48.676939] RSP: 0000:ffff88001f983ed0 EFLAGS: 00010086
[ 48.679617] RAX: ffff88001d721b60 RBX: ffff88001d721b40 RCX:
ffff8800192f26a8
[ 48.681937] RDX: 0000000000000000 RSI: ffff88001d721b70 RDI:
ffff8800192f2600
[ 48.684117] RBP: ffff88001da3a140 R08: ffff88001d721b50 R09:
0000000000000000
[ 48.688197] R10: ffff8800176fdb00 R11: 0000000000000040 R12:
0000000000000000
[ 48.690628] R13: ffff88001d721b90 R14: 0000000000000046 R15:
ffff88001d721b40
[ 48.693943] FS: 0000000000000000(0000) GS:ffff88001f980000(0000)
knlGS:0000000000000000
[ 48.698935] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 48.701592] CR2: 0000000000000000 CR3: 0000000004008002 CR4:
00000000003606e0
[ 48.703861] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[ 48.705994] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7:
0000000000000400
[ 48.708165] Call Trace:
[ 48.709827] <IRQ>
[ 48.712631] mq_flush_data_end_io+0xb3/0xf0
[ 48.714419] scsi_end_request+0x90/0x1e0 [scsi_mod]
[ 48.717553] scsi_io_completion+0x237/0x650 [scsi_mod]
[ 48.721822] flush_smp_call_function_queue+0x7c/0xf0
[ 48.726672] smp_call_function_single_interrupt+0x32/0xf0
[ 48.733743] call_function_single_interrupt+0xa2/0xb0
[ 48.737194] </IRQ>
[ 48.738656] RIP: 0010:_raw_spin_unlock_irqrestore+0x11/0x40
[ 48.741128] RSP: 0000:ffffc900005e3d30 EFLAGS: 00000293 ORIG_RAX:
ffffffffffffff04
[ 48.745138] RAX: 0000000000000001 RBX: ffff88001d640000 RCX:
0000000000000012
[ 48.747764] RDX: 0000000000040000 RSI: 0000000000000293 RDI:
0000000000000293
[ 48.752698] RBP: 0000000000000293 R08: ffffffffffffffff R09:
0000000000000090
[ 48.755910] R10: 0000000000432a3f R11: 000000000002000b R12:
0000000000000000
[ 48.760517] R13: ffff8800199ef800 R14: ffff880018d29948 R15:
ffff8800199ef800
[ 48.771214] ata_scsi_queuecmd+0xa0/0x210 [libata]
[ 48.774631] scsi_dispatch_cmd+0xe8/0x260 [scsi_mod]
[ 48.777489] scsi_queue_rq+0x4cf/0x560 [scsi_mod]
[ 48.782246] blk_mq_dispatch_rq_list+0x8f/0x4c0
[ 48.787614] blk_mq_sched_dispatch_requests+0x105/0x190
[ 48.790303] __blk_mq_run_hw_queue+0x80/0x90
[ 48.795313] process_one_work+0x1df/0x420
[ 48.798006] worker_thread+0x2b/0x3d0
[ 48.801376] ? process_one_work+0x420/0x420
[ 48.804226] kthread+0x113/0x130
[ 48.806674] ? kthread_create_on_node+0x70/0x70
[ 48.809640] ret_from_fork+0x35/0x40
[ 48.812834] Code: 39 d0 0f 84 8f 00 00 00 48 8b 97 b0 00 00 00 49 c1
e0 04 45 31 e4 48 8b b7 a8 00 00 00 49 01 d8 48 8d 8f a8 00 00 00 48 89
56 08 <48> 89 32 49 8b 50 18 49 89 48 18 48 89 87 a8 00 00 00 48 89 97
[ 48.822452] RIP: blk_flush_complete_seq+0x20a/0x300 RSP:
ffff88001f983ed0
[ 48.824908] CR2: 0000000000000000
[ 48.830677] ---[ end trace 4e5ef1b3dcbb32c5 ]---
[ 48.833655] Kernel panic - not syncing: Fatal exception in interrupt
[ 48.836166] Kernel Offset: disabled
[ 48.837150] ---[ end Kernel panic - not syncing: Fatal exception in
interrupt
===
Revoking my Tested-by tag (:.
On Tue, 2018-02-06 at 13:43 +0100, Holger Hoffst?tte wrote:
>
> A much more interesting question to me is why there is kyber in the middle. :)
Yeah, given per sysfs I have zero devices using kyber.
-Mike
> Il giorno 06 feb 2018, alle ore 15:07, Oleksandr Natalenko <[email protected]> ha scritto:
>
> Hi.
>
> 06.02.2018 14:46, Mike Galbraith wrote:
>>> Sorry for the noise, but just to make it clear, are we talking about
>>> "deadline" or "mq-deadline" now?
>> mq-deadline.
>
> Okay, I've spent a little bit more time on stressing the VM with BFQ + this patch enabled, and managed to get it crashed relatively easy just by traversing through all the files in the /usr and reading them. 3 stacktraces from different boots are below:
>
> ===
> [ 33.147909] BUG: unable to handle kernel NULL pointer dereference at (null)
> [ 33.156874] IP: blk_flush_complete_seq+0x20a/0x300
> [ 33.160400] PGD 0 P4D 0
> [ 33.162682] Oops: 0002 [#1] PREEMPT SMP PTI
> [ 33.166091] Modules linked in: crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc nls_iso8859_1 nls_cp437 aesni_intel vfat aes_x86_64 crypto_simd fat glue_helper cryptd bochs_drm ttm iTCO_wdt drm_kms_helper iTCO_vendor_support ppdev psmouse drm input_leds led_class syscopyarea intel_agp parport_pc joydev parport evdev rtc_cmos mousedev intel_gtt mac_hid i2c_i801 sysfillrect lpc_ich sysimgblt agpgart fb_sys_fops qemu_fw_cfg sch_fq_codel ip_tables x_tables hid_generic usbhid hid xfs libcrc32c crc32c_generic dm_mod raid10 md_mod sr_mod cdrom sd_mod uhci_hcd ahci libahci xhci_pci serio_raw atkbd libata ehci_pci virtio_net libps2 xhci_hcd ehci_hcd crc32c_intel scsi_mod virtio_pci usbcore virtio_ring usb_common virtio i8042 serio
> [ 33.226238] CPU: 0 PID: 0 Comm: BFS/0 Not tainted 4.15.0-pf2 #1
> [ 33.232823] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
> [ 33.245062] RIP: 0010:blk_flush_complete_seq+0x20a/0x300
> [ 33.247781] RSP: 0018:ffff88001f803ed0 EFLAGS: 00010086
> [ 33.250184] RAX: ffff8800199b5e00 RBX: ffff8800199b5de0 RCX: ffff8800197f72a8
> [ 33.253220] RDX: 0000000000000000 RSI: ffff8800199b5e10 RDI: ffff8800197f7200
> [ 33.257429] RBP: ffff8800194090a0 R08: ffff8800199b5df0 R09: 0000000000000000
> [ 33.260756] R10: ffff88001df2b600 R11: ffff88001f803ce8 R12: 0000000000000000
> [ 33.268840] R13: ffff8800199b5e30 R14: 0000000000000046 R15: ffff8800199b5de0
> [ 33.272722] FS: 0000000000000000(0000) GS:ffff88001f800000(0000) knlGS:0000000000000000
> [ 33.276798] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 33.278981] CR2: 0000000000000000 CR3: 0000000004008003 CR4: 00000000003606f0
> [ 33.282078] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [ 33.285566] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [ 33.289322] Call Trace:
> [ 33.291094] <IRQ>
> [ 33.294208] mq_flush_data_end_io+0xb3/0xf0
> [ 33.301226] scsi_end_request+0x90/0x1e0 [scsi_mod]
> [ 33.303660] scsi_io_completion+0x237/0x650 [scsi_mod]
> [ 33.306833] flush_smp_call_function_queue+0x7c/0xf0
> [ 33.311369] smp_call_function_single_interrupt+0x32/0xf0
> [ 33.314245] call_function_single_interrupt+0xa2/0xb0
> [ 33.316755] </IRQ>
> [ 33.318365] RIP: 0010:native_safe_halt+0x2/0x10
> [ 33.321988] RSP: 0018:ffffffff82003ea0 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff04
> [ 33.324995] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
> [ 33.334532] RDX: 0000000000000000 RSI: ffffffff81e43850 RDI: ffffffff81e43a9d
> [ 33.336643] RBP: ffffffff82128080 R08: 0000000e7441b6ce R09: ffff88001a4c2c00
> [ 33.339282] R10: 0000000000000000 R11: ffff88001bceb7f0 R12: ffffffff81ea5c92
> [ 33.344597] R13: 0000000000000000 R14: 0000000000000000 R15: 000000001e07cd69
> [ 33.346526] default_idle+0x18/0x130
> [ 33.347929] do_idle+0x167/0x1d0
> [ 33.349201] cpu_startup_entry+0x6f/0x80
> [ 33.350553] start_kernel+0x4c2/0x4e2
> [ 33.351822] secondary_startup_64+0xa5/0xb0
> [ 33.354470] Code: 39 d0 0f 84 8f 00 00 00 48 8b 97 b0 00 00 00 49 c1 e0 04 45 31 e4 48 8b b7 a8 00 00 00 49 01 d8 48 8d 8f a8 00 00 00 48 89 56 08 <48> 89 32 49 8b 50 18 49 89 48 18 48 89 87 a8 00 00 00 48 89 97
> [ 33.364997] RIP: blk_flush_complete_seq+0x20a/0x300 RSP: ffff88001f803ed0
> [ 33.366759] CR2: 0000000000000000
> [ 33.367921] ---[ end trace 5179c1a9cbc4eaa2 ]---
> [ 33.369413] Kernel panic - not syncing: Fatal exception in interrupt
> [ 33.372089] Kernel Offset: disabled
> [ 33.374413] ---[ end Kernel panic - not syncing: Fatal exception in interrupt
> ===
>
> ===
> [ 30.937747] BUG: unable to handle kernel NULL pointer dereference at 0000000000000028
> [ 30.940984] IP: bfq_put_queue+0x10b/0x130
> [ 30.941609] PGD 0 P4D 0
> [ 30.941976] Oops: 0000 [#1] PREEMPT SMP PTI
> [ 30.942560] Modules linked in: crct10dif_pclmul crc32_pclmul ghash_clmulni_intel nls_iso8859_1 bochs_drm pcbc nls_cp437 vfat ttm aesni_intel fat aes_x86_64 crypto_simd glue_helper cryptd drm_kms_helper iTCO_wdt drm ppdev iTCO_vendor_support input_leds psmouse led_class intel_agp parport_pc joydev mousedev intel_gtt syscopyarea parport rtc_cmos evdev sysfillrect sysimgblt agpgart fb_sys_fops i2c_i801 mac_hid qemu_fw_cfg lpc_ich sch_fq_codel ip_tables x_tables xfs libcrc32c crc32c_generic dm_mod raid10 md_mod hid_generic usbhid hid sr_mod cdrom sd_mod uhci_hcd ahci libahci serio_raw virtio_net xhci_pci ehci_pci atkbd libata libps2 xhci_hcd virtio_pci ehci_hcd virtio_ring crc32c_intel scsi_mod usbcore i8042 usb_common virtio serio
> [ 30.955195] CPU: 2 PID: 181 Comm: kworker/2:1H Not tainted 4.15.0-pf2 #1
> [ 30.956649] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
> [ 30.958404] Workqueue: kblockd blk_mq_requeue_work
> [ 30.959128] RIP: 0010:bfq_put_queue+0x10b/0x130
> [ 30.960330] RSP: 0018:ffffc90000617c98 EFLAGS: 00010282
> [ 30.961574] RAX: 0000000000000000 RBX: ffff88001d537210 RCX: 00000000ffffffff
> [ 30.962990] RDX: 0000000000000000 RSI: ffff880018a300d8 RDI: ffff88001d537240
> [ 30.964114] RBP: 0000000018a300a8 R08: 0000000000000041 R09: ffff88001d537210
> [ 30.965449] R10: 0000000000432a7f R11: 000000000002000b R12: ffff88001d537240
> [ 30.966798] R13: ffff88001941d6d9 R14: 0000000000000041 R15: 00000000ffffffff
> [ 30.969154] FS: 0000000000000000(0000) GS:ffff88001f900000(0000) knlGS:0000000000000000
> [ 30.972781] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 30.974310] CR2: 0000000000000028 CR3: 0000000004008004 CR4: 00000000003606e0
> [ 30.975544] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [ 30.976963] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [ 30.980515] Call Trace:
> [ 30.981893] bfq_finish_requeue_request+0x54/0x380
> [ 30.983499] __blk_mq_requeue_request+0x5c/0x140
> [ 30.988010] blk_mq_dispatch_rq_list+0x1b4/0x4c0
> [ 30.989621] ? __switch_to_asm+0x34/0x70
> [ 30.991699] ? __switch_to_asm+0x40/0x70
> [ 30.994801] ? stub_ptregs_64+0x11/0x30
> [ 30.996506] blk_mq_sched_dispatch_requests+0x105/0x190
> [ 30.998842] __blk_mq_run_hw_queue+0x80/0x90
> [ 31.002840] __blk_mq_delay_run_hw_queue+0x92/0xe0
> [ 31.004873] blk_mq_run_hw_queue+0x25/0x90
> [ 31.006766] blk_mq_run_hw_queues+0x3a/0x50
> [ 31.008725] blk_mq_requeue_work+0x116/0x140
> [ 31.011034] process_one_work+0x1df/0x420
> [ 31.012841] worker_thread+0x2b/0x3d0
> [ 31.014371] ? process_one_work+0x420/0x420
> [ 31.016165] kthread+0x113/0x130
> [ 31.018432] ? kthread_create_on_node+0x70/0x70
> [ 31.020638] ? do_group_exit+0x33/0xa0
> [ 31.022188] ret_from_fork+0x35/0x40
> [ 31.024845] Code: c1 e8 06 83 e0 01 48 83 f8 01 45 19 f6 e8 be 3b 00 00 41 83 e6 ee 48 89 c7 41 83 c6 53 e8 8e 3b 00 00 49 89 d9 45 89 f0 44 89 f9 <48> 8b 70 28 48 c7 c2 12 be e5 81 55 4c 89 ef e8 11 0f e0 ff 8b
> [ 31.037915] RIP: bfq_put_queue+0x10b/0x130 RSP: ffffc90000617c98
> [ 31.040346] CR2: 0000000000000028
> [ 31.042889] ---[ end trace 11f85b2ea2b00253 ]---
> [ 31.046478] note: kworker/2:1H[181] exited with preempt_count 1
> ===
>
Could you please do a
gdb <buildir>/block/bfq-iosched.o # or vmlinux.o if bfq is builtin
list *(bfq_finish_requeue_request+0x54)
list *(bfq_put_queue+0x10b)
for me?
Thanks,
Paolo
> ===
> [ 48.629969] BUG: unable to handle kernel NULL pointer dereference at (null)
> [ 48.632678] IP: blk_flush_complete_seq+0x20a/0x300
> [ 48.637504] PGD 0 P4D 0
> [ 48.639647] Oops: 0002 [#1] PREEMPT SMP PTI
> [ 48.641496] Modules linked in: nls_iso8859_1 nls_cp437 vfat fat crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc aesni_intel aes_x86_64 crypto_simd glue_helper bochs_drm cryptd ttm ppdev drm_kms_helper iTCO_wdt iTCO_vendor_support input_leds led_class intel_agp psmouse joydev drm intel_gtt parport_pc mousedev syscopyarea sysfillrect sysimgblt evdev fb_sys_fops parport lpc_ich agpgart mac_hid i2c_i801 qemu_fw_cfg rtc_cmos sch_fq_codel ip_tables x_tables xfs libcrc32c crc32c_generic dm_mod raid10 hid_generic md_mod usbhid hid sr_mod cdrom sd_mod uhci_hcd ahci xhci_pci libahci serio_raw ehci_pci atkbd xhci_hcd ehci_hcd virtio_net libps2 libata crc32c_intel scsi_mod virtio_pci usbcore virtio_ring usb_common virtio i8042 serio
> [ 48.663536] CPU: 3 PID: 175 Comm: kworker/3:1H Not tainted 4.15.0-pf2 #1
> [ 48.668487] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
> [ 48.672290] Workqueue: kblockd blk_mq_run_work_fn
> [ 48.674271] RIP: 0010:blk_flush_complete_seq+0x20a/0x300
> [ 48.676939] RSP: 0000:ffff88001f983ed0 EFLAGS: 00010086
> [ 48.679617] RAX: ffff88001d721b60 RBX: ffff88001d721b40 RCX: ffff8800192f26a8
> [ 48.681937] RDX: 0000000000000000 RSI: ffff88001d721b70 RDI: ffff8800192f2600
> [ 48.684117] RBP: ffff88001da3a140 R08: ffff88001d721b50 R09: 0000000000000000
> [ 48.688197] R10: ffff8800176fdb00 R11: 0000000000000040 R12: 0000000000000000
> [ 48.690628] R13: ffff88001d721b90 R14: 0000000000000046 R15: ffff88001d721b40
> [ 48.693943] FS: 0000000000000000(0000) GS:ffff88001f980000(0000) knlGS:0000000000000000
> [ 48.698935] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 48.701592] CR2: 0000000000000000 CR3: 0000000004008002 CR4: 00000000003606e0
> [ 48.703861] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [ 48.705994] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> [ 48.708165] Call Trace:
> [ 48.709827] <IRQ>
> [ 48.712631] mq_flush_data_end_io+0xb3/0xf0
> [ 48.714419] scsi_end_request+0x90/0x1e0 [scsi_mod]
> [ 48.717553] scsi_io_completion+0x237/0x650 [scsi_mod]
> [ 48.721822] flush_smp_call_function_queue+0x7c/0xf0
> [ 48.726672] smp_call_function_single_interrupt+0x32/0xf0
> [ 48.733743] call_function_single_interrupt+0xa2/0xb0
> [ 48.737194] </IRQ>
> [ 48.738656] RIP: 0010:_raw_spin_unlock_irqrestore+0x11/0x40
> [ 48.741128] RSP: 0000:ffffc900005e3d30 EFLAGS: 00000293 ORIG_RAX: ffffffffffffff04
> [ 48.745138] RAX: 0000000000000001 RBX: ffff88001d640000 RCX: 0000000000000012
> [ 48.747764] RDX: 0000000000040000 RSI: 0000000000000293 RDI: 0000000000000293
> [ 48.752698] RBP: 0000000000000293 R08: ffffffffffffffff R09: 0000000000000090
> [ 48.755910] R10: 0000000000432a3f R11: 000000000002000b R12: 0000000000000000
> [ 48.760517] R13: ffff8800199ef800 R14: ffff880018d29948 R15: ffff8800199ef800
> [ 48.771214] ata_scsi_queuecmd+0xa0/0x210 [libata]
> [ 48.774631] scsi_dispatch_cmd+0xe8/0x260 [scsi_mod]
> [ 48.777489] scsi_queue_rq+0x4cf/0x560 [scsi_mod]
> [ 48.782246] blk_mq_dispatch_rq_list+0x8f/0x4c0
> [ 48.787614] blk_mq_sched_dispatch_requests+0x105/0x190
> [ 48.790303] __blk_mq_run_hw_queue+0x80/0x90
> [ 48.795313] process_one_work+0x1df/0x420
> [ 48.798006] worker_thread+0x2b/0x3d0
> [ 48.801376] ? process_one_work+0x420/0x420
> [ 48.804226] kthread+0x113/0x130
> [ 48.806674] ? kthread_create_on_node+0x70/0x70
> [ 48.809640] ret_from_fork+0x35/0x40
> [ 48.812834] Code: 39 d0 0f 84 8f 00 00 00 48 8b 97 b0 00 00 00 49 c1 e0 04 45 31 e4 48 8b b7 a8 00 00 00 49 01 d8 48 8d 8f a8 00 00 00 48 89 56 08 <48> 89 32 49 8b 50 18 49 89 48 18 48 89 87 a8 00 00 00 48 89 97
> [ 48.822452] RIP: blk_flush_complete_seq+0x20a/0x300 RSP: ffff88001f983ed0
> [ 48.824908] CR2: 0000000000000000
> [ 48.830677] ---[ end trace 4e5ef1b3dcbb32c5 ]---
> [ 48.833655] Kernel panic - not syncing: Fatal exception in interrupt
> [ 48.836166] Kernel Offset: disabled
> [ 48.837150] ---[ end Kernel panic - not syncing: Fatal exception in interrupt
> ===
>
> Revoking my Tested-by tag (:.
> Il giorno 06 feb 2018, alle ore 14:40, Holger Hoffstätte <[email protected]> ha scritto:
>
>
> The plot thickens!
>
Yep, the culprit seems clearer, though ...
> Just as I was about to post that I didn't have any problems - because
> I didn't have any - I decided to do a second test, activated bfq on my
> workstation, on a hunch typed "sync" and .. the machine locked up, hard.
>
> Rebooted, activated bfq, typed sync..sync hangs. Luckily this time
> a second terminal was still alive, so I could capture a trace for
> your enjoyment:
>
> Feb 6 14:28:17 ragnarok kernel: io scheduler bfq registered
> Feb 6 14:28:20 ragnarok kernel: BUG: unable to handle kernel NULL pointer dereference at 0000000000000030
> Feb 6 14:28:20 ragnarok kernel: IP: bfq_put_queue+0x10b/0x130 [bfq]
> Feb 6 14:28:20 ragnarok kernel: PGD 0 P4D 0
> Feb 6 14:28:20 ragnarok kernel: Oops: 0000 [#1] SMP PTI
> Feb 6 14:28:20 ragnarok kernel: Modules linked in: bfq lz4 lz4_compress lz4_decompress nfs lockd grace sunrpc autofs4 sch_fq_codel it87 hwmon_vid x86_pkg_temp_thermal snd_hda_codec_realtek coretemp radeon crc32_pclmul snd_hda_codec_generic crc32c_intel pcbc snd_hda_codec_hdmi i2c_algo_bit aesni_intel drm_kms_helper aes_x86_64 uvcvideo syscopyarea crypto_simd snd_hda_intel sysfillrect cryptd snd_usb_audio sysimgblt videobuf2_vmalloc glue_helper fb_sys_fops snd_hda_codec snd_hwdep videobuf2_memops ttm videobuf2_v4l2 snd_usbmidi_lib videobuf2_core snd_rawmidi snd_hda_core drm snd_seq_device videodev snd_pcm i2c_i801 usbhid snd_timer i2c_core snd backlight soundcore r8169 parport_pc mii parport
> Feb 6 14:28:20 ragnarok kernel: CPU: 0 PID: 4 Comm: kworker/0:0H Not tainted 4.14.18 #1
> Feb 6 14:28:20 ragnarok kernel: Hardware name: Gigabyte Technology Co., Ltd. P67-DS3-B3/P67-DS3-B3, BIOS F1 05/06/2011
> Feb 6 14:28:20 ragnarok kernel: Workqueue: kblockd blk_mq_requeue_work
> Feb 6 14:28:20 ragnarok kernel: task: ffff88060395a1c0 task.stack: ffffc90000044000
> Feb 6 14:28:20 ragnarok kernel: RIP: 0010:bfq_put_queue+0x10b/0x130 [bfq]
> Feb 6 14:28:20 ragnarok kernel: RSP: 0018:ffffc90000047ca0 EFLAGS: 00010286
> Feb 6 14:28:20 ragnarok kernel: RAX: 0000000000000008 RBX: ffff8806023db690 RCX: 0000000000000000
> Feb 6 14:28:20 ragnarok kernel: RDX: 0000000000000000 RSI: ffff880601bb39b0 RDI: ffff880601a56400
> Feb 6 14:28:20 ragnarok kernel: RBP: 0000000001bb3980 R08: 0000000000000053 R09: ffff8806023db690
> Feb 6 14:28:20 ragnarok kernel: R10: 000000001dd0f11e R11: 00000000080a011b R12: ffff880601a56400
> Feb 6 14:28:20 ragnarok kernel: R13: ffff8806023dbed0 R14: 0000000000000053 R15: 0000000000000000
> Feb 6 14:28:20 ragnarok kernel: FS: 0000000000000000(0000) GS:ffff88061f400000(0000) knlGS:0000000000000000
> Feb 6 14:28:20 ragnarok kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> Feb 6 14:28:20 ragnarok kernel: CR2: 0000000000000030 CR3: 000000000200a002 CR4: 00000000000606f0
> Feb 6 14:28:20 ragnarok kernel: Call Trace:
> Feb 6 14:28:20 ragnarok kernel: bfq_finish_requeue_request+0x4b/0x370 [bfq]
> Feb 6 14:28:20 ragnarok kernel: __blk_mq_requeue_request+0x57/0x130
> Feb 6 14:28:20 ragnarok kernel: blk_mq_dispatch_rq_list+0x1b3/0x510
> Feb 6 14:28:20 ragnarok kernel: ? __bfq_bfqd_reset_in_service+0x20/0x70 [bfq]
> Feb 6 14:28:20 ragnarok kernel: ? bfq_bfqq_expire+0x212/0x740 [bfq]
> Feb 6 14:28:20 ragnarok kernel: blk_mq_sched_dispatch_requests+0xf0/0x170
> Feb 6 14:28:20 ragnarok kernel: __blk_mq_run_hw_queue+0x4e/0x90
> Feb 6 14:28:20 ragnarok kernel: __blk_mq_delay_run_hw_queue+0x73/0x80
> Feb 6 14:28:20 ragnarok kernel: blk_mq_run_hw_queue+0x53/0x150
> Feb 6 14:28:20 ragnarok kernel: blk_mq_run_hw_queues+0x3a/0x50
> Feb 6 14:28:20 ragnarok kernel: blk_mq_requeue_work+0x104/0x110
> Feb 6 14:28:20 ragnarok kernel: process_one_work+0x1d4/0x3d0
> Feb 6 14:28:20 ragnarok kernel: worker_thread+0x2b/0x3c0
> Feb 6 14:28:20 ragnarok kernel: ? process_one_work+0x3d0/0x3d0
> Feb 6 14:28:20 ragnarok kernel: kthread+0x117/0x130
> Feb 6 14:28:20 ragnarok kernel: ? kthread_create_on_node+0x40/0x40
> Feb 6 14:28:20 ragnarok kernel: ret_from_fork+0x1f/0x30
> Feb 6 14:28:20 ragnarok kernel: Code: c1 e8 06 83 e0 01 48 83 f8 01 45 19 f6 e8 ce 3a 00 00 41 83 e6 ee 48 89 c7 41 83 c6 53 e8 9e 3a 00 00 49 89 d9 45 89 f0 44 89 f9 <48> 8b 70 28 48 c7 c2 d8 00 25 a0 55 4c 89 ef e8 11 ba ea e0 8b
> Feb 6 14:28:20 ragnarok kernel: RIP: bfq_put_queue+0x10b/0x130 [bfq] RSP: ffffc90000047ca0
> Feb 6 14:28:20 ragnarok kernel: CR2: 0000000000000030
> Feb 6 14:28:20 ragnarok kernel: ---[ end trace 8b782ace30a4e7d8 ]---
>
Same request: please
gdb <buildir>/block/bfq-iosched.o
list *(bfq_finish_requeue_request+0x4b)
list *(bfq_put_queue+0x10b)
Thanks,
Paolo
> Yes, this is 4.14.x but with most-of block/4.16, rock-solid otherwise (in daily use).
> Looks like there is something wrong with this patch after all..
>
> cheers
> Holger
>
06.02.2018 15:50, Paolo Valente wrote:
> Could you please do a
> gdb <buildir>/block/bfq-iosched.o # or vmlinux.o if bfq is builtin
> list *(bfq_finish_requeue_request+0x54)
> list *(bfq_put_queue+0x10b)
> for me?
Yes. Just give me some time to recompile the kernel with minimal debug
info enabled. I'll post then list/disasm and new stacktraces.
On 02/06/18 15:55, Paolo Valente wrote:
>
>
>> Il giorno 06 feb 2018, alle ore 14:40, Holger Hoffstätte <[email protected]> ha scritto:
>>
>>
>> The plot thickens!
>>
>
> Yep, the culprit seems clearer, though ...
>
>> Just as I was about to post that I didn't have any problems - because
>> I didn't have any - I decided to do a second test, activated bfq on my
>> workstation, on a hunch typed "sync" and .. the machine locked up, hard.
>>
>> Rebooted, activated bfq, typed sync..sync hangs. Luckily this time
>> a second terminal was still alive, so I could capture a trace for
>> your enjoyment:
>>
>> Feb 6 14:28:17 ragnarok kernel: io scheduler bfq registered
>> Feb 6 14:28:20 ragnarok kernel: BUG: unable to handle kernel NULL pointer dereference at 0000000000000030
>> Feb 6 14:28:20 ragnarok kernel: IP: bfq_put_queue+0x10b/0x130 [bfq]
>> Feb 6 14:28:20 ragnarok kernel: PGD 0 P4D 0
>> Feb 6 14:28:20 ragnarok kernel: Oops: 0000 [#1] SMP PTI
>> Feb 6 14:28:20 ragnarok kernel: Modules linked in: bfq lz4 lz4_compress lz4_decompress nfs lockd grace sunrpc autofs4 sch_fq_codel it87 hwmon_vid x86_pkg_temp_thermal snd_hda_codec_realtek coretemp radeon crc32_pclmul snd_hda_codec_generic crc32c_intel pcbc snd_hda_codec_hdmi i2c_algo_bit aesni_intel drm_kms_helper aes_x86_64 uvcvideo syscopyarea crypto_simd snd_hda_intel sysfillrect cryptd snd_usb_audio sysimgblt videobuf2_vmalloc glue_helper fb_sys_fops snd_hda_codec snd_hwdep videobuf2_memops ttm videobuf2_v4l2 snd_usbmidi_lib videobuf2_core snd_rawmidi snd_hda_core drm snd_seq_device videodev snd_pcm i2c_i801 usbhid snd_timer i2c_core snd backlight soundcore r8169 parport_pc mii parport
>> Feb 6 14:28:20 ragnarok kernel: CPU: 0 PID: 4 Comm: kworker/0:0H Not tainted 4.14.18 #1
>> Feb 6 14:28:20 ragnarok kernel: Hardware name: Gigabyte Technology Co., Ltd. P67-DS3-B3/P67-DS3-B3, BIOS F1 05/06/2011
>> Feb 6 14:28:20 ragnarok kernel: Workqueue: kblockd blk_mq_requeue_work
>> Feb 6 14:28:20 ragnarok kernel: task: ffff88060395a1c0 task.stack: ffffc90000044000
>> Feb 6 14:28:20 ragnarok kernel: RIP: 0010:bfq_put_queue+0x10b/0x130 [bfq]
>> Feb 6 14:28:20 ragnarok kernel: RSP: 0018:ffffc90000047ca0 EFLAGS: 00010286
>> Feb 6 14:28:20 ragnarok kernel: RAX: 0000000000000008 RBX: ffff8806023db690 RCX: 0000000000000000
>> Feb 6 14:28:20 ragnarok kernel: RDX: 0000000000000000 RSI: ffff880601bb39b0 RDI: ffff880601a56400
>> Feb 6 14:28:20 ragnarok kernel: RBP: 0000000001bb3980 R08: 0000000000000053 R09: ffff8806023db690
>> Feb 6 14:28:20 ragnarok kernel: R10: 000000001dd0f11e R11: 00000000080a011b R12: ffff880601a56400
>> Feb 6 14:28:20 ragnarok kernel: R13: ffff8806023dbed0 R14: 0000000000000053 R15: 0000000000000000
>> Feb 6 14:28:20 ragnarok kernel: FS: 0000000000000000(0000) GS:ffff88061f400000(0000) knlGS:0000000000000000
>> Feb 6 14:28:20 ragnarok kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> Feb 6 14:28:20 ragnarok kernel: CR2: 0000000000000030 CR3: 000000000200a002 CR4: 00000000000606f0
>> Feb 6 14:28:20 ragnarok kernel: Call Trace:
>> Feb 6 14:28:20 ragnarok kernel: bfq_finish_requeue_request+0x4b/0x370 [bfq]
>> Feb 6 14:28:20 ragnarok kernel: __blk_mq_requeue_request+0x57/0x130
>> Feb 6 14:28:20 ragnarok kernel: blk_mq_dispatch_rq_list+0x1b3/0x510
>> Feb 6 14:28:20 ragnarok kernel: ? __bfq_bfqd_reset_in_service+0x20/0x70 [bfq]
>> Feb 6 14:28:20 ragnarok kernel: ? bfq_bfqq_expire+0x212/0x740 [bfq]
>> Feb 6 14:28:20 ragnarok kernel: blk_mq_sched_dispatch_requests+0xf0/0x170
>> Feb 6 14:28:20 ragnarok kernel: __blk_mq_run_hw_queue+0x4e/0x90
>> Feb 6 14:28:20 ragnarok kernel: __blk_mq_delay_run_hw_queue+0x73/0x80
>> Feb 6 14:28:20 ragnarok kernel: blk_mq_run_hw_queue+0x53/0x150
>> Feb 6 14:28:20 ragnarok kernel: blk_mq_run_hw_queues+0x3a/0x50
>> Feb 6 14:28:20 ragnarok kernel: blk_mq_requeue_work+0x104/0x110
>> Feb 6 14:28:20 ragnarok kernel: process_one_work+0x1d4/0x3d0
>> Feb 6 14:28:20 ragnarok kernel: worker_thread+0x2b/0x3c0
>> Feb 6 14:28:20 ragnarok kernel: ? process_one_work+0x3d0/0x3d0
>> Feb 6 14:28:20 ragnarok kernel: kthread+0x117/0x130
>> Feb 6 14:28:20 ragnarok kernel: ? kthread_create_on_node+0x40/0x40
>> Feb 6 14:28:20 ragnarok kernel: ret_from_fork+0x1f/0x30
>> Feb 6 14:28:20 ragnarok kernel: Code: c1 e8 06 83 e0 01 48 83 f8 01 45 19 f6 e8 ce 3a 00 00 41 83 e6 ee 48 89 c7 41 83 c6 53 e8 9e 3a 00 00 49 89 d9 45 89 f0 44 89 f9 <48> 8b 70 28 48 c7 c2 d8 00 25 a0 55 4c 89 ef e8 11 ba ea e0 8b
>> Feb 6 14:28:20 ragnarok kernel: RIP: bfq_put_queue+0x10b/0x130 [bfq] RSP: ffffc90000047ca0
>> Feb 6 14:28:20 ragnarok kernel: CR2: 0000000000000030
>> Feb 6 14:28:20 ragnarok kernel: ---[ end trace 8b782ace30a4e7d8 ]---
>>
>
> Same request: please
> gdb <buildir>/block/bfq-iosched.o
> list *(bfq_finish_requeue_request+0x4b)
> list *(bfq_put_queue+0x10b)
(gdb) list *(bfq_finish_requeue_request+0x4b)
0x46cb is in bfq_finish_requeue_request (block/bfq-iosched.c:4804).
4799 * that re-insertions of requeued requests, without
4800 * re-preparation, can happen only for pass_through or at_head
4801 * requests (which are not re-inserted into bfq internal
4802 * queues).
4803 */
4804 rq->elv.priv[0] = NULL;
4805 rq->elv.priv[1] = NULL;
4806 }
4807
4808 /*
(gdb) list *(bfq_put_queue+0x10b)
0x415b is in bfq_put_queue (block/bfq-iosched.c:3978).
3973 #ifdef CONFIG_BFQ_GROUP_IOSCHED
3974 struct bfq_group *bfqg = bfqq_group(bfqq);
3975 #endif
3976
3977 if (bfqq->bfqd)
3978 bfq_log_bfqq(bfqq->bfqd, bfqq, "put_queue: %p %d",
3979 bfqq, bfqq->ref);
3980
3981 bfqq->ref--;
3982 if (bfqq->ref)
Hope this helps!
Holger
Hi.
06.02.2018 15:50, Paolo Valente wrote:
> Could you please do a
> gdb <buildir>/block/bfq-iosched.o # or vmlinux.o if bfq is builtin
> list *(bfq_finish_requeue_request+0x54)
> list *(bfq_put_queue+0x10b)
> for me?
Fresh crashes and gdb output are given below. A side note: it is harder
to trigger things on a slower machine, so clearly some timing-bounded
race condition there.
[ 134.276548] BUG: unable to handle kernel NULL pointer dereference at
(null)
[ 134.283699] IP: blk_flush_complete_seq+0x20a/0x300
[ 134.288163] PGD 0 P4D 0
[ 134.291284] Oops: 0002 [#1] PREEMPT SMP PTI
[ 134.293842] Modules linked in: bochs_drm ttm nls_iso8859_1 kvm_intel
nls_cp437 vfat fat drm_kms_helper kvm drm irqbypass psmouse iTCO_wdt
ppdev iTCO_vendor_support input_leds led_class i2c_i801 parport_pc
joydev intel_agp parport intel_gtt mousedev lpc_ich rtc_cmos syscopyarea
evdev sysfillrect agpgart qemu_fw_cfg mac_hid sysimgblt fb_sys_fops
sch_fq_codel ip_tables x_tables xfs dm_thin_pool dm_persistent_data
dm_bio_prison dm_bufio libcrc32c crc32c_generic dm_crypt algif_skcipher
af_alg dm_mod hid_generic usbhid raid10 hid md_mod sr_mod sd_mod cdrom
uhci_hcd ehci_pci serio_raw crct10dif_pclmul crc32_pclmul atkbd
crc32c_intel libps2 ghash_clmulni_intel pcbc xhci_pci xhci_hcd ehci_hcd
aesni_intel aes_x86_64 crypto_simd glue_helper cryptd ahci libahci
libata usbcore usb_common i8042 serio virtio_scsi
[ 134.340606] scsi_mod virtio_blk virtio_net virtio_pci virtio_ring
virtio
[ 134.345803] CPU: 0 PID: 178 Comm: kworker/0:1H Not tainted 4.15.0-pf2
#1
[ 134.350309] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS
0.0.0 02/06/2015
[ 134.355106] Workqueue: kblockd blk_mq_run_work_fn
[ 134.359034] RIP: 0010:blk_flush_complete_seq+0x20a/0x300
[ 134.367647] RSP: 0000:ffff88000f803ce8 EFLAGS: 00010082
[ 134.371632] RAX: ffff88000d9755c0 RBX: ffff88000d9755a0 RCX:
ffff88000c9b39a8
[ 134.375675] RDX: 0000000000000000 RSI: ffff88000d9755d0 RDI:
ffff88000c9b3900
[ 134.381068] RBP: ffff88000d21a990 R08: ffff88000d9755b0 R09:
0000000000000000
[ 134.386302] R10: ffff8800058ff100 R11: 000000000002000b R12:
0000000000000000
[ 134.396915] R13: ffff88000d9755f0 R14: 0000000000000046 R15:
ffff88000d9755a0
[ 134.401140] FS: 0000000000000000(0000) GS:ffff88000f800000(0000)
knlGS:0000000000000000
[ 134.407361] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 134.412384] CR2: 0000000000000000 CR3: 0000000004008006 CR4:
00000000001606f0
[ 134.416913] Call Trace:
[ 134.420251] <IRQ>
[ 134.427731] mq_flush_data_end_io+0xb3/0xf0
[ 134.431848] scsi_end_request+0x90/0x1e0 [scsi_mod]
[ 134.436424] scsi_io_completion+0x237/0x650 [scsi_mod]
[ 134.440109] __blk_mq_complete_request+0xc4/0x150
[ 134.444517] ? scsi_mq_get_budget+0x110/0x110 [scsi_mod]
[ 134.449603] ata_scsi_qc_complete+0x8d/0x430 [libata]
[ 134.458487] ata_qc_complete_multiple+0x8d/0xe0 [libata]
[ 134.461726] ahci_handle_port_interrupt+0xc9/0x5b0 [libahci]
[ 134.466420] ahci_handle_port_intr+0x54/0xb0 [libahci]
[ 134.470128] ahci_single_level_irq_intr+0x3b/0x60 [libahci]
[ 134.473327] __handle_irq_event_percpu+0x44/0x1e0
[ 134.476700] handle_irq_event_percpu+0x30/0x70
[ 134.480227] handle_irq_event+0x37/0x60
[ 134.490341] handle_edge_irq+0x107/0x1c0
[ 134.492876] handle_irq+0x1f/0x30
[ 134.495497] do_IRQ+0x4d/0xe0
[ 134.497963] common_interrupt+0xa2/0xa2
[ 134.500877] </IRQ>
[ 134.503129] RIP: 0010:_raw_spin_unlock_irqrestore+0x11/0x40
[ 134.506782] RSP: 0000:ffffc90000307d30 EFLAGS: 00000293 ORIG_RAX:
ffffffffffffffdb
[ 134.511845] RAX: 0000000000000001 RBX: ffff88000db04000 RCX:
0000000000000008
[ 134.523019] RDX: 0000000000000100 RSI: 0000000000000293 RDI:
0000000000000293
[ 134.527968] RBP: 0000000000000293 R08: ffffffffffffffff R09:
0000000000000040
[ 134.532289] R10: 00000000008e66bf R11: 000000000002000b R12:
0000000000000000
[ 134.536376] R13: ffff88000d26a000 R14: ffff88000b99ac48 R15:
ffff88000d26a000
[ 134.541046] ata_scsi_queuecmd+0xa0/0x210 [libata]
[ 134.544363] scsi_dispatch_cmd+0xe8/0x260 [scsi_mod]
[ 134.552883] scsi_queue_rq+0x4cf/0x560 [scsi_mod]
[ 134.556811] blk_mq_dispatch_rq_list+0x8f/0x4c0
[ 134.559741] blk_mq_sched_dispatch_requests+0x105/0x190
[ 134.563253] __blk_mq_run_hw_queue+0x80/0x90
[ 134.565540] process_one_work+0x1df/0x420
[ 134.568041] worker_thread+0x2b/0x3d0
[ 134.571032] ? process_one_work+0x420/0x420
[ 134.573964] kthread+0x113/0x130
[ 134.584370] ? kthread_create_on_node+0x70/0x70
[ 134.587355] ret_from_fork+0x35/0x40
[ 134.589796] Code: 39 d0 0f 84 8f 00 00 00 48 8b 97 b0 00 00 00 49 c1
e0 04 45 31 e4 48 8b b7 a8 00 00 00 49 01 d8 48 8d 8f a8 00 00 00 48 89
56 08 <48> 89 32 49 8b 50 18 49 89 48 18 48 89 87 a8 00 00 00 48 89 97
[ 134.598881] RIP: blk_flush_complete_seq+0x20a/0x300 RSP:
ffff88000f803ce8
[ 134.601812] CR2: 0000000000000000
[ 134.603728] ---[ end trace fc6d0cdf33d29717 ]---
[ 134.612349] Kernel panic - not syncing: Fatal exception in interrupt
[ 134.615630] Kernel Offset: disabled
[ 134.617712] ---[ end Kernel panic - not syncing: Fatal exception in
interrupt
(gdb) list *(blk_flush_complete_seq+0x20a)
0xffffffff813056ca is in blk_flush_complete_seq
(./include/linux/compiler.h:212).
207 {
208 switch (size) {
209 case 1: *(volatile __u8 *)p = *(__u8 *)res; break;
210 case 2: *(volatile __u16 *)p = *(__u16 *)res; break;
211 case 4: *(volatile __u32 *)p = *(__u32 *)res; break;
212 case 8: *(volatile __u64 *)p = *(__u64 *)res; break;
213 default:
214 barrier();
215 __builtin_memcpy((void *)p, (const void *)res,
size);
216 barrier();
[ 231.545605] BUG: unable to handle kernel paging request at
0000001000000028
[ 231.551962] IP: bfq_put_queue+0x10b/0x130
[ 231.556307] PGD 0 P4D 0
[ 231.558939] Oops: 0000 [#1] PREEMPT SMP PTI
[ 231.562149] Modules linked in: nls_iso8859_1 nls_cp437 vfat fat
kvm_intel kvm bochs_drm irqbypass ttm iTCO_wdt ppdev drm_kms_helper
iTCO_vendor_support psmouse input_leds drm led_class joydev parport_pc
mousedev intel_agp syscopyarea parport intel_gtt sysfillrect i2c_i801
evdev sysimgblt agpgart rtc_cmos qemu_fw_cfg mac_hid fb_sys_fops lpc_ich
sch_fq_codel ip_tables x_tables xfs dm_thin_pool dm_persistent_data
dm_bio_prison dm_bufio libcrc32c crc32c_generic dm_crypt algif_skcipher
af_alg dm_mod hid_generic usbhid hid raid10 md_mod sr_mod cdrom sd_mod
serio_raw atkbd libps2 uhci_hcd crct10dif_pclmul crc32_pclmul
crc32c_intel ghash_clmulni_intel pcbc xhci_pci aesni_intel aes_x86_64
ehci_pci xhci_hcd ehci_hcd ahci crypto_simd glue_helper libahci cryptd
usbcore libata usb_common i8042 serio virtio_scsi
[ 231.608289] scsi_mod virtio_blk virtio_net virtio_pci virtio_ring
virtio
[ 231.613610] CPU: 0 PID: 187 Comm: kworker/0:1H Not tainted 4.15.0-pf2
#1
[ 231.619675] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS
0.0.0 02/06/2015
[ 231.624477] Workqueue: kblockd blk_mq_requeue_work
[ 231.628532] RIP: 0010:bfq_put_queue+0x10b/0x130
[ 231.635453] RSP: 0000:ffffc90000377c98 EFLAGS: 00010282
[ 231.638621] RAX: 0000001000000000 RBX: ffff88000cdf20f0 RCX:
0000000000000000
[ 231.642332] RDX: 0000000000000000 RSI: ffff88000d4926d8 RDI:
ffff88000cdf2120
[ 231.647000] RBP: 000000000d4926a8 R08: 0000000000000041 R09:
ffff88000cdf20f0
[ 231.652682] R10: 0000000000105a7f R11: 000000000002000b R12:
ffff88000cdf2120
[ 231.657102] R13: ffff88000e152188 R14: 0000000000000041 R15:
0000000000000000
[ 231.661213] FS: 0000000000000000(0000) GS:ffff88000f800000(0000)
knlGS:0000000000000000
[ 231.664746] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 231.667647] CR2: 0000001000000028 CR3: 0000000004008002 CR4:
00000000001606f0
[ 231.671475] Call Trace:
[ 231.673873] bfq_finish_requeue_request+0x54/0x380
[ 231.676823] __blk_mq_requeue_request+0x5c/0x140
[ 231.679465] blk_mq_dispatch_rq_list+0x1b4/0x4c0
[ 231.681798] blk_mq_sched_dispatch_requests+0x105/0x190
[ 231.685059] __blk_mq_run_hw_queue+0x80/0x90
[ 231.687750] __blk_mq_delay_run_hw_queue+0x92/0xe0
[ 231.691510] blk_mq_run_hw_queue+0x25/0x90
[ 231.694759] blk_mq_run_hw_queues+0x3a/0x50
[ 231.696706] blk_mq_requeue_work+0x116/0x140
[ 231.699340] process_one_work+0x1df/0x420
[ 231.703147] worker_thread+0x2b/0x3d0
[ 231.705322] ? process_one_work+0x420/0x420
[ 231.707002] kthread+0x113/0x130
[ 231.708494] ? kthread_create_on_node+0x70/0x70
[ 231.710209] ? kthread_create_on_node+0x70/0x70
[ 231.712754] ret_from_fork+0x35/0x40
[ 231.715068] Code: c1 e8 06 83 e0 01 48 83 f8 01 45 19 f6 e8 be 3b 00
00 41 83 e6 ee 48 89 c7 41 83 c6 53 e8 8e 3b 00 00 49 89 d9 45 89 f0 44
89 f9 <48> 8b 70 28 48 c7 c2 3a 9a e5 81 55 4c 89 ef e8 11 1c e0 ff 8b
[ 231.725379] RIP: bfq_put_queue+0x10b/0x130 RSP: ffffc90000377c98
[ 231.728391] CR2: 0000001000000028
[ 231.730840] ---[ end trace 03bd81aa0d2b1434 ]---
[ 231.733269] note: kworker/0:1H[187] exited with preempt_count 1
(gdb) l *(bfq_put_queue+0x10b)
0xffffffff81334d1b is in bfq_put_queue (block/bfq-iosched.c:3978).
3973 #ifdef CONFIG_BFQ_GROUP_IOSCHED
3974 struct bfq_group *bfqg = bfqq_group(bfqq);
3975 #endif
3976
3977 if (bfqq->bfqd)
3978 bfq_log_bfqq(bfqq->bfqd, bfqq, "put_queue: %p
%d",
3979 bfqq, bfqq->ref);
3980
3981 bfqq->ref--;
3982 if (bfqq->ref)
(gdb) l *(bfq_finish_requeue_request+0x54)
0xffffffff81335294 is in bfq_finish_requeue_request
(block/bfq-iosched.c:4804).
4799 * that re-insertions of requeued requests, without
4800 * re-preparation, can happen only for pass_through or
at_head
4801 * requests (which are not re-inserted into bfq internal
4802 * queues).
4803 */
4804 rq->elv.priv[0] = NULL;
4805 rq->elv.priv[1] = NULL;
4806 }
4807
4808 /*
[ 322.939697] BUG: unable to handle kernel NULL pointer dereference at
0000000000000008
[ 322.944283] IP: blk_flush_complete_seq+0x206/0x300
[ 322.947463] PGD 0 P4D 0
[ 322.950266] Oops: 0002 [#2] PREEMPT SMP PTI
[ 322.958898] Modules linked in: kvm_intel bochs_drm nls_iso8859_1
nls_cp437 vfat fat ttm kvm drm_kms_helper drm iTCO_wdt irqbypass psmouse
ppdev iTCO_vendor_support input_leds led_class i2c_i801 intel_agp
parport_pc intel_gtt joydev lpc_ich rtc_cmos agpgart evdev parport
syscopyarea mousedev qemu_fw_cfg sysfillrect mac_hid sysimgblt
fb_sys_fops sch_fq_codel ip_tables x_tables xfs dm_thin_pool
dm_persistent_data dm_bio_prison dm_bufio libcrc32c crc32c_generic
dm_crypt algif_skcipher af_alg dm_mod hid_generic usbhid hid
crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel raid10
pcbc md_mod sr_mod cdrom sd_mod serio_raw atkbd libps2 uhci_hcd xhci_pci
xhci_hcd ahci ehci_pci libahci aesni_intel aes_x86_64 crypto_simd
glue_helper ehci_hcd cryptd libata usbcore usb_common i8042 serio
virtio_scsi
[ 323.001668] scsi_mod virtio_blk virtio_net virtio_pci virtio_ring
virtio
[ 323.006121] CPU: 0 PID: 215 Comm: kworker/u5:1 Tainted: G D
4.15.0-pf2 #1
[ 323.010263] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS
0.0.0 02/06/2015
[ 323.021225] Workqueue: kcryptd kcryptd_crypt [dm_crypt]
[ 323.024947] RIP: 0010:blk_flush_complete_seq+0x206/0x300
[ 323.028405] RSP: 0018:ffff88000f803ed0 EFLAGS: 00010086
[ 323.032491] RAX: ffff88000cfe78b0 RBX: ffff88000cfe78a0 RCX:
ffff88000d4d85a8
[ 323.036262] RDX: 0000000000000000 RSI: 0000000000000000 RDI:
ffff88000d4d8500
[ 323.041032] RBP: ffff88000d6510a0 R08: ffff88000cfe78a0 R09:
0000000000000000
[ 323.051518] R10: ffff88000dab4d00 R11: ffffffffc01aafb0 R12:
0000000000000000
[ 323.055818] R13: ffff88000cfe78f0 R14: 0000000000000046 R15:
ffff88000cfe78a0
[ 323.060965] FS: 0000000000000000(0000) GS:ffff88000f800000(0000)
knlGS:0000000000000000
[ 323.065902] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 323.070571] CR2: 0000000000000008 CR3: 0000000004008001 CR4:
00000000001606f0
[ 323.076591] Call Trace:
[ 323.081685] <IRQ>
[ 323.084025] mq_flush_data_end_io+0xb3/0xf0
[ 323.087155] scsi_end_request+0x90/0x1e0 [scsi_mod]
[ 323.095768] scsi_io_completion+0x237/0x650 [scsi_mod]
[ 323.099928] flush_smp_call_function_queue+0x7c/0xf0
[ 323.104028] smp_call_function_single_interrupt+0x32/0xf0
[ 323.114170] call_function_single_interrupt+0xa2/0xb0
[ 323.118208] </IRQ>
[ 323.121040] RIP: 0010:_aesni_enc4+0x178/0x190 [aesni_intel]
[ 323.124658] RSP: 0018:ffffc900004a7c40 EFLAGS: 00000293 ORIG_RAX:
ffffffffffffff04
[ 323.128777] RAX: ffffffffc01ab208 RBX: 0000000000000180 RCX:
0000000000000000
[ 323.133003] RDX: ffff88000daf9c80 RSI: ffff88000a2b3c80 RDI:
ffff88000cd24260
[ 323.139211] RBP: ffffc900004a7d40 R08: ffff8800089f7718 R09:
0000000000000010
[ 323.146930] R10: ffff88000cd24290 R11: ffffffffc01aafb0 R12:
0000000000000080
[ 323.151758] R13: ffffffffc01c90c8 R14: ffff88000a2b3d00 R15:
ffff88000daf9d00
[ 323.156507] ? _aesni_enc1+0xac/0xac [aesni_intel]
[ 323.160419] ? _aesni_dec1+0xac/0xac [aesni_intel]
[ 323.164204] ? aesni_xts_crypt8+0x21e/0x260 [aesni_intel]
[ 323.167322] ? glue_xts_req_128bit+0x125/0x1d0 [glue_helper]
[ 323.178383] ? crypt_convert+0x961/0xef0 [dm_crypt]
[ 323.182089] ? xts_decrypt+0x40/0x40 [aesni_intel]
[ 323.185825] ? crypt_convert+0x961/0xef0 [dm_crypt]
[ 323.189438] ? bio_alloc_bioset+0x132/0x1e0
[ 323.191926] ? kcryptd_crypt+0x1ff/0x360 [dm_crypt]
[ 323.194998] ? process_one_work+0x1df/0x420
[ 323.197475] ? worker_thread+0x2b/0x3d0
[ 323.206991] ? process_one_work+0x420/0x420
[ 323.210387] ? kthread+0x113/0x130
[ 323.213396] ? kthread_create_on_node+0x70/0x70
[ 323.216751] ? ret_from_fork+0x35/0x40
[ 323.220815] Code: 48 8b 10 48 39 d0 0f 84 8f 00 00 00 48 8b 97 b0 00
00 00 49 c1 e0 04 45 31 e4 48 8b b7 a8 00 00 00 49 01 d8 48 8d 8f a8 00
00 00 <48> 89 56 08 48 89 32 49 8b 50 18 49 89 48 18 48 89 87 a8 00 00
[ 323.233543] RIP: blk_flush_complete_seq+0x206/0x300 RSP:
ffff88000f803ed0
[ 323.238885] CR2: 0000000000000008
[ 323.241673] ---[ end trace 2ec7b63c3a4a4a02 ]---
[ 323.245006] Kernel panic - not syncing: Fatal exception in interrupt
[ 323.248858] Kernel Offset: disabled
[ 323.250753] ---[ end Kernel panic - not syncing: Fatal exception in
interrupt
(gdb) l *(blk_flush_complete_seq+0x206)
0xffffffff813056c6 is in blk_flush_complete_seq
(./include/linux/list.h:105).
100 * This is only for internal list manipulation where we know
101 * the prev/next entries already!
102 */
103 static inline void __list_del(struct list_head * prev, struct
list_head * next)
104 {
105 next->prev = prev;
106 WRITE_ONCE(prev->next, next);
107 }
108
109 /**
> Il giorno 06 feb 2018, alle ore 19:35, Oleksandr Natalenko <[email protected]> ha scritto:
>
> Hi.
>
> 06.02.2018 15:50, Paolo Valente wrote:
>> Could you please do a
>> gdb <buildir>/block/bfq-iosched.o # or vmlinux.o if bfq is builtin
>> list *(bfq_finish_requeue_request+0x54)
>> list *(bfq_put_queue+0x10b)
>> for me?
>
> Fresh crashes and gdb output are given below. A side note: it is harder to trigger things on a slower machine, so clearly some timing-bounded race condition there.
>
> [ 134.276548] BUG: unable to handle kernel NULL pointer dereference at (null)
> [ 134.283699] IP: blk_flush_complete_seq+0x20a/0x300
> [ 134.288163] PGD 0 P4D 0
> [ 134.291284] Oops: 0002 [#1] PREEMPT SMP PTI
> [ 134.293842] Modules linked in: bochs_drm ttm nls_iso8859_1 kvm_intel nls_cp437 vfat fat drm_kms_helper kvm drm irqbypass psmouse iTCO_wdt ppdev iTCO_vendor_support input_leds led_class i2c_i801 parport_pc joydev intel_agp parport intel_gtt mousedev lpc_ich rtc_cmos syscopyarea evdev sysfillrect agpgart qemu_fw_cfg mac_hid sysimgblt fb_sys_fops sch_fq_codel ip_tables x_tables xfs dm_thin_pool dm_persistent_data dm_bio_prison dm_bufio libcrc32c crc32c_generic dm_crypt algif_skcipher af_alg dm_mod hid_generic usbhid raid10 hid md_mod sr_mod sd_mod cdrom uhci_hcd ehci_pci serio_raw crct10dif_pclmul crc32_pclmul atkbd crc32c_intel libps2 ghash_clmulni_intel pcbc xhci_pci xhci_hcd ehci_hcd aesni_intel aes_x86_64 crypto_simd glue_helper cryptd ahci libahci libata usbcore usb_common i8042 serio virtio_scsi
> [ 134.340606] scsi_mod virtio_blk virtio_net virtio_pci virtio_ring virtio
> [ 134.345803] CPU: 0 PID: 178 Comm: kworker/0:1H Not tainted 4.15.0-pf2 #1
> [ 134.350309] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
> [ 134.355106] Workqueue: kblockd blk_mq_run_work_fn
> [ 134.359034] RIP: 0010:blk_flush_complete_seq+0x20a/0x300
> [ 134.367647] RSP: 0000:ffff88000f803ce8 EFLAGS: 00010082
> [ 134.371632] RAX: ffff88000d9755c0 RBX: ffff88000d9755a0 RCX: ffff88000c9b39a8
> [ 134.375675] RDX: 0000000000000000 RSI: ffff88000d9755d0 RDI: ffff88000c9b3900
> [ 134.381068] RBP: ffff88000d21a990 R08: ffff88000d9755b0 R09: 0000000000000000
> [ 134.386302] R10: ffff8800058ff100 R11: 000000000002000b R12: 0000000000000000
> [ 134.396915] R13: ffff88000d9755f0 R14: 0000000000000046 R15: ffff88000d9755a0
> [ 134.401140] FS: 0000000000000000(0000) GS:ffff88000f800000(0000) knlGS:0000000000000000
> [ 134.407361] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 134.412384] CR2: 0000000000000000 CR3: 0000000004008006 CR4: 00000000001606f0
> [ 134.416913] Call Trace:
> [ 134.420251] <IRQ>
> [ 134.427731] mq_flush_data_end_io+0xb3/0xf0
> [ 134.431848] scsi_end_request+0x90/0x1e0 [scsi_mod]
> [ 134.436424] scsi_io_completion+0x237/0x650 [scsi_mod]
> [ 134.440109] __blk_mq_complete_request+0xc4/0x150
> [ 134.444517] ? scsi_mq_get_budget+0x110/0x110 [scsi_mod]
> [ 134.449603] ata_scsi_qc_complete+0x8d/0x430 [libata]
> [ 134.458487] ata_qc_complete_multiple+0x8d/0xe0 [libata]
> [ 134.461726] ahci_handle_port_interrupt+0xc9/0x5b0 [libahci]
> [ 134.466420] ahci_handle_port_intr+0x54/0xb0 [libahci]
> [ 134.470128] ahci_single_level_irq_intr+0x3b/0x60 [libahci]
> [ 134.473327] __handle_irq_event_percpu+0x44/0x1e0
> [ 134.476700] handle_irq_event_percpu+0x30/0x70
> [ 134.480227] handle_irq_event+0x37/0x60
> [ 134.490341] handle_edge_irq+0x107/0x1c0
> [ 134.492876] handle_irq+0x1f/0x30
> [ 134.495497] do_IRQ+0x4d/0xe0
> [ 134.497963] common_interrupt+0xa2/0xa2
> [ 134.500877] </IRQ>
> [ 134.503129] RIP: 0010:_raw_spin_unlock_irqrestore+0x11/0x40
> [ 134.506782] RSP: 0000:ffffc90000307d30 EFLAGS: 00000293 ORIG_RAX: ffffffffffffffdb
> [ 134.511845] RAX: 0000000000000001 RBX: ffff88000db04000 RCX: 0000000000000008
> [ 134.523019] RDX: 0000000000000100 RSI: 0000000000000293 RDI: 0000000000000293
> [ 134.527968] RBP: 0000000000000293 R08: ffffffffffffffff R09: 0000000000000040
> [ 134.532289] R10: 00000000008e66bf R11: 000000000002000b R12: 0000000000000000
> [ 134.536376] R13: ffff88000d26a000 R14: ffff88000b99ac48 R15: ffff88000d26a000
> [ 134.541046] ata_scsi_queuecmd+0xa0/0x210 [libata]
> [ 134.544363] scsi_dispatch_cmd+0xe8/0x260 [scsi_mod]
> [ 134.552883] scsi_queue_rq+0x4cf/0x560 [scsi_mod]
> [ 134.556811] blk_mq_dispatch_rq_list+0x8f/0x4c0
> [ 134.559741] blk_mq_sched_dispatch_requests+0x105/0x190
> [ 134.563253] __blk_mq_run_hw_queue+0x80/0x90
> [ 134.565540] process_one_work+0x1df/0x420
> [ 134.568041] worker_thread+0x2b/0x3d0
> [ 134.571032] ? process_one_work+0x420/0x420
> [ 134.573964] kthread+0x113/0x130
> [ 134.584370] ? kthread_create_on_node+0x70/0x70
> [ 134.587355] ret_from_fork+0x35/0x40
> [ 134.589796] Code: 39 d0 0f 84 8f 00 00 00 48 8b 97 b0 00 00 00 49 c1 e0 04 45 31 e4 48 8b b7 a8 00 00 00 49 01 d8 48 8d 8f a8 00 00 00 48 89 56 08 <48> 89 32 49 8b 50 18 49 89 48 18 48 89 87 a8 00 00 00 48 89 97
> [ 134.598881] RIP: blk_flush_complete_seq+0x20a/0x300 RSP: ffff88000f803ce8
> [ 134.601812] CR2: 0000000000000000
> [ 134.603728] ---[ end trace fc6d0cdf33d29717 ]---
> [ 134.612349] Kernel panic - not syncing: Fatal exception in interrupt
> [ 134.615630] Kernel Offset: disabled
> [ 134.617712] ---[ end Kernel panic - not syncing: Fatal exception in interrupt
>
> (gdb) list *(blk_flush_complete_seq+0x20a)
> 0xffffffff813056ca is in blk_flush_complete_seq (./include/linux/compiler.h:212).
> 207 {
> 208 switch (size) {
> 209 case 1: *(volatile __u8 *)p = *(__u8 *)res; break;
> 210 case 2: *(volatile __u16 *)p = *(__u16 *)res; break;
> 211 case 4: *(volatile __u32 *)p = *(__u32 *)res; break;
> 212 case 8: *(volatile __u64 *)p = *(__u64 *)res; break;
> 213 default:
> 214 barrier();
> 215 __builtin_memcpy((void *)p, (const void *)res, size);
> 216 barrier();
>
> [ 231.545605] BUG: unable to handle kernel paging request at 0000001000000028
> [ 231.551962] IP: bfq_put_queue+0x10b/0x130
> [ 231.556307] PGD 0 P4D 0
> [ 231.558939] Oops: 0000 [#1] PREEMPT SMP PTI
> [ 231.562149] Modules linked in: nls_iso8859_1 nls_cp437 vfat fat kvm_intel kvm bochs_drm irqbypass ttm iTCO_wdt ppdev drm_kms_helper iTCO_vendor_support psmouse input_leds drm led_class joydev parport_pc mousedev intel_agp syscopyarea parport intel_gtt sysfillrect i2c_i801 evdev sysimgblt agpgart rtc_cmos qemu_fw_cfg mac_hid fb_sys_fops lpc_ich sch_fq_codel ip_tables x_tables xfs dm_thin_pool dm_persistent_data dm_bio_prison dm_bufio libcrc32c crc32c_generic dm_crypt algif_skcipher af_alg dm_mod hid_generic usbhid hid raid10 md_mod sr_mod cdrom sd_mod serio_raw atkbd libps2 uhci_hcd crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel pcbc xhci_pci aesni_intel aes_x86_64 ehci_pci xhci_hcd ehci_hcd ahci crypto_simd glue_helper libahci cryptd usbcore libata usb_common i8042 serio virtio_scsi
> [ 231.608289] scsi_mod virtio_blk virtio_net virtio_pci virtio_ring virtio
> [ 231.613610] CPU: 0 PID: 187 Comm: kworker/0:1H Not tainted 4.15.0-pf2 #1
> [ 231.619675] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
> [ 231.624477] Workqueue: kblockd blk_mq_requeue_work
> [ 231.628532] RIP: 0010:bfq_put_queue+0x10b/0x130
> [ 231.635453] RSP: 0000:ffffc90000377c98 EFLAGS: 00010282
> [ 231.638621] RAX: 0000001000000000 RBX: ffff88000cdf20f0 RCX: 0000000000000000
> [ 231.642332] RDX: 0000000000000000 RSI: ffff88000d4926d8 RDI: ffff88000cdf2120
> [ 231.647000] RBP: 000000000d4926a8 R08: 0000000000000041 R09: ffff88000cdf20f0
> [ 231.652682] R10: 0000000000105a7f R11: 000000000002000b R12: ffff88000cdf2120
> [ 231.657102] R13: ffff88000e152188 R14: 0000000000000041 R15: 0000000000000000
> [ 231.661213] FS: 0000000000000000(0000) GS:ffff88000f800000(0000) knlGS:0000000000000000
> [ 231.664746] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 231.667647] CR2: 0000001000000028 CR3: 0000000004008002 CR4: 00000000001606f0
> [ 231.671475] Call Trace:
> [ 231.673873] bfq_finish_requeue_request+0x54/0x380
> [ 231.676823] __blk_mq_requeue_request+0x5c/0x140
> [ 231.679465] blk_mq_dispatch_rq_list+0x1b4/0x4c0
> [ 231.681798] blk_mq_sched_dispatch_requests+0x105/0x190
> [ 231.685059] __blk_mq_run_hw_queue+0x80/0x90
> [ 231.687750] __blk_mq_delay_run_hw_queue+0x92/0xe0
> [ 231.691510] blk_mq_run_hw_queue+0x25/0x90
> [ 231.694759] blk_mq_run_hw_queues+0x3a/0x50
> [ 231.696706] blk_mq_requeue_work+0x116/0x140
> [ 231.699340] process_one_work+0x1df/0x420
> [ 231.703147] worker_thread+0x2b/0x3d0
> [ 231.705322] ? process_one_work+0x420/0x420
> [ 231.707002] kthread+0x113/0x130
> [ 231.708494] ? kthread_create_on_node+0x70/0x70
> [ 231.710209] ? kthread_create_on_node+0x70/0x70
> [ 231.712754] ret_from_fork+0x35/0x40
> [ 231.715068] Code: c1 e8 06 83 e0 01 48 83 f8 01 45 19 f6 e8 be 3b 00 00 41 83 e6 ee 48 89 c7 41 83 c6 53 e8 8e 3b 00 00 49 89 d9 45 89 f0 44 89 f9 <48> 8b 70 28 48 c7 c2 3a 9a e5 81 55 4c 89 ef e8 11 1c e0 ff 8b
> [ 231.725379] RIP: bfq_put_queue+0x10b/0x130 RSP: ffffc90000377c98
> [ 231.728391] CR2: 0000001000000028
> [ 231.730840] ---[ end trace 03bd81aa0d2b1434 ]---
> [ 231.733269] note: kworker/0:1H[187] exited with preempt_count 1
>
> (gdb) l *(bfq_put_queue+0x10b)
> 0xffffffff81334d1b is in bfq_put_queue (block/bfq-iosched.c:3978).
> 3973 #ifdef CONFIG_BFQ_GROUP_IOSCHED
> 3974 struct bfq_group *bfqg = bfqq_group(bfqq);
> 3975 #endif
> 3976
> 3977 if (bfqq->bfqd)
> 3978 bfq_log_bfqq(bfqq->bfqd, bfqq, "put_queue: %p %d",
> 3979 bfqq, bfqq->ref);
> 3980
> 3981 bfqq->ref--;
> 3982 if (bfqq->ref)
>
> (gdb) l *(bfq_finish_requeue_request+0x54)
> 0xffffffff81335294 is in bfq_finish_requeue_request (block/bfq-iosched.c:4804).
> 4799 * that re-insertions of requeued requests, without
> 4800 * re-preparation, can happen only for pass_through or at_head
> 4801 * requests (which are not re-inserted into bfq internal
> 4802 * queues).
> 4803 */
> 4804 rq->elv.priv[0] = NULL;
> 4805 rq->elv.priv[1] = NULL;
> 4806 }
> 4807
> 4808 /*
>
> [ 322.939697] BUG: unable to handle kernel NULL pointer dereference at 0000000000000008
> [ 322.944283] IP: blk_flush_complete_seq+0x206/0x300
> [ 322.947463] PGD 0 P4D 0
> [ 322.950266] Oops: 0002 [#2] PREEMPT SMP PTI
> [ 322.958898] Modules linked in: kvm_intel bochs_drm nls_iso8859_1 nls_cp437 vfat fat ttm kvm drm_kms_helper drm iTCO_wdt irqbypass psmouse ppdev iTCO_vendor_support input_leds led_class i2c_i801 intel_agp parport_pc intel_gtt joydev lpc_ich rtc_cmos agpgart evdev parport syscopyarea mousedev qemu_fw_cfg sysfillrect mac_hid sysimgblt fb_sys_fops sch_fq_codel ip_tables x_tables xfs dm_thin_pool dm_persistent_data dm_bio_prison dm_bufio libcrc32c crc32c_generic dm_crypt algif_skcipher af_alg dm_mod hid_generic usbhid hid crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel raid10 pcbc md_mod sr_mod cdrom sd_mod serio_raw atkbd libps2 uhci_hcd xhci_pci xhci_hcd ahci ehci_pci libahci aesni_intel aes_x86_64 crypto_simd glue_helper ehci_hcd cryptd libata usbcore usb_common i8042 serio virtio_scsi
> [ 323.001668] scsi_mod virtio_blk virtio_net virtio_pci virtio_ring virtio
> [ 323.006121] CPU: 0 PID: 215 Comm: kworker/u5:1 Tainted: G D 4.15.0-pf2 #1
> [ 323.010263] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015
> [ 323.021225] Workqueue: kcryptd kcryptd_crypt [dm_crypt]
> [ 323.024947] RIP: 0010:blk_flush_complete_seq+0x206/0x300
> [ 323.028405] RSP: 0018:ffff88000f803ed0 EFLAGS: 00010086
> [ 323.032491] RAX: ffff88000cfe78b0 RBX: ffff88000cfe78a0 RCX: ffff88000d4d85a8
> [ 323.036262] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff88000d4d8500
> [ 323.041032] RBP: ffff88000d6510a0 R08: ffff88000cfe78a0 R09: 0000000000000000
> [ 323.051518] R10: ffff88000dab4d00 R11: ffffffffc01aafb0 R12: 0000000000000000
> [ 323.055818] R13: ffff88000cfe78f0 R14: 0000000000000046 R15: ffff88000cfe78a0
> [ 323.060965] FS: 0000000000000000(0000) GS:ffff88000f800000(0000) knlGS:0000000000000000
> [ 323.065902] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 323.070571] CR2: 0000000000000008 CR3: 0000000004008001 CR4: 00000000001606f0
> [ 323.076591] Call Trace:
> [ 323.081685] <IRQ>
> [ 323.084025] mq_flush_data_end_io+0xb3/0xf0
> [ 323.087155] scsi_end_request+0x90/0x1e0 [scsi_mod]
> [ 323.095768] scsi_io_completion+0x237/0x650 [scsi_mod]
> [ 323.099928] flush_smp_call_function_queue+0x7c/0xf0
> [ 323.104028] smp_call_function_single_interrupt+0x32/0xf0
> [ 323.114170] call_function_single_interrupt+0xa2/0xb0
> [ 323.118208] </IRQ>
> [ 323.121040] RIP: 0010:_aesni_enc4+0x178/0x190 [aesni_intel]
> [ 323.124658] RSP: 0018:ffffc900004a7c40 EFLAGS: 00000293 ORIG_RAX: ffffffffffffff04
> [ 323.128777] RAX: ffffffffc01ab208 RBX: 0000000000000180 RCX: 0000000000000000
> [ 323.133003] RDX: ffff88000daf9c80 RSI: ffff88000a2b3c80 RDI: ffff88000cd24260
> [ 323.139211] RBP: ffffc900004a7d40 R08: ffff8800089f7718 R09: 0000000000000010
> [ 323.146930] R10: ffff88000cd24290 R11: ffffffffc01aafb0 R12: 0000000000000080
> [ 323.151758] R13: ffffffffc01c90c8 R14: ffff88000a2b3d00 R15: ffff88000daf9d00
> [ 323.156507] ? _aesni_enc1+0xac/0xac [aesni_intel]
> [ 323.160419] ? _aesni_dec1+0xac/0xac [aesni_intel]
> [ 323.164204] ? aesni_xts_crypt8+0x21e/0x260 [aesni_intel]
> [ 323.167322] ? glue_xts_req_128bit+0x125/0x1d0 [glue_helper]
> [ 323.178383] ? crypt_convert+0x961/0xef0 [dm_crypt]
> [ 323.182089] ? xts_decrypt+0x40/0x40 [aesni_intel]
> [ 323.185825] ? crypt_convert+0x961/0xef0 [dm_crypt]
> [ 323.189438] ? bio_alloc_bioset+0x132/0x1e0
> [ 323.191926] ? kcryptd_crypt+0x1ff/0x360 [dm_crypt]
> [ 323.194998] ? process_one_work+0x1df/0x420
> [ 323.197475] ? worker_thread+0x2b/0x3d0
> [ 323.206991] ? process_one_work+0x420/0x420
> [ 323.210387] ? kthread+0x113/0x130
> [ 323.213396] ? kthread_create_on_node+0x70/0x70
> [ 323.216751] ? ret_from_fork+0x35/0x40
> [ 323.220815] Code: 48 8b 10 48 39 d0 0f 84 8f 00 00 00 48 8b 97 b0 00 00 00 49 c1 e0 04 45 31 e4 48 8b b7 a8 00 00 00 49 01 d8 48 8d 8f a8 00 00 00 <48> 89 56 08 48 89 32 49 8b 50 18 49 89 48 18 48 89 87 a8 00 00
> [ 323.233543] RIP: blk_flush_complete_seq+0x206/0x300 RSP: ffff88000f803ed0
> [ 323.238885] CR2: 0000000000000008
> [ 323.241673] ---[ end trace 2ec7b63c3a4a4a02 ]---
> [ 323.245006] Kernel panic - not syncing: Fatal exception in interrupt
> [ 323.248858] Kernel Offset: disabled
> [ 323.250753] ---[ end Kernel panic - not syncing: Fatal exception in interrupt
>
> (gdb) l *(blk_flush_complete_seq+0x206)
> 0xffffffff813056c6 is in blk_flush_complete_seq (./include/linux/list.h:105).
> 100 * This is only for internal list manipulation where we know
> 101 * the prev/next entries already!
> 102 */
> 103 static inline void __list_del(struct list_head * prev, struct list_head * next)
> 104 {
> 105 next->prev = prev;
> 106 WRITE_ONCE(prev->next, next);
> 107 }
> 108
> 109 /**
Thank you very much Oleksandr, and Holger, for your listings,
I've managed to make a crash happen, unfortunately only after a lot of
time and I/O. Unfortunately, the crash happened for one of the call
chains not including bfq. If you guys have found a way to get these
crashes more or less easily, then I think I'll need your help here.
The first piece of information I need is whether this failure happens
even without "BFQ hierarchical scheduling support". If it does, then
the area of investigation narrows a little. So, could you please
retry after disabling hierarchical support?
Thanks,
Paolo
On Wed, 2018-02-07 at 10:08 +0100, Paolo Valente wrote:
>
> The first piece of information I need is whether this failure happens
> even without "BFQ hierarchical scheduling support".
I presume you mean BFQ_GROUP_IOSCHED, which I do not have enabled.
-Mike?
On Wed, 2018-02-07 at 10:45 +0100, Paolo Valente wrote:
>
> > Il giorno 07 feb 2018, alle ore 10:23, Mike Galbraith <[email protected]> ha scritto:
> >
> > On Wed, 2018-02-07 at 10:08 +0100, Paolo Valente wrote:
> >>
> >> The first piece of information I need is whether this failure happens
> >> even without "BFQ hierarchical scheduling support".
> >
> > I presume you mean BFQ_GROUP_IOSCHED, which I do not have enabled.
> >
>
> Great (so to speak), this saves us one step.
>
> So, here's my next request for help: please apply the attached patch
> (compressed to preserve it from my email client) and retry. It adds
> several anomaly checks. I hope I have not added any false-positive
> check.
kernel BUG at block/bfq-iosched.c:4742!
4742 BUG_ON(!(rq->rq_flags & RQF_ELVPRIV));
> Il giorno 07 feb 2018, alle ore 11:15, Mike Galbraith <[email protected]> ha scritto:
>
> On Wed, 2018-02-07 at 10:45 +0100, Paolo Valente wrote:
>>
>>> Il giorno 07 feb 2018, alle ore 10:23, Mike Galbraith <[email protected]> ha scritto:
>>>
>>> On Wed, 2018-02-07 at 10:08 +0100, Paolo Valente wrote:
>>>>
>>>> The first piece of information I need is whether this failure happens
>>>> even without "BFQ hierarchical scheduling support".
>>>
>>> I presume you mean BFQ_GROUP_IOSCHED, which I do not have enabled.
>>>
>>
>> Great (so to speak), this saves us one step.
>>
>> So, here's my next request for help: please apply the attached patch
>> (compressed to preserve it from my email client) and retry. It adds
>> several anomaly checks. I hope I have not added any false-positive
>> check.
>
> kernel BUG at block/bfq-iosched.c:4742!
>
> 4742 BUG_ON(!(rq->rq_flags & RQF_ELVPRIV));
Oh my, this is as crazy as, fortunately, easy to fix. The problem is
that this is easy to fix in bfq, but increases the doubts I have
expressed in my cover letter: is it ok that, in blk-mq, the functions
of an elevator may get invoked, without control, on requests that do
not belong to that elevator?
Anyway, two requests, Mike, if you haven't had enough already:
1. Could you paste a stack trace for this OOPS, just to understand how we
get there?
2. Could you please turn that BUG_ON into:
if (!(rq->rq_flags & RQF_ELVPRIV))
return;
and see what happens?
Thanks a lot,
Paolo
On Wed, 2018-02-07 at 11:27 +0100, Paolo Valente wrote:
>
> 1. Could you paste a stack trace for this OOPS, just to understand how we
> get there?
[ 442.421058] kernel BUG at block/bfq-iosched.c:4742!
[ 442.421762] invalid opcode: 0000 [#1] SMP PTI
[ 442.422436] Dumping ftrace buffer:
[ 442.423116] (ftrace buffer empty)
[ 442.423785] Modules linked in: fuse(E) ebtable_filter(E) ebtables(E) af_packet(E) bridge(E) stp(E) llc(E) iscsi_ibft(E) iscsi_boot_sysfs(E) nf_conntrack_ipv6(E) nf_defrag_ipv6(E) ipt_REJECT(E) xt_tcpudp(E) iptable_filter(E) ip6table_>
[ 442.426685] pcbc(E) iTCO_wdt(E) aesni_intel(E) aes_x86_64(E) iTCO_vendor_support(E) crypto_simd(E) glue_helper(E) mei_me(E) i2c_i801(E) r8169(E) cryptd(E) lpc_ich(E) mfd_core(E) mii(E) mei(E) soundcore(E) pcspkr(E) shpchp(E) thermal>
[ 442.429634] dm_multipath(E) dm_mod(E) scsi_dh_rdac(E) scsi_dh_emc(E) scsi_dh_alua(E) scsi_mod(E) efivarfs(E) autofs4(E)
[ 442.430166] CPU: 2 PID: 489 Comm: kworker/2:1H Tainted: G E 4.15.0.ga2e5790-master #612
[ 442.430675] Hardware name: MEDION MS-7848/MS-7848, BIOS M7848W08.20C 09/23/2013
[ 442.431195] Workqueue: kblockd blk_mq_requeue_work
[ 442.431706] RIP: 0010:bfq_only_requeue_request+0xd1/0xe0
[ 442.432221] RSP: 0018:ffff8803f7b8fcc0 EFLAGS: 00010246
[ 442.432733] RAX: 0000000000002090 RBX: ffff8803dbda2580 RCX: 0000000000000000
[ 442.433250] RDX: ffff8803fa3c8000 RSI: 0000000000000004 RDI: ffff8803dbda2580
[ 442.433778] RBP: ffff8803f9ec85d0 R08: ffff8803fa3c81c0 R09: 0000000000000000
[ 442.434296] R10: ffff8803fa3c81d0 R11: 0000000000001000 R12: ffff8803dbda2600
[ 442.434815] R13: 000000000000000d R14: 0000000000000000 R15: ffff8803f7b8fd88
[ 442.435334] FS: 0000000000000000(0000) GS:ffff88041ec80000(0000) knlGS:0000000000000000
[ 442.435863] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 442.436381] CR2: 00007f00e001e198 CR3: 0000000001e0a002 CR4: 00000000001606e0
[ 442.436909] Call Trace:
[ 442.437445] __blk_mq_requeue_request+0x8f/0x120
[ 442.437980] blk_mq_dispatch_rq_list+0x342/0x550
[ 442.438506] ? kyber_dispatch_request+0xd0/0xd0
[ 442.439041] blk_mq_sched_dispatch_requests+0xf7/0x180
[ 442.439568] __blk_mq_run_hw_queue+0x58/0xd0
[ 442.440103] __blk_mq_delay_run_hw_queue+0x99/0xa0
[ 442.440628] blk_mq_run_hw_queue+0x54/0xf0
[ 442.441157] blk_mq_run_hw_queues+0x4b/0x60
[ 442.441822] blk_mq_requeue_work+0x13a/0x150
[ 442.442518] process_one_work+0x147/0x350
[ 442.443205] worker_thread+0x47/0x3e0
[ 442.443887] kthread+0xf8/0x130
[ 442.444579] ? rescuer_thread+0x360/0x360
[ 442.445264] ? kthread_stop+0x120/0x120
[ 442.445965] ? do_syscall_64+0x75/0x1a0
[ 442.446651] ? SyS_exit_group+0x10/0x10
[ 442.447340] ret_from_fork+0x35/0x40
[ 442.448023] Code: ff 4c 89 f6 4c 89 ef e8 be ec 2e 00 48 c7 83 80 00 00 00 00 00 00 00 48 c7 83 88 00 00 00 00 00 00 00 5b 5d 41 5c 41 5d 41 5e c3 <0f> 0b 0f 0b 0f 0b 0f 0b 0f 1f 80 00 00 00 00 0f 1f 44 00 00 41
[ 442.448668] RIP: bfq_only_requeue_request+0xd1/0xe0 RSP: ffff8803f7b8fcc0
On Wed, 2018-02-07 at 11:27 +0100, Paolo Valente wrote:
>
> 2. Could you please turn that BUG_ON into:
> if (!(rq->rq_flags & RQF_ELVPRIV))
> return;
> and see what happens?
That seems to make it forgets how to make boom.
-Mike
> Il giorno 07 feb 2018, alle ore 12:03, Mike Galbraith <[email protected]> ha scritto:
>
> On Wed, 2018-02-07 at 11:27 +0100, Paolo Valente wrote:
>>
>> 2. Could you please turn that BUG_ON into:
>> if (!(rq->rq_flags & RQF_ELVPRIV))
>> return;
>> and see what happens?
>
> That seems to make it forgets how to make boom.
>
Great! This deserves to be celebrated with a packet of Ikea chips.
Just to be certain, before submitting a new patch: you changed *only*
the BUG_ON at line 4742, on top of my instrumentation patch.
Thanks,
Paolo
> -Mike
On Wed, 2018-02-07 at 12:12 +0100, Paolo Valente wrote:
> Just to be certain, before submitting a new patch: you changed *only*
> the BUG_ON at line 4742, on top of my instrumentation patch.
Nah, I completely rewrite it with only a little help from an ouija
board to compensate for missing (all) knowledge wrt BFQ internals.
(iow yeah, I did exactly and only what I was asked to do:)
> Thanks a lot,
> Paolo
Hi.
07.02.2018 12:27, Paolo Valente wrote:
> Hi Oleksandr, Holger,
> before I prepare a V2 candidate patch, could you please test my
> instrumentation patch too, with the above change made. For your
> convenience, I have attached a compressed archive with both the
> instrumentation patch and a patch making the above change.
>
> Crossing my fingers,
> Paolo
With all three patches applied I cannot reproduce neither cfdisk hang
nor some kind of boom.
Thank you.
Oleksandr
> Il giorno 07 feb 2018, alle ore 16:50, Oleksandr Natalenko <[email protected]> ha scritto:
>
> Hi.
>
> 07.02.2018 12:27, Paolo Valente wrote:
>> Hi Oleksandr, Holger,
>> before I prepare a V2 candidate patch, could you please test my
>> instrumentation patch too, with the above change made. For your
>> convenience, I have attached a compressed archive with both the
>> instrumentation patch and a patch making the above change.
>> Crossing my fingers,
>> Paolo
>
> With all three patches applied I cannot reproduce neither cfdisk hang nor some kind of boom.
>
> Thank you.
>
Thank you, Oleksandr. I'm now ready to prepare a new version of this patch.
Paolo
> Oleksandr