SOLVED Freias 9.3 performs restarts when writing data to share

[valvius]

Edit (translate):
Hello

Im new to freenas.Sorry for german thread-title, I thought I am in the International -German-section.

I've got one problem: freenas reboots or looses the networkconnection evrytime I try to move my data from an external drive to my new shares using rsync and windows 8.1.

Details to my Setup:
Mainboard: Interl Server s5000psl
CPU : 2x Xeon Dual Core
Ram: 20 GB
OS Drive: 4GB USB 2.0
HDD: 6x Seagate Barracuda 2TB + 2x Seagate Video 3,5 2TB (connected through CSL Raidcontroller without Raid-Config)
Netzwork: Gigabit

The 8 drives are configuered as one volume with raidz2 and I created several shares for os x and windows for backups and shared-storage.

The "alert" box in the web-ui doesn't provide any information for me and there aren't any plugins installed yet.

I think my problem is related to my setup and I hope someone can help me to find my mistakes.


(Original)
Hallo erstmal.
Da ich noch ein Neuling in Sachen Freenas bin dachte ich ich schreibe hier, da ich mir nicht sicher bin ob ich alles richtig eingerichtet habe.

Ich habe das Problem, das ich die Verbindung zum Nas von meinem Win 8 verliere sobald ich anfange meine Daten mittels Rsync von einer externen HDD zu kopieren. Dabei startet Freenas immer neu.

Zu meinem Nas:
Mainboard: Interl Server s5000psl
CPU : 2x Xeon Dual Core
Ram: 20 GB
OS Drive: 4GB USB 2.0
HDD: 6x Seagate Barracuda 2TB + 2x Seagate Video 3,5 2TB (angeschlossen mit CSL Raidcontroller ohne Raid-Config)
Netzwerk: Gigabit

Habe aus den HDD ein Volumen im RaidZ2 erstellt und shares für Windows sowie Mac eingestellt (jeweils für Backup und für gemeinsame Daten)

Bei "Alert" bekomme ich keine Informationen zu den Vorfällen.
Es sind keine Plugins installiert (plexserver soll noch kommen)

Hoffe mir kann hier jemand helfen.

 

[dlavigne]

Which version of FreeNAS? How is the external drive mounted? Anything in /var/log/messages?

 

[valvius]

The version is "FreeNAS-9.3-STABLE-201502271818". The external drive is mounted like any usb drive for windows (plug in and be happy).
Some output from messages. Everything else there seems normal. But there are hint for new firmware for my drives. Should I update them?

Show

Mar 13 17:36:49 freenas smbd[4362]: STATUS=daemon 'smbd' finished starting up and ready to serve connectionsbitfinix_i5 (ipv4:192.168.178.2:3641) closed connection to service Gast

