Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 6 Nov 2014 09:20:38 +0100 (CET)
From:      =?ISO-8859-1?Q?Trond_Endrest=F8l?= <Trond.Endrestol@fagskolen.gjovik.no>
To:        Kai Gallasch <k@free.de>
Cc:        freebsd-stable@freebsd.org
Subject:   Re: 10.1 RC4 r273903 - zpool scrub on ssd mirror - ahci command timeout
Message-ID:  <alpine.BSF.2.11.1411060905290.1380@mail.fig.ol.no>
In-Reply-To: <20141106003240.344dedf6@orwell>
References:  <20141106003240.344dedf6@orwell>

next in thread | previous in thread | raw e-mail | index | archive | help
On Thu, 6 Nov 2014 00:32+0100, Kai Gallasch wrote:

> 
> Hi.
> 
> Not sure if this is 10.1 related or more a problem of the ssd
> model and/or ahci controller..
> 
> I am currently running 10.1 RC4 r273903 on a zfs on root server with two
> mirror pools. One of the pools is a mirror consisting of two Samsung
> SSD 850 PRO 512GB SSDs.
> 
> When I start a zfs scrub on this pool the result of the scrub is:
> 
> # zpool status -v ssdpool
>   pool: ssdpool
>  state: ONLINE
> status: One or more devices has experienced an unrecoverable error.  An
> 	attempt was made to correct the error.  Applications are
> unaffected. action: Determine if the device needs to be replaced, and
> clear the errors using 'zpool clear' or replace the device with 'zpool
> replace'. see: http://illumos.org/msg/ZFS-8000-9P
>   scan: scrub repaired 73K in 0h8m with 0 errors on Thu Nov  6 00:00:16
> 2014 config:
> 
> 	NAME              STATE     READ WRITE CKSUM
> 	ssdpool           ONLINE       0     0     0
> 	  mirror-0        ONLINE       0     0     0
> 	    gpt/ssdpool0  ONLINE       0     0    17
> 	    gpt/ssdpool1  ONLINE       0     0    29
> 
> When I do a 'zpool clear' the pool status looks ok again. But when I
> again start a zpool scrub the same thing happens again and the
> above status "One or more devices has experienced an unrecoverable
> error" shows again.
> 
> 
> I find the following kernel message in the output of 'dmesg': (after
> running zpool scrub two times)
> 
> 
> ahcich2: Timeout on slot 15 port 0
> ahcich2: is 00000000 cs 000f0000 ss 000f8000 rs 000f8000 tfd 40 serr
> 00000000 cmd 0024cf17 (ada2:ahcich2:0:0:0): READ_FPDMA_QUEUED. ACB: 60
> 8b a6 1d 56 40 0d 00 00 00 00 00 (ada2:ahcich2:0:0:0): CAM status:
> Command timeout (ada2:ahcich2:0:0:0): Retrying command
> ahcich2: Timeout on slot 23 port 0
> ahcich2: is 00000000 cs 0f000000 ss 0f800000 rs 0f800000 tfd 40 serr
> 00000000 cmd 0024d817 (ada2:ahcich2:0:0:0): READ_FPDMA_QUEUED. ACB: 60
> 1b 23 81 bc 40 06 00 00 00 00 00 (ada2:ahcich2:0:0:0): CAM status:
> Command timeout (ada2:ahcich2:0:0:0): Retrying command
> ahcich2: Timeout on slot 3 port 0
> ahcich2: is 00000000 cs 00000030 ss 00000038 rs 00000038 tfd 40 serr
> 00000000 cmd 0024c317 (ada2:ahcich2:0:0:0): READ_FPDMA_QUEUED. ACB: 60
> 26 bd 18 8e 40 12 00 00 00 00 00 (ada2:ahcich2:0:0:0): CAM status:
> Command timeout (ada2:ahcich2:0:0:0): Retrying command

Incidently, I've recently seen similar messages in my base/head VMs 
running in VirtualBox on a Win7Pro host at home.

These messages appeared after I upgraded VBox to 4.3.18 on both host 
and guests, and after upgrading base/head to roughly r273963, last 
Sunday.

I haven't touched my base/head VMs since Sunday, but I may find time 
to investigate both base/head and base/stable/10 later this evening, 
and see if they all exhibit the same symptoms as yours.

All my FreeBSD VMs uses VirtualBox' SATA controller, except stable/8 
which only works correctly with VirtualBox' SCSI controller.

