From owner-freebsd-scsi@freebsd.org Thu Jun 29 13:36:50 2017 Return-Path: Delivered-To: freebsd-scsi@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 3896DD9DA79; Thu, 29 Jun 2017 13:36:50 +0000 (UTC) (envelope-from ben.rubson@gmail.com) Received: from mail-wr0-x22c.google.com (mail-wr0-x22c.google.com [IPv6:2a00:1450:400c:c0c::22c]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (Client CN "smtp.gmail.com", Issuer "Google Internet Authority G2" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id BF9A784B72; Thu, 29 Jun 2017 13:36:49 +0000 (UTC) (envelope-from ben.rubson@gmail.com) Received: by mail-wr0-x22c.google.com with SMTP id 77so189723290wrb.1; Thu, 29 Jun 2017 06:36:49 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:subject:from:in-reply-to:date :content-transfer-encoding:message-id:references:to; bh=+McbihPIfeGbcGMjhpqCdlCVmu56lMnabX+qRvak6gA=; b=pyYZmvTpY7dmtUS9n4ncGm6giAdNt48yKoIuLdiMbqS6reZvnpNjrEmBgXdzMp46eG tPawmK6TDvaeZ8887eHzCP6AgWUAj5E1Rvi1uIhgYlYHYRGRw1a8SU3mi7JsR/JSnMn8 Gqs0I8hwFmIsVsl4bpz5AmSfz8f1Hh+uuLnTstu3yYqCJIzMvMVTSqd17h80/2GfNQgR LK9clCpjH9WnBERnPbF9FbcK8a9+RC29Bkb1T33pu+MysWu6WJkicg8Alh0hVymtuQJO dkIZXO3e/3HqSuAUBXNlwMYqenGboShzSVl+pd/US4yp8EgvTXYK/LUlO5V2EeVRpO3S Ej5g== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:subject:from:in-reply-to:date :content-transfer-encoding:message-id:references:to; bh=+McbihPIfeGbcGMjhpqCdlCVmu56lMnabX+qRvak6gA=; b=p5cxOjMt8eu7VVlvPrZg0D68pU6/4D9bgT0bmNeRI9EtJP/jbM0kT5OvmDXi1t9jBg 4kRxtRy/mZNAQRMN/K5AZnxOJHHJ8kT/3Xz0niDoHPq7pvRsibYXBEWehGmXBjpVoLBl OgvP3lgn4rIiSfbyzP6MQ7PcuwC5r8goPoMvmvQXX3Jh/Z54hgiwsykhXKRdNFbUlA/M JePcyyAO2suGmOknG9KggmNf101+oIpT66q71tcWi8SDgBtGQsAaNRRyADj/bNhtczRn iKLQnx85+ZtQBtOk+CQO8NOdYnTdDwnLE1i80qip//uGZ48nlLB9svSN4xjlUYiOxDp7 V1jQ== X-Gm-Message-State: AKS2vOwYt7y/W6mDHhXHsk8cDaAfAwiYbeGjqzwR5W2yxR2wPlpaRRLx 4nl9NJgd/q7+ynWQe/8= X-Received: by 10.223.143.10 with SMTP id p10mr21583804wrb.120.1498743407648; Thu, 29 Jun 2017 06:36:47 -0700 (PDT) Received: from ben.home (LFbn-1-11339-180.w2-15.abo.wanadoo.fr. [2.15.165.180]) by smtp.gmail.com with ESMTPSA id b197sm1498890wmb.4.2017.06.29.06.36.46 (version=TLS1 cipher=ECDHE-RSA-AES128-SHA bits=128/128); Thu, 29 Jun 2017 06:36:47 -0700 (PDT) Content-Type: text/plain; charset=us-ascii Mime-Version: 1.0 (Mac OS X Mail 9.3 \(3124\)) Subject: Re: I/O to pool appears to be hung, panic ! From: Ben RUBSON In-Reply-To: <20170629144334.1e283570@fabiankeil.de> Date: Thu, 29 Jun 2017 15:36:45 +0200 Content-Transfer-Encoding: quoted-printable Message-Id: References: <20170629144334.1e283570@fabiankeil.de> To: Freebsd fs , freebsd-scsi@freebsd.org X-Mailer: Apple Mail (2.3124) X-BeenThere: freebsd-scsi@freebsd.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: SCSI subsystem List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 29 Jun 2017 13:36:50 -0000 > On 29 Jun 2017, at 14:43, Fabian Keil = wrote: Thank you for your feedback Fabian. > Ben RUBSON wrote: >=20 >> One of my servers did a kernel panic last night, giving the following = message : >> panic: I/O to pool 'home' appears to be hung on vdev guid 122... at = '/dev/label/G23iscsi'. > [...]=20 >> Here are some numbers regarding this disk, taken from the server = hosting the pool : >> (unfortunately not from the iscsi target server) >> https://s23.postimg.org/zd8jy9xaj/busydisk.png >>=20 >> We clearly see that suddendly, disk became 100% busy, meanwhile CPU = was almost idle. >>=20 >> No error message at all on both servers. > [...] >> The only log I have is the following stacktrace taken from the server = console : >> panic: I/O to pool 'home' appears to be hung on vdev guid 122... at = '/dev/label/G23iscsi'. >> cpuid =3D 0 >> KDB: stack backtrace: >> #0 0xffffffff80b240f7 at kdb_backtrace+0x67 >> #1 0xffffffff80ad9462 at vpanic+0x182 >> #2 0xffffffff80ad92d3 at panic+0x43 >> #3 0xffffffff82238fa7 at vdev_deadman+0x127 >> #4 0xffffffff82238ec0 at vdev_deadman+0x40 >> #5 0xffffffff82238ec0 at vdev_deadman+0x40 >> #6 0xffffffff8222d0a6 at spa_deadman+0x86 >> #7 0xffffffff80af32da at softclock_call_cc+0x18a >> #8 0xffffffff80af3854 at softclock+0x94 >> #9 0xffffffff80a9348f at intr_event_execute_handlers+0x20f >> #10 0xffffffff80a936f6 at ithread_loop+0xc6 >> #11 0xffffffff80a900d5 at fork_exit+0x85 >> #12 0xffffffff80f846fe at fork_trampoline+0xe >> Uptime: 92d2h47m6s >>=20 >> I would have been pleased to make a dump available. >> However, despite my (correct ?) configuration, server did not dump : >> (nevertheless, "sysctl debug.kdb.panic=3D1" make it to dump) >> # grep ^dump /boot/loader.conf /etc/rc.conf >> /boot/loader.conf:dumpdev=3D"/dev/mirror/swap" >> /etc/rc.conf:dumpdev=3D"AUTO" >=20 > You may want to look at the NOTES section in gmirror(8). Yes, I should already be OK (prefer algorithm set). >> I use default kernel, with a rebuilt zfs module : >> # uname -v >> FreeBSD 11.0-RELEASE-p8 #0: Wed Feb 22 06:12:04 UTC 2017 = root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC=20 >>=20 >> I use the following iSCSI configuration, which disconnects the disks = "as soon as" they are unavailable : >> kern.iscsi.ping_timeout=3D5 >> kern.iscsi.fail_on_disconnection=3D1 >> kern.iscsi.iscsid_timeout=3D5 >>=20 >> I then think disk was at least correctly reachable during these 20 = busy minutes. >>=20 >> So, any idea why I could have faced this issue ? >=20 > Is it possible that the system was under memory pressure? No I don't think it was : https://s1.postimg.org/uvsebpyyn/busydisk2.png More than 2GB of available memory. Swap not used (624kB). ARC behaviour seems correct (anon increases because ZFS can't actually = write I think). Regarding the pool itself, it was receiving data at 6MB/s, sending = around 30kB blocks to disks. When disk went busy, throughput fell to some kB, with 128kB blocks. > geli's use of malloc() is known to cause deadlocks under memory = pressure: > https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D209759 >=20 > Given that gmirror uses malloc() as well it probably has the same = issue. I don't use geli so I should not face this issue. >> I would have thought ZFS would have taken the busy device offline, = instead of raising a panic. >> Perhaps it is already possible to make ZFS behave like this ? >=20 > There's a tunable for this: vfs.zfs.deadman_enabled. > If the panic is just a symptom of the deadlock it's unlikely > to help though. I think this tunable should have prevented the server from having raised = a panic : # sysctl -d vfs.zfs.deadman_enabled vfs.zfs.deadman_enabled: Kernel panic on stalled ZFS I/O # sysctl vfs.zfs.deadman_enabled vfs.zfs.deadman_enabled: 1 But not sure how it would have behaved then... (busy disk miraculously back to normal status, memory pressure due to = anon increasing...) I also tried to look for some LSI SAS2008 error counters (on target = side), but did not found anything interesting. (sysctl -a | grep -i mps) Thank you again, Ben