Mar 13 17:37:02 freenas (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 e0 d8 3d 40 40 02 00 00 00 00 00

Mar 13 17:37:02 freenas (ada0:ahcich0:0:0:0): CAM status: CCB request was invalid

Mar 13 17:37:02 freenas (ada0:ahcich0:0:0:0): Error 22, Unretryable error

Mar 13 17:37:05 freenas (ada7:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 e8 88 5f 40 40 02 00 00 00 00 00

Mar 13 17:37:05 freenas (ada7:ahcich1:0:0:0): CAM status: CCB request was invalid

Mar 13 17:37:05 freenas (ada7:ahcich1:0:0:0): Error 22, Unretryable error

Mar 13 17:37:05 freenas ada7 at ahcich1 bus 0 scbus1 target 0 lun 0

Mar 13 17:37:05 freenas ada7: <ST2000VM003-1CT164 SC23> s/n W1H27PDX detached

Mar 13 17:37:05 freenas (ada7:ahcich1:0:0:0): Periph destroyed

Mar 13 17:37:06 freenas (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 e0 60 ba 40 40 02 00 00 00 00 00

Mar 13 17:37:06 freenas (ada0:ahcich0:0:0:0): CAM status: CCB request was invalid

Mar 13 17:37:06 freenas (ada0:ahcich0:0:0:0): Error 22, Unretryable error

Mar 13 17:37:06 freenas (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 e0 18 ee 40 40 02 00 00 00 00 00

Mar 13 17:37:06 freenas (ada0:ahcich0:0:0:0): CAM status: CCB request was invalid

Mar 13 17:37:06 freenas (ada0:ahcich0:0:0:0): Error 22, Unretryable error

Mar 13 17:37:08 freenas (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 e0 f8 16 41 40 02 00 00 00 00 00

Mar 13 17:37:08 freenas (ada0:ahcich0:0:0:0): CAM status: CCB request was invalid

Mar 13 17:37:08 freenas (ada0:ahcich0:0:0:0): Error 22, Unretryable error

Mar 13 17:37:09 freenas zfsd: Replace vdev(Volumen-1/17360644253551827853) by physical path: Unable to allocate spare target data.

Mar 13 17:37:13 freenas (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 e0 08 27 41 40 02 00 00 00 00 00

Mar 13 17:37:13 freenas (ada0:ahcich0:0:0:0): CAM status: CCB request was invalid

Mar 13 17:37:13 freenas (ada0:ahcich0:0:0:0): Error 22, Unretryable error

Mar 13 17:37:16 freenas (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 e0 f8 d6 41 40 02 00 00 00 00 00

Mar 13 17:37:16 freenas (ada0:ahcich0:0:0:0): CAM status: CCB request was invalid

Mar 13 17:37:16 freenas (ada0:ahcich0:0:0:0): Error 22, Unretryable error

Mar 13 17:37:16 freenas (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 58 08 18 41 40 02 00 00 00 00 00

Mar 13 17:37:16 freenas (ada0:ahcich0:0:0:0): CAM status: CCB request was invalid

Mar 13 17:37:16 freenas (ada0:ahcich0:0:0:0): Error 22, Unretryable error

Mar 13 17:37:17 freenas ada7 at ahcich1 bus 0 scbus1 target 0 lun 0

Mar 13 17:37:17 freenas ada7: <ST2000VM003-1CT164 SC23> ATA-8 SATA 3.x device

Mar 13 17:37:17 freenas ada7: Serial Number W1H27PDX

Mar 13 17:37:17 freenas ada7: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)

Mar 13 17:37:17 freenas ada7: Command Queueing enabled

Mar 13 17:37:17 freenas ada7: 1907729MB (3907029168 512 byte sectors: 16H 63S/T 16383C)

Mar 13 17:37:17 freenas ada7: Previously was known as ad6

Mar 13 17:46:12 freenas syslog-ng[1876]: syslog-ng starting up; version='3.5.6'

Mar 13 17:46:12 freenas Copyright (c) 1992-2014 The FreeBSD Project.

Mar 13 17:46:12 freenas Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994

Mar 13 17:46:12 freenas The Regents of the University of California. All rights reserved.

Mar 13 17:46:12 freenas FreeBSD is a registered trademark of The FreeBSD Foundation.

Mar 13 17:46:12 freenas FreeBSD 9.3-RELEASE-p10 #0 r275790+a21079f: Thu Feb 26 22:13:30 PST 2015

Mar 13 17:46:12 freenas root@build3.ixsystems.com:/tank/home/jkh/build/FN93/freenas/objs/os-base/amd64/fusion/jkh/FN93/freenas/FreeBSD/src/sys/FREENAS.amd64 amd64

 

[dlavigne]

FreeNAS isn't really designed to use USB drives for storage or sharing. It only gives limited support to temporarily mount a USB drive in order to copy its data onto the storage pool.

 

[valvius]

I think you got it wrong. My windows 8.1 mounted the USB drive and tries to move the data to freenas

 

[dlavigne]

Ah, OK. Please post the relevant messages from /var/log/messages. Also, what is the exact message regarding the firmware?

 

[valvius]

I cleared the log and created the problem. Here is the log since than. It took much longer this time. There were several reboots.
The logfile: https://drive.google.com/file/d/0B5NSIUOxM9oMdXoyeURxRHU4c28/view?usp=sharing

And here ist the part for firmware:

Show : messeges -firmware

Mar 15 13:12:03 freenas smartd[2972]: Device: /dev/ada2, WARNING: A firmware update for this drive is available,
Mar 15 13:12:03 freenas smartd[2972]: see the following Seagate web pages:
Mar 15 13:12:03 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/207931en
Mar 15 13:12:03 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/223651en
Mar 15 13:12:03 freenas smartd[2972]: Device: /dev/ada3, WARNING: A firmware update for this drive is available,
Mar 15 13:12:03 freenas smartd[2972]: see the following Seagate web pages:
Mar 15 13:12:03 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/207931en
Mar 15 13:12:03 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/223651en
Mar 15 13:12:04 freenas smartd[2972]: Device: /dev/ada4, WARNING: A firmware update for this drive is available,
Mar 15 13:12:04 freenas smartd[2972]: see the following Seagate web pages:
Mar 15 13:12:04 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/207931en
Mar 15 13:12:04 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/223651en
Mar 15 13:12:04 freenas smbd[2966]: [2015/03/15 13:12:04.151495, 0] ../lib/util/become_daemon.c:136(daemon_ready)
Mar 15 13:12:04 freenas smbd[2966]: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
Mar 15 13:12:04 freenas smartd[2972]: Device: /dev/ada5, WARNING: A firmware update for this drive is available,
Mar 15 13:12:04 freenas smartd[2972]: see the following Seagate web pages:
Mar 15 13:12:04 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/207931en
Mar 15 13:12:04 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/223651en
Mar 15 13:12:04 freenas smartd[2972]: Device: /dev/ada6, WARNING: A firmware update for this drive is available,
Mar 15 13:12:04 freenas smartd[2972]: see the following Seagate web pages:
Mar 15 13:12:04 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/207931en
Mar 15 13:12:04 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/223651en
Mar 15 13:12:04 freenas smartd[2972]: Device: /dev/ada7, WARNING: A firmware update for this drive is available,
Mar 15 13:12:04 freenas smartd[2972]: see the following Seagate web pages:
Mar 15 13:12:04 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/207931en
Mar 15 13:12:04 freenas smartd[2972]: http://knowledge.seagate.com/articles/en_US/FAQ/223651en

I hope there is some useful information.

 

[dlavigne]

When's the last time you ran a SMART test or a scrub? ada0 is showing some errors in the log.

 

[valvius]

There weren't any tests since i removed ada0 and ada1 from my old Sitecomnas. The first complete test is still going on. I will post the results.

 

[valvius]

Ok test is over. There weren't any errors in ad1-ad7 but on ad0:

Show : smartctl -l selftest /dev/ada0

smartctl -a /dev/ada0
smartctl 6.3 2014-07-26 r3976 [FreeBSD 9.3-RELEASE-p10 amd64] (local build)
Copyright (C) 2002-14, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF INFORMATION SECTION ===
Model Family: Seagate Video 3.5 HDD
Device Model: ST2000VM003-1CT164
Serial Number: W1H29KKM
LU WWN Device Id: 5 000c50 06a845fe9
Firmware Version: SC23
User Capacity: 2,000,398,934,016 bytes [2.00 TB]
Sector Sizes: 512 bytes logical, 4096 bytes physical
Rotation Rate: 5900 rpm
Form Factor: 3.5 inches
Device is: In smartctl database [for details use: -P show]
ATA Version is: ATA8-ACS T13/1699-D revision 4
SATA Version is: SATA 3.0, 6.0 Gb/s (current: 3.0 Gb/s)
Local Time is: Tue Mar 17 17:05:39 2015 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
See vendor-specific Attribute list for marginal Attributes.

General SMART Values:
Offline data collection status: (0x82) Offline data collection activity
was completed without error.
Auto Offline Data Collection: Enabled.
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: ( 107) seconds.
Offline data collection
capabilities: (0x7b) SMART execute Offline immediate.
Auto Offline data collection on/off support.
Suspend Offline collection upon new
command.
Offline surface scan supported.
Self-test supported.
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: ( 1) minutes.
Extended self-test routine
recommended polling time: ( 278) minutes.
Conveyance self-test routine
recommended polling time: ( 2) minutes.
SCT capabilities: (0x10b9) SCT Status supported.
SCT Error Recovery Control supported.
SCT Feature Control supported.
SCT Data Table supported.

SMART Attributes Data Structure revision number: 10
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE
1 Raw_Read_Error_Rate 0x000f 119 100 006 Pre-fail Always - 205844912
3 Spin_Up_Time 0x0003 096 095 000 Pre-fail Always - 0
4 Start_Stop_Count 0x0032 099 099 020 Old_age Always - 1120
5 Reallocated_Sector_Ct 0x0033 100 100 036 Pre-fail Always - 0
7 Seek_Error_Rate 0x000f 067 060 030 Pre-fail Always - 6271553
9 Power_On_Hours 0x0032 092 092 000 Old_age Always - 7752
10 Spin_Retry_Count 0x0013 100 100 097 Pre-fail Always - 0
12 Power_Cycle_Count 0x0032 100 100 020 Old_age Always - 122
184 End-to-End_Error 0x0032 100 100 099 Old_age Always - 0
187 Reported_Uncorrect 0x0032 100 100 000 Old_age Always - 0
188 Command_Timeout 0x0032 099 069 000 Old_age Always - 188981444749
189 High_Fly_Writes 0x003a 031 031 000 Old_age Always - 69
190 Airflow_Temperature_Cel 0x0022 059 041 045 Old_age Always In_the_past 41 (Min/Max 20/41 #55)
191 G-Sense_Error_Rate 0x0032 100 100 000 Old_age Always - 0
192 Power-Off_Retract_Count 0x0032 100 100 000 Old_age Always - 113
193 Load_Cycle_Count 0x0032 100 100 000 Old_age Always - 1134
194 Temperature_Celsius 0x0022 041 059 000 Old_age Always - 41 (0 9 0 0 0)
197 Current_Pending_Sector 0x0012 100 100 000 Old_age Always - 0
198 Offline_Uncorrectable 0x0010 100 100 000 Old_age Offline - 0
199 UDMA_CRC_Error_Count 0x003e 200 200 000 Old_age Always - 4

SMART Error Log Version: 1
ATA Error Count: 2
CR = Command Register [HEX]
FR = Features Register [HEX]
SC = Sector Count Register [HEX]
SN = Sector Number Register [HEX]
CL = Cylinder Low Register [HEX]
CH = Cylinder High Register [HEX]
DH = Device/Head Register [HEX]
DC = Device Command Register [HEX]
ER = Error register [HEX]
ST = Status register [HEX]
Powered_Up_Time is measured from power on, and printed as
DDd+hh:mm:SS.sss where DD=days, hh=hours, mm=minutes,
SS=sec, and sss=millisec. It "wraps" after 49.710 days.

Error 2 occurred at disk power-on lifetime: 7745 hours (322 days + 17 hours)
When the command that caused the error occurred, the device was in an unknown state.

After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
04 51 00 00 00 00 00 Error: ABRT

Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
00 00 00 00 00 00 00 ff 1d+01:50:59.955 NOP [Abort queued commands]
b0 d4 00 81 4f c2 40 00 1d+01:50:39.792 SMART EXECUTE OFF-LINE IMMEDIATE
b0 d0 01 00 4f c2 40 00 1d+01:50:39.789 SMART READ DATA
ec 00 01 00 00 00 40 00 1d+01:50:39.772 IDENTIFY DEVICE
b0 d5 01 06 4f c2 40 00 1d+01:50:18.582 SMART READ LOG

Error 1 occurred at disk power-on lifetime: 7681 hours (320 days + 1 hours)
When the command that caused the error occurred, the device was in an unknown state.

After command completion occurred, registers were:
ER ST SC SN CL CH DH
-- -- -- -- -- -- --
04 51 00 00 00 00 00 Error: ABRT

Commands leading to the command that caused the error were:
CR FR SC SN CL CH DH DC Powered_Up_Time Command/Feature_Name
-- -- -- -- -- -- -- -- ---------------- --------------------
00 00 00 00 00 00 00 ff 00:21:28.131 NOP [Abort queued commands]
b0 d4 00 81 4f c2 a0 00 00:20:37.022 SMART EXECUTE OFF-LINE IMMEDIATE
b0 d8 00 00 4f c2 a0 00 00:20:37.022 SMART ENABLE OPERATIONS
ef 03 45 00 4f c2 e0 00 00:19:35.142 SET FEATURES [Set transfer mode]
ef 03 0a 00 4f c2 e0 00 00:19:35.112 SET FEATURES [Set transfer mode]

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% 7749 -
# 2 Short captive Interrupted (host reset) 70% 7745 -
# 3 Short offline Completed without error 00% 7745 -
# 4 Short offline Completed without error 00% 7745 -
# 5 Extended offline Interrupted (host reset) 90% 7744 -
# 6 Extended offline Interrupted (host reset) 90% 7720 -
# 7 Short captive Interrupted (host reset) 10% 7681 -

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.

Edit reason: More Information
Today I recieved this message

Show : notification

da0 at umass-sim0 bus 0 scbus11 target 0 lun 0
<ST2000VM003-1CT164 SC23> ATA-8 SATA 3.x device
Timecounter "TSC" frequency 1995042294 Hz quality 1000
(ada1:ahcich1:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 e0 38 00 4b 40 06 00 00 00 00 00
(ada1:ahcich1:0:0:0): CAM status: CCB request was invalid
(ada1:ahcich1:0:0:0): Error 22, Unretryable error
ada1 at ahcich1 bus 0 scbus1 target 0 lun 0
ada1: <ST2000VM003-1CT164 SC23> s/n W1H27PDX detached
(ada1:ahcich1:0:0:0): Periph destroyed
vboxdrv: fAsync=0 offMin=0x804 offMax=0x134a
ada1 at ahcich1 bus 0 scbus1 target 0 lun 0
ada1: <ST2000VM003-1CT164 SC23> ATA-8 SATA 3.x device
ada1: Serial Number W1H27PDX
ada1: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
ada1: Command Queueing enabled
ada1: 1907729MB (3907029168 512 byte sectors: 16H 63S/T 16383C)
ada1: Previously was known as ad6
em0: promiscuous mode enabled
epair0a: Ethernet address: 02:48:48:00:0b:0a
epair0b: Ethernet address: 02:48:48:00:0c:0b
ahcich0: Timeout on slot 5 port 0
ahcich0: is 00000000 cs 00000020 ss 00000000 rs 00000020 tfd d0 serr 00000000 cmd 0004c511
ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
ada0: <ST2000VM003-1CT164 SC23> s/n W1H29KKM detached

I see problems with ada1 and ada0 but only ada0 is detached and both are connected with PCI-E expansion card(http://www.amazon.de/dp/B00FF7L854)

 

[valvius]

Problem solved...there was a defect with the raid controller.