> Besides: smartctl shows no error on ada2.
> Here comes the output..
> 
> # smartctl -a -q noserial /dev/ada2
> smartctl 6.3 2014-07-26 r3976 [FreeBSD 10.1-RC4 amd64] (local build)
> Copyright (C) 2002-14, Bruce Allen, Christian Franke,
> www.smartmontools.org
> 
> === START OF INFORMATION SECTION ===
> Device Model:     Samsung SSD 850 PRO 512GB
> Firmware Version: EXM01B6Q
> User Capacity:    512,110,190,592 bytes [512 GB]
> Sector Size:      512 bytes logical/physical
> Rotation Rate:    Solid State Device
> Device is:        Not in smartctl database [for details use: -P showall]
> ATA Version is:   ACS-2, ATA8-ACS T13/1699-D revision 4c
> SATA Version is:  SATA 3.1, 6.0 Gb/s (current: 3.0 Gb/s)
> Local Time is:    Thu Nov  6 00:02:04 2014 CET
> SMART support is: Available - device has SMART capability.
> SMART support is: Enabled
> 
> === START OF READ SMART DATA SECTION ===
> SMART overall-health self-assessment test result: PASSED
> 
> General SMART Values:
> Offline data collection status:  (0x00)	Offline data collection
> activity was never started.
> 					Auto Offline Data Collection:
> Disabled. Self-test execution status:      (   0)	The previous
> self-test routine completed without error or no self-test has ever 
> 					been run.
> Total time to complete Offline 
> data collection: 		(    0) seconds.
> Offline data collection
> capabilities: 			 (0x53) SMART execute Offline
> immediate. Auto Offline data collection on/off support.
> 					Suspend Offline collection upon
> new command.
> 					No Offline surface scan
> supported. Self-test supported.
> 					No Conveyance Self-test
> supported. Selective Self-test supported.
> SMART capabilities:            (0x0003)	Saves SMART data before
> entering power-saving mode.
> 					Supports SMART auto save timer.
> Error logging capability:        (0x01)	Error logging supported.
> 					General Purpose Logging
> supported. Short self-test routine 
> recommended polling time: 	 (   2) minutes.
> Extended self-test routine
> recommended polling time: 	 (  33) minutes.
> SCT capabilities: 	       (0x003d)	SCT Status supported.
> 					SCT Error Recovery Control
> supported. SCT Feature Control supported.
> 					SCT Data Table supported.
> 
> SMART Attributes Data Structure revision number: 1
> Vendor Specific SMART Attributes with Thresholds:
> ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE
> UPDATED  WHEN_FAILED RAW_VALUE 5 Reallocated_Sector_Ct   0x0033   100
> 100   010    Pre-fail  Always       -       0 9 Power_On_Hours
> 0x0032   099   099   000    Old_age   Always       -       154 12
> Power_Cycle_Count       0x0032   099   099   000    Old_age
> Always       -       5 177 Wear_Leveling_Count     0x0013   100   100
> 000    Pre-fail  Always       -       0 179 Used_Rsvd_Blk_Cnt_Tot
> 0x0013   100   100   010    Pre-fail  Always       -       0 181
> Program_Fail_Cnt_Total  0x0032   100   100   010    Old_age
> Always       -       0 182 Erase_Fail_Count_Total  0x0032   100   100
> 010    Old_age   Always       -       0 183 Runtime_Bad_Block
> 0x0013   100   100   010    Pre-fail  Always       -       0 187
> Reported_Uncorrect      0x0032   100   100   000    Old_age
> Always       -       0 190 Airflow_Temperature_Cel 0x0032   070   068
> 000    Old_age   Always       -       30 195 Hardware_ECC_Recovered
> 0x001a   200   200   000    Old_age   Always       -       0 199
> UDMA_CRC_Error_Count    0x003e   100   100   000    Old_age
> Always       -       0 235 Unknown_Attribute       0x0012   100   100
> 000    Old_age   Always       -       0 241 Total_LBAs_Written
> 0x0032   099   099   000    Old_age   Always       -       400466433
> 
> SMART Error Log Version: 1
> No Errors Logged
> 
> SMART Self-test log structure revision number 1
> Num  Test_Description    Status                  Remaining
> LifeTime(hours)  LBA_of_first_error # 1  Extended offline    Completed
> without error       00%       147         -
> 
> SMART Selective self-test log data structure revision number 1
>  SPAN  MIN_LBA  MAX_LBA  CURRENT_TEST_STATUS
>     1        0        0  Not_testing
>     2        0        0  Not_testing
>     3        0        0  Not_testing
>     4        0        0  Not_testing
>     5        0        0  Not_testing
> Selective self-test flags (0x0):
>   After scanning selected spans, do NOT read-scan remainder of disk.
> If Selective self-test is pending on power-up, resume after 0 minute
> delay.
> 
> I wonder What is the possible reason for this. Both SSDs are new.
> Is this a common problem with zfs and SSDs (for example ahci timeouts
> because of high data rates for a bus ?)
> 
> K.

-- 
+-------------------------------+------------------------------------+
| Vennlig hilsen,               | Best regards,                      |
| Trond Endrestøl,              | Trond Endrestøl,                   |
| IT-ansvarlig,                 | System administrator,              |
| Fagskolen Innlandet,          | Gjøvik Technical College, Norway,  |
| tlf. mob.   952 62 567,       | Cellular...: +47 952 62 567,       |
| sentralbord 61 14 54 00.      | Switchboard: +47 61 14 54 00.      |
+-------------------------------+------------------------------------+
From owner-freebsd-stable@FreeBSD.ORG  Thu Nov  6 08:31:59 2014
Return-Path: <owner-freebsd-stable@FreeBSD.ORG>
Delivered-To: freebsd-stable@freebsd.org
Received: from mx1.freebsd.org (mx1.freebsd.org
 [IPv6:2001:1900:2254:206a::19:1])
 (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits))
 (No client certificate requested)
 by hub.freebsd.org (Postfix) with ESMTPS id 874DB385;
 Thu,  6 Nov 2014 08:31:59 +0000 (UTC)
Received: from kib.kiev.ua (kib.kiev.ua [IPv6:2001:470:d5e7:1::1])
 (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits))
 (Client did not present a certificate)
 by mx1.freebsd.org (Postfix) with ESMTPS id EE02B9A1;
 Thu,  6 Nov 2014 08:31:58 +0000 (UTC)
Received: from tom.home (kostik@localhost [127.0.0.1])
 by kib.kiev.ua (8.14.9/8.14.9) with ESMTP id sA68VrFh035017
 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NO);
 Thu, 6 Nov 2014 10:31:53 +0200 (EET)
 (envelope-from kostikbel@gmail.com)
DKIM-Filter: OpenDKIM Filter v2.9.2 kib.kiev.ua sA68VrFh035017
Received: (from kostik@localhost)
 by tom.home (8.14.9/8.14.9/Submit) id sA68VrPu035016;
 Thu, 6 Nov 2014 10:31:53 +0200 (EET)
 (envelope-from kostikbel@gmail.com)
X-Authentication-Warning: tom.home: kostik set sender to kostikbel@gmail.com
 using -f
Date: Thu, 6 Nov 2014 10:31:53 +0200
From: Konstantin Belousov <kostikbel@gmail.com>
To: Matthew Seaman <matthew@FreeBSD.org>
Subject: Re: Varnish proxy goes catatonic under heavy load
Message-ID: <20141106083153.GK53947@kib.kiev.ua>
References: <545A0EB4.4090404@freebsd.org> <545A117B.4080606@multiplay.co.uk>
 <545B1F2A.5010203@FreeBSD.org>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <545B1F2A.5010203@FreeBSD.org>
User-Agent: Mutt/1.5.23 (2014-03-12)
X-Spam-Status: No, score=-2.0 required=5.0 tests=ALL_TRUSTED,BAYES_00,
 DKIM_ADSP_CUSTOM_MED,FREEMAIL_FROM,NML_ADSP_CUSTOM_MED autolearn=no
 autolearn_force=no version=3.4.0
X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on tom.home
Cc: freebsd-stable@freebsd.org, Steven Hartland <killing@multiplay.co.uk>
X-BeenThere: freebsd-stable@freebsd.org
X-Mailman-Version: 2.1.18-1
Precedence: list
List-Id: Production branch of FreeBSD source code <freebsd-stable.freebsd.org>
List-Unsubscribe: <http://lists.freebsd.org/mailman/options/freebsd-stable>,
 <mailto:freebsd-stable-request@freebsd.org?subject=unsubscribe>
List-Archive: <http://lists.freebsd.org/pipermail/freebsd-stable/>;
List-Post: <mailto:freebsd-stable@freebsd.org>
List-Help: <mailto:freebsd-stable-request@freebsd.org?subject=help>
List-Subscribe: <http://lists.freebsd.org/mailman/listinfo/freebsd-stable>,
 <mailto:freebsd-stable-request@freebsd.org?subject=subscribe>
X-List-Received-Date: Thu, 06 Nov 2014 08:31:59 -0000

On Thu, Nov 06, 2014 at 07:11:38AM +0000, Matthew Seaman wrote:
> On 05/11/2014 12:00, Steven Hartland wrote:
> > As a guess you exhausted all mbufs, 10 has much better defaults for
> > these so I'd recommend updating.
> > 
> > If you can get in via IPMI or something similar you should be able to
> > confirm.
> > 
> > A trick I've used in the past to recover from such a issue is to hard
> > bounce the nic ports on the switch which seemed to free enough to be
> > able to ssh in.
> 
> Yes, you nailed it.  We managed to recreate the effect in the lab, and
> 10.0 behaves much better under horrible overload.  While horribly slow,
> we can still get to a shell prompt via ssh, and when we turn off the
> load, the system recovers straight away.
> 
> We'll be upgrading to 10.x ASAP.
> 

I do not remember exact point in the stable/9 lifetime when the
debug.vn_io_fault_enable was merged.  If it is present in your system,
frob its value to 1 and see.  I highly suspect that if varnish is in
'mmap' mode (whatever it is called), and you use UFS, it may help.

I am suggesting this before upgrading to 10 only because I want to
know whether the vn_io_fault code helps in this situation.  There
are rumors that it does, but I never seen the confirmation.



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?alpine.BSF.2.11.1411060905290.1380>