Freenas Ahci Timeout On Slot

Freenas

Freenas Ahci Time Out On Slot Machines

  1. May 10 22:56:50 freenas smbd[2643]: STATUS=daemon 'smbd' finished starting up and ready to serve connectionsget_ea_dos_attribute: Cannot get attribute from EA on file ./..: Error = Operation not supported
  2. May 10 23:54:25 freenas smbd[8581]: STATUS=daemon 'smbd' finished starting up and ready to serve connectionsget_ea_dos_attribute: Cannot get attribute from EA on file ./..: Error = Operation not supported
  3. May 11 00:00:00 freenas syslog-ng[1681]: Configuration reload request received, reloading configuration;
  4. May 11 00:05:11 freenas smbd[8616]: STATUS=daemon 'smbd' finished starting up and ready to serve connectionsreceive_smb_raw_talloc failed for client ipv4:192.168.1.154:49323 read error = NT_STATUS_IO_TIMEOUT.
  5. May 11 14:50:44 freenas syslog-ng[1683]: syslog-ng starting up; version='3.5.6'
  6. May 11 14:50:44 freenas Copyright (c) 1992-2014 The FreeBSD Project.
  7. May 11 14:50:44 freenas Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
  8. May 11 14:50:44 freenas The Regents of the University of California. All rights reserved.
  9. May 11 14:50:44 freenas FreeBSD is a registered trademark of The FreeBSD Foundation.
  10. May 11 14:50:44 freenas FreeBSD 9.3-RELEASE-p8 #0 r275790+4edb7b0: Fri Jan 16 14:37:13 PST 2015
  11. May 11 14:50:44 freenas root@build3.ixsystems.com:/tank/home/jkh/build/93/FN/objs/os-base/amd64/fusion/jkh/93/FN/FreeBSD/src/sys/FREENAS.amd64 amd64
  12. May 11 14:50:44 freenas gcc version 4.2.1 20070831 patched [FreeBSD]
  13. May 11 14:50:44 freenas CPU: AMD Phenom(tm) II X2 555 Processor (3210.96-MHz K8-class CPU)
  14. May 11 14:50:44 freenas Origin = 'AuthenticAMD' Id = 0x100f43 Family = 0x10 Model = 0x4 Stepping = 3
  15. May 11 14:50:44 freenas Features=0x178bfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CLFLUSH,MMX,FXSR,SSE,SSE2,HTT>
  16. May 11 14:50:44 freenas Features2=0x802009<SSE3,MON,CX16,POPCNT>
  17. May 11 14:50:44 freenas AMD Features=0xee500800<SYSCALL,NX,MMX+,FFXSR,Page1GB,RDTSCP,LM,3DNow!+,3DNow!>
  18. May 11 14:50:44 freenas AMD Features2=0x37ff<LAHF,CMP,SVM,ExtAPIC,CR8,ABM,SSE4A,MAS,Prefetch,OSVW,IBS,SKINIT,WDT>
  19. May 11 14:50:44 freenas real memory = 9395240960 (8960 MB)
  20. May 11 14:50:44 freenas avail memory = 8227340288 (7846 MB)
  21. May 11 14:50:44 freenas Event timer 'LAPIC' quality 400
  22. May 11 14:50:44 freenas ACPI APIC Table: <050410 APIC1420>
  23. May 11 14:50:44 freenas FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
  24. May 11 14:50:44 freenas FreeBSD/SMP: 1 package(s) x 2 core(s)
  25. May 11 14:50:44 freenas cpu1 (AP): APIC ID: 1
  26. May 11 14:50:44 freenas WARNING: VIMAGE (virtualized network stack) is a highly experimental feature.
  27. May 11 14:50:44 freenas ioapic0 <Version 2.1> irqs 0-23 on motherboard
  28. May 11 14:50:44 freenas ispfw: registered firmware <isp_1040>
  29. May 11 14:50:44 freenas ispfw: registered firmware <isp_1040_it>
  30. May 11 14:50:44 freenas ispfw: registered firmware <isp_1080>
  31. May 11 14:50:44 freenas ispfw: registered firmware <isp_1080_it>
  32. May 11 14:50:44 freenas ispfw: registered firmware <isp_12160>
  33. May 11 14:50:44 freenas ispfw: registered firmware <isp_12160_it>
  34. May 11 14:50:44 freenas ispfw: registered firmware <isp_2100>
  35. May 11 14:50:44 freenas ispfw: registered firmware <isp_2200>
  36. May 11 14:50:44 freenas ispfw: registered firmware <isp_2300>
  37. May 11 14:50:44 freenas ispfw: registered firmware <isp_2322>
  38. May 11 14:50:44 freenas ispfw: registered firmware <isp_2400>
  39. May 11 14:50:44 freenas ispfw: registered firmware <isp_2400_multi>
  40. May 11 14:50:44 freenas ispfw: registered firmware <isp_2500>
  41. May 11 14:50:44 freenas ispfw: registered firmware <isp_2500_multi>
  42. May 11 14:50:44 freenas cryptosoft0: <software crypto> on motherboard
  43. May 11 14:50:44 freenas padlock0: No ACE support.
  44. May 11 14:50:44 freenas acpi0: <050410 XSDT1420> on motherboard
  45. May 11 14:50:44 freenas acpi0: Power Button (fixed)
  46. May 11 14:50:44 freenas acpi0: reservation of fee00000, 1000 (3) failed
  47. May 11 14:50:44 freenas acpi0: reservation of ffb80000, 80000 (3) failed
  48. May 11 14:50:44 freenas acpi0: reservation of fec10000, 20 (3) failed
  49. May 11 14:50:44 freenas acpi0: reservation of fed80000, 1000 (3) failed
  50. May 11 14:50:44 freenas acpi0: reservation of 0, a0000 (3) failed
  51. May 11 14:50:44 freenas acpi0: reservation of 100000, cfd00000 (3) failed
  52. May 11 14:50:44 freenas cpu1: <ACPI CPU> on acpi0
  53. May 11 14:50:44 freenas attimer0: <AT timer> port 0x40-0x43 irq 0 on acpi0
  54. May 11 14:50:44 freenas Timecounter 'i8254' frequency 1193182 Hz quality 0
  55. May 11 14:50:44 freenas Event timer 'i8254' frequency 1193182 Hz quality 100
  56. May 11 14:50:44 freenas atrtc0: <AT realtime clock> port 0x70-0x71 irq 8 on acpi0
  57. May 11 14:50:44 freenas Event timer 'RTC' frequency 32768 Hz quality 0
  58. May 11 14:50:44 freenas hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0
  59. May 11 14:50:44 freenas Timecounter 'HPET' frequency 14318180 Hz quality 950
  60. May 11 14:50:44 freenas Event timer 'HPET' frequency 14318180 Hz quality 550
  61. May 11 14:50:44 freenas Event timer 'HPET1' frequency 14318180 Hz quality 450
  62. May 11 14:50:44 freenas Timecounter 'ACPI-fast' frequency 3579545 Hz quality 900
  63. May 11 14:50:44 freenas acpi_timer0: <32-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0
  64. May 11 14:50:44 freenas acpi_ec0: <Embedded Controller: GPE 0xa> port 0x62,0x66 on acpi0
  65. May 11 14:50:44 freenas pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0
  66. May 11 14:50:44 freenas pci0: <ACPI PCI bus> on pcib0
  67. May 11 14:50:44 freenas pcib1: <ACPI PCI-PCI bridge> irq 19 at device 3.0 on pci0
  68. May 11 14:50:44 freenas pci1: <ACPI PCI bus> on pcib1
  69. May 11 14:50:44 freenas vgapci0: <VGA-compatible display> port 0xb000-0xb0ff mem 0xd0000000-0xdfffffff,0xfe6f0000-0xfe6fffff irq 19 at device 0.0 on pci1
  70. May 11 14:50:44 freenas vgapci0: Boot video device
  71. May 11 14:50:44 freenas vgapci1: <VGA-compatible display> mem 0xfe6e0000-0xfe6effff at device 0.1 on pci1
  72. May 11 14:50:44 freenas pcib2: <ACPI PCI-PCI bridge> irq 17 at device 9.0 on pci0
  73. May 11 14:50:44 freenas pci2: <ACPI PCI bus> on pcib2
  74. May 11 14:50:44 freenas pci2: <serial bus, USB> at device 0.0 (no driver attached)
  75. May 11 14:50:44 freenas pcib3: <ACPI PCI-PCI bridge> irq 18 at device 10.0 on pci0
  76. May 11 14:50:44 freenas pci3: <ACPI PCI bus> on pcib3
  77. May 11 14:50:44 freenas atapci0: <JMicron JMB361 UDMA133 controller> port 0xcc00-0xcc07,0xc880-0xc883,0xc800-0xc807,0xc480-0xc483,0xc400-0xc40f mem 0xfe8fe000-0xfe8fffff irq 18 at device 0.0 on pci3
  78. May 11 14:50:44 freenas ahci0: <JMicron JMB361 AHCI SATA controller> at channel -1 on atapci0
  79. May 11 14:50:44 freenas ahci0: AHCI v1.00 with 2 3Gbps ports, Port Multiplier supported
  80. May 11 14:50:44 freenas ahci0: quirks=0x1<NOFORCE>
  81. May 11 14:50:44 freenas ahcich0: <AHCI channel> at channel 0 on ahci0
  82. May 11 14:50:44 freenas ahcich1: <AHCI channel> at channel 1 on ahci0
  83. May 11 14:50:44 freenas ata2: <ATA channel> at channel 0 on atapci0
  84. May 11 14:50:44 freenas ahci1: <AMD SB7x0/SB8x0/SB9x0 AHCI SATA controller> port 0xa000-0xa007,0x9000-0x9003,0x8000-0x8007,0x7000-0x7003,0x6000-0x600f mem 0xfe5ffc00-0xfe5fffff irq 19 at device 17.0 on pci0
  85. May 11 14:50:44 freenas ahci1: AHCI v1.20 with 6 6Gbps ports, Port Multiplier supported
  86. May 11 14:50:44 freenas ahcich2: <AHCI channel> at channel 0 on ahci1
  87. May 11 14:50:44 freenas ahcich3: <AHCI channel> at channel 1 on ahci1
  88. May 11 14:50:44 freenas ahcich4: <AHCI channel> at channel 2 on ahci1
  89. May 11 14:50:44 freenas ahcich5: <AHCI channel> at channel 3 on ahci1
  90. May 11 14:50:44 freenas ahcich6: <AHCI channel> at channel 4 on ahci1
  91. May 11 14:50:44 freenas ahcich7: <AHCI channel> at channel 5 on ahci1
  92. May 11 14:50:44 freenas ohci0: <AMD SB7x0/SB8x0/SB9x0 USB controller> mem 0xfe5fe000-0xfe5fefff irq 18 at device 18.0 on pci0
  93. May 11 14:50:44 freenas ehci0: <AMD SB7x0/SB8x0/SB9x0 USB 2.0 controller> mem 0xfe5ff800-0xfe5ff8ff irq 17 at device 18.2 on pci0
  94. May 11 14:50:44 freenas usbus1 on ehci0
  95. May 11 14:50:44 freenas ohci1: <AMD SB7x0/SB8x0/SB9x0 USB controller> mem 0xfe5fd000-0xfe5fdfff irq 18 at device 19.0 on pci0
  96. May 11 14:50:44 freenas ehci1: <AMD SB7x0/SB8x0/SB9x0 USB 2.0 controller> mem 0xfe5ff400-0xfe5ff4ff irq 17 at device 19.2 on pci0
  97. May 11 14:50:44 freenas root: /etc/rc: WARNING: failed to start watchdogd
  98. May 11 14:50:44 freenas pci0: <multimedia, HDA> at device 20.2 (no driver attached)
  99. May 11 14:50:44 freenas isab0: <PCI-ISA bridge> at device 20.3 on pci0
  100. May 11 14:50:44 freenas pcib4: <ACPI PCI-PCI bridge> at device 20.4 on pci0
  101. May 11 14:50:44 freenas pci4: <ACPI PCI bus> on pcib4
  102. May 11 14:50:44 freenas fwohci0: <VIA Fire II (VT6306)> port 0xdc00-0xdc7f mem 0xfe9fb800-0xfe9fbfff irq 22 at device 7.0 on pci4
  103. May 11 14:50:44 freenas fwohci0: OHCI version 1.10 (ROM=1)
  104. May 11 14:50:44 freenas fwohci0: No. of Isochronous channels is 4.
  105. May 11 14:50:44 freenas fwohci0: EUI64 00:1e:8c:00:00:da:a4:a4
  106. May 11 14:50:44 freenas fwohci0: Phy 1394a available S400, 2 ports.
  107. May 11 14:50:44 freenas fwohci0: Link S400, max_rec 2048 bytes.
  108. May 11 14:50:44 freenas firewire0: <IEEE1394(FireWire) bus> on fwohci0
  109. May 11 14:50:44 freenas sbp0: <SBP-2/SCSI over FireWire> on firewire0
  110. May 11 14:50:44 freenas fwohci0: Initiate bus reset
  111. May 11 14:50:44 freenas fwohci0: fwohci_intr_core: BUS reset
  112. May 11 14:50:44 freenas fwohci0: fwohci_intr_core: node_id=0x00000000, SelfID Count=1, CYCLEMASTER mode
  113. May 11 14:50:44 freenas ohci2: <AMD SB7x0/SB8x0/SB9x0 USB controller> mem 0xfe5fc000-0xfe5fcfff irq 18 at device 20.5 on pci0
  114. May 11 14:50:44 freenas pcib5: <ACPI PCI-PCI bridge> at device 21.0 on pci0
  115. May 11 14:50:44 freenas pci5: <ACPI PCI bus> on pcib5
  116. May 11 14:50:44 freenas re0: <RealTek 8168/8111 B/C/CP/D/DP/E/F/G PCIe Gigabit Ethernet> port 0xe800-0xe8ff mem 0xfdfff000-0xfdffffff,0xfdff8000-0xfdffbfff irq 16 at device 0.0 on pci5
  117. May 11 14:50:44 freenas re0: Using 1 MSI-X message
  118. May 11 14:50:44 freenas re0: Chip rev. 0x2c000000
  119. May 11 14:50:44 freenas miibus0: <MII bus> on re0
  120. May 11 14:50:44 freenas rgephy0: <RTL8169S/8110S/8211 1000BASE-T media interface> PHY 1 on miibus0
  121. May 11 14:50:44 freenas rgephy0: none, 10baseT, 10baseT-FDX, 10baseT-FDX-flow, 100baseTX, 100baseTX-FDX, 100baseTX-FDX-flow, 1000baseT, 1000baseT-master, 1000baseT-FDX, 1000baseT-FDX-master, 1000baseT-FDX-flow, 1000baseT-FDX-flow-master, auto, auto-flow
  122. May 11 14:50:44 freenas re0: Ethernet address: 20:cf:30:07:b6:ac
  123. May 11 14:50:44 freenas ohci3: <AMD SB7x0/SB8x0/SB9x0 USB controller> mem 0xfe5f3000-0xfe5f3fff irq 18 at device 22.0 on pci0
  124. May 11 14:50:44 freenas ehci2: <AMD SB7x0/SB8x0/SB9x0 USB 2.0 controller> mem 0xfe5ff000-0xfe5ff0ff irq 17 at device 22.2 on pci0
  125. May 11 14:50:44 freenas usbus6 on ehci2
  126. May 11 14:50:44 freenas amdtemp0: <AMD CPU On-Die Thermal Sensors> on hostb4
  127. May 11 14:50:44 freenas acpi_button0: <Power Button> on acpi0
  128. May 11 14:50:44 freenas uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
  129. May 11 14:50:44 freenas orm0: <ISA Option ROMs> at iomem 0xc0000-0xcefff,0xd3800-0xd67ff,0xd6800-0xd77ff on isa0
  130. May 11 14:50:44 freenas sc0: <System console> at flags 0x100 on isa0
  131. May 11 14:50:44 freenas sc0: VGA <16 virtual consoles, flags=0x300>
  132. May 11 14:50:44 freenas vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
  133. May 11 14:50:44 freenas atkbdc0: <Keyboard controller (i8042)> at port 0x60,0x64 on isa0
  134. May 11 14:50:44 freenas atkbd0: <AT Keyboard> irq 1 on atkbdc0
  135. May 11 14:50:44 freenas atkbd0: [GIANT-LOCKED]
  136. May 11 14:50:44 freenas wbwd0: HEFRAS and EFER do not align: EFER 0x2e DevID 0xff DevRev 0xff CR26 0xff
  137. May 11 14:50:44 freenas acpi_throttle0: <ACPI CPU Throttling> on cpu0
  138. May 11 14:50:44 freenas hwpstate0: <Cool`n'Quiet 2.0> on cpu0
  139. May 11 14:50:44 freenas firewire0: 1 nodes, maxhop <= 0 cable IRM irm(0) (me)
  140. May 11 14:50:44 freenas ZFS filesystem version: 5
  141. May 11 14:50:44 freenas ZFS storage pool version: features support (5000)
  142. May 11 14:50:44 freenas Timecounters tick every 1.000 msec
  143. May 11 14:50:44 freenas ipfw2 (+ipv6) initialized, divert enabled, nat enabled, default to accept, logging disabled
  144. May 11 14:50:44 freenas usbus0: 12Mbps Full Speed USB v1.0
  145. May 11 14:50:44 freenas usbus1: 480Mbps High Speed USB v2.0
  146. May 11 14:50:44 freenas usbus2: 12Mbps Full Speed USB v1.0
  147. May 11 14:50:44 freenas usbus3: 480Mbps High Speed USB v2.0
  148. May 11 14:50:44 freenas usbus4: 12Mbps Full Speed USB v1.0
  149. May 11 14:50:44 freenas usbus5: 12Mbps Full Speed USB v1.0
  150. May 11 14:50:44 freenas usbus6: 480Mbps High Speed USB v2.0
  151. May 11 14:50:44 freenas uhub0: <ATI OHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
  152. May 11 14:50:44 freenas uhub1: <ATI EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus1
  153. May 11 14:50:44 freenas uhub2: <ATI OHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus2
  154. May 11 14:50:44 freenas uhub3: <ATI EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus3
  155. May 11 14:50:44 freenas uhub4: <ATI OHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus4
  156. May 11 14:50:44 freenas uhub5: <ATI OHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus5
  157. May 11 14:50:44 freenas uhub6: <ATI EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus6
  158. May 11 14:50:44 freenas (aprobe1:ahcich2:0:0:0): SETFEATURES DISABLE SATA FEATURE. ACB: ef 90 00 00 00 40 00 00 00 00 03 00
  159. May 11 14:50:44 freenas (aprobe1:ahcich2:0:0:0): CAM status: ATA Status Error
  160. May 11 14:50:44 freenas (aprobe1:ahcich2:0:0:0): ATA status: 51 (DRDY SERV ERR), error: 04 (ABRT )
  161. May 11 14:50:44 freenas (aprobe1:ahcich2:0:0:0): RES: 51 04 00 00 00 40 00 00 00 03 00
  162. May 11 14:50:44 freenas (aprobe1:ahcich2:0:0:0): Retrying command
  163. May 11 14:50:44 freenas (aprobe1:ahcich2:0:0:0): SETFEATURES DISABLE SATA FEATURE. ACB: ef 90 00 00 00 40 00 00 00 00 03 00
  164. May 11 14:50:44 freenas (aprobe1:ahcich2:0:0:0): CAM status: ATA Status Error
  165. May 11 14:50:44 freenas (aprobe1:ahcich2:0:0:0): ATA status: 51 (DRDY SERV ERR), error: 04 (ABRT )
  166. May 11 14:50:44 freenas (aprobe1:ahcich2:0:0:0): RES: 51 04 00 00 00 40 00 00 00 03 00
  167. May 11 14:50:44 freenas (aprobe1:ahcich2:0:0:0): Error 5, Retries exhausted
  168. May 11 14:50:44 freenas (aprobe2:ahcich3:0:0:0): SETFEATURES DISABLE SATA FEATURE. ACB: ef 90 00 00 00 40 00 00 00 00 03 00
  169. May 11 14:50:44 freenas (aprobe2:ahcich3:0:0:0): CAM status: ATA Status Error
  170. May 11 14:50:44 freenas (aprobe2:ahcich3:0:0:0): ATA status: 51 (DRDY SERV ERR), error: 04 (ABRT )
  171. May 11 14:50:44 freenas (aprobe2:ahcich3:0:0:0): RES: 51 04 00 00 00 40 00 00 00 03 00
  172. May 11 14:50:44 freenas (aprobe2:ahcich3:0:0:0): Retrying command
  173. May 11 14:50:44 freenas (aprobe2:ahcich3:0:0:0): SETFEATURES DISABLE SATA FEATURE. ACB: ef 90 00 00 00 40 00 00 00 00 03 00
  174. May 11 14:50:44 freenas (aprobe2:ahcich3:0:0:0): CAM status: ATA Status Error
  175. May 11 14:50:44 freenas (aprobe2:ahcich3:0:0:0): ATA status: 51 (DRDY SERV ERR), error: 04 (ABRT )
  176. May 11 14:50:44 freenas (aprobe2:ahcich3:0:0:0): RES: 51 04 00 00 00 40 00 00 00 03 00
  177. May 11 14:50:44 freenas (aprobe2:ahcich3:0:0:0): Error 5, Retries exhausted
  178. May 11 14:50:44 freenas uhub4: 2 ports with 2 removable, self powered
  179. May 11 14:50:44 freenas uhub5: 4 ports with 4 removable, self powered
  180. May 11 14:50:44 freenas uhub0: 5 ports with 5 removable, self powered
  181. May 11 14:50:44 freenas uhub2: 5 ports with 5 removable, self powered
  182. May 11 14:50:44 freenas uhub6: 4 ports with 4 removable, self powered
  183. May 11 14:50:44 freenas uhub1: 5 ports with 5 removable, self powered
  184. May 11 14:50:44 freenas uhub3: 5 ports with 5 removable, self powered
  185. May 11 14:50:44 freenas ugen2.2: <Logitech> at usbus2
  186. May 11 14:50:44 freenas ukbd0: <Logitech USB Receiver, class 0/0, rev 2.00/12.01, addr 2> on usbus2
  187. May 11 14:50:44 freenas ums0: <Logitech USB Receiver, class 0/0, rev 2.00/12.01, addr 2> on usbus2
  188. May 11 14:50:44 freenas ums0: 16 buttons and [XYZT] coordinates ID=2
  189. May 11 14:50:44 freenas uhid0: <Logitech USB Receiver, class 0/0, rev 2.00/12.01, addr 2> on usbus2
  190. May 11 14:50:44 freenas ugen1.2: <PNY Technologies> at usbus1
  191. May 11 14:50:44 freenas umass0: <PNY Technologies USB 2.0 FD, class 0/0, rev 2.00/1.00, addr 2> on usbus1
  192. May 11 14:50:44 freenas umass0: SCSI over Bulk-Only; quirks = 0x0100
  193. May 11 14:50:44 freenas umass0:11:0:-1: Attached to scbus11
  194. May 11 14:50:44 freenas ahcich1: AHCI reset: device not ready after 31000ms (tfd = 000000ff)
  195. May 11 14:50:44 freenas ahcich1: Poll timeout on slot 0 port 15
  196. May 11 14:50:44 freenas ahcich1: is 00000000 cs 00000001 ss 00000000 rs 00000001 tfd 77 serr 00020000 cmd 0004c011
  197. May 11 14:50:44 freenas (aprobe0:ahcich1:0:15:0): SOFT_RESET. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
  198. May 11 14:50:44 freenas (aprobe0:ahcich1:0:15:0): CAM status: Command timeout
  199. May 11 14:50:44 freenas (aprobe0:ahcich1:0:15:0): Error 5, Retries exhausted
  200. May 11 14:50:44 freenas ahcich1: Poll timeout on slot 0 port 0
  201. May 11 14:50:44 freenas ahcich1: is 00000000 cs 00000001 ss 00000000 rs 00000001 tfd 77 serr 00020000 cmd 0004c011
  202. May 11 14:50:44 freenas (aprobe0:ahcich1:0:0:0): SOFT_RESET. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
  203. May 11 14:50:44 freenas (aprobe0:ahcich1:0:0:0): CAM status: Command timeout
  204. May 11 14:50:44 freenas (aprobe0:ahcich1:0:0:0): Error 5, Retries exhausted
  205. May 11 14:50:44 freenas run_interrupt_driven_hooks: still waiting after 60 seconds for xpt_config
  206. May 11 14:50:44 freenas ada0 at ahcich2 bus 0 scbus3 target 0 lun 0
  207. May 11 14:50:44 freenas ada0: <WDC WD1200JD-00GBB0 02.05D02> ATA-6 SATA 1.x device
  208. May 11 14:50:44 freenas ada0: Serial Number WD-WMAES2981097
  209. May 11 14:50:44 freenas ada0: 150.000MB/s transfers (SATA 1.x, UDMA5, PIO 8192bytes)
  210. May 11 14:50:44 freenas ada0: 114473MB (234441648 512 byte sectors: 16H 63S/T 16383C)
  211. May 11 14:50:44 freenas ada0: Previously was known as ad10
  212. May 11 14:50:44 freenas ada1 at ahcich3 bus 0 scbus4 target 0 lun 0
  213. May 11 14:50:44 freenas ada1: <WDC WD1200JD-00GBB0 02.05D02> ATA-6 SATA 1.x device
  214. May 11 14:50:44 freenas da0 at umass-sim0 bus 0 scbus11 target 0 lun 0
  215. May 11 14:50:44 freenas da0: <PNY USB 2.0 FD 0.00> Removable Direct Access SCSI-4 device
  216. May 11 14:50:44 freenas da0: Serial Number UT2A268100000088
  217. May 11 14:50:44 freenas da0: 30532MB (62529536 512 byte sectors: 255H 63S/T 3892C)
  218. May 11 14:50:44 freenas da0: quirks=0x2<NO_6_BYTE>
  219. May 11 14:50:44 freenas ada1: Serial Number WD-WMAET1604268
  220. May 11 14:50:44 freenas ada1: 150.000MB/s transfers (SATA 1.x, UDMA5, PIO 8192bytes)
  221. May 11 14:50:44 freenas ada1: 114473MB (234441648 512 byte sectors: 16H 63S/T 16383C)
  222. May 11 14:50:44 freenas ada1: Previously was known as ad12
  223. May 11 14:50:44 freenas ada2 at ahcich4 bus 0 scbus5 target 0 lun 0
  224. May 11 14:50:44 freenas ada2: <Hitachi HDS722020ALA330 JKAOA3EA> ATA-8 SATA 2.x device
  225. May 11 14:50:44 freenas ada2: Serial Number JK1171YBK7L9JF
  226. May 11 14:50:44 freenas ada2: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
  227. May 11 14:50:44 freenas ada2: Command Queueing enabled
  228. May 11 14:50:44 freenas ada2: 1907729MB (3907029168 512 byte sectors: 16H 63S/T 16383C)
  229. May 11 14:50:44 freenas ada2: Previously was known as ad14
  230. May 11 14:50:44 freenas ada3 at ahcich5 bus 0 scbus6 target 0 lun 0
  231. May 11 14:50:44 freenas ada3: <Hitachi HDS721050CLA362 JP2OA3GH> ATA-8 SATA 2.x device
  232. May 11 14:50:44 freenas ada3: Serial Number JP5570HK15KH7P
  233. May 11 14:50:44 freenas ada3: 300.000MB/s transfers (SATA 2.x, UDMA6, PIO 8192bytes)
  234. May 11 14:50:44 freenas ada3: Command Queueing enabled
  235. May 11 14:50:44 freenas ada3: 476940MB (976773168 512 byte sectors: 16H 63S/T 16383C)
  236. May 11 14:50:44 freenas ada3: Previously was known as ad16
  237. May 11 14:50:44 freenas Timecounter 'TSC-low' frequency 1605480945 Hz quality 800
  238. May 11 14:50:44 freenas Trying to mount root from zfs:freenas-boot/ROOT/default []...
  239. May 11 14:50:44 freenas GEOM_RAID5: Module loaded, version 1.3.20140711.62 (rev f91e28e40bf7)
  240. May 11 14:50:44 freenas wbwd0: HEFRAS and EFER do not align: EFER 0x2e DevID 0xff DevRev 0xff CR26 0xff
  241. May 11 14:50:45 freenas GEOM_ELI: Device ada2p1.eli created.
  242. May 11 14:50:45 freenas GEOM_ELI: Encryption: AES-XTS 256
  243. May 11 14:50:45 freenas GEOM_ELI: Crypto: software
  244. May 11 14:50:45 freenas GEOM_ELI: Device ada3p1.eli created.
  245. May 11 14:50:45 freenas GEOM_ELI: Encryption: AES-XTS 256
  246. May 11 14:50:45 freenas GEOM_ELI: Crypto: software
  247. May 11 14:50:45 freenas GEOM_ELI: Device ada0p1.eli created.
  248. May 11 14:50:45 freenas GEOM_ELI: Encryption: AES-XTS 256
  249. May 11 14:50:45 freenas GEOM_ELI: Crypto: software
  250. May 11 14:50:45 freenas GEOM_ELI: Device ada1p1.eli created.
  251. May 11 14:50:45 freenas GEOM_ELI: Encryption: AES-XTS 256
  252. May 11 14:50:45 freenas GEOM_ELI: Crypto: software
  253. May 11 14:50:46 freenas savecore: /dev/ada0p1: Operation not permitted
  254. May 11 14:50:47 freenas nfsd: can't register svc name
  255. May 11 14:50:47 freenas root: /etc/rc: WARNING: failed precmd routine for vmware_guestd
  256. May 11 14:50:47 freenas vboxdrv: fAsync=0 offMin=0x3d8 offMax=0x9f8
  257. May 11 14:50:49 freenas ntpd[2081]: ntpd 4.2.4p5-a (1)
  258. May 11 14:50:56 freenas generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /sbin/sysctl -n 'kern.maxfilesperproc'
  259. May 11 14:50:56 freenas generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: zfs list -H -o mountpoint,name
  260. May 11 14:50:56 freenas generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: zfs list -H -o mountpoint
  261. May 11 14:50:56 freenas generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: zfs list -H -o mountpoint
  262. May 11 14:50:56 freenas generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: zfs list -H -o mountpoint
  263. May 11 14:50:56 freenas generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/pdbedit -d 0 -i smbpasswd:/tmp/tmp4KvKHM -s /usr/local/etc/smb4.conf -e tdbsam:/var/etc/private/passdb.tdb
  264. May 11 14:50:57 freenas generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/bin/getent passwd 'subcool'
  265. May 11 14:50:57 freenas generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/pdbedit -L
  266. May 11 14:50:57 freenas generate_smb4_conf.py: [common.pipesubr:58] Popen()ing: /usr/local/bin/net sam rights grant subcool SeTakeOwnershipPrivilege SeBackupPrivilege SeRestorePrivilege
  267. May 11 14:50:58 freenas nmbd[2339]: [2015/05/11 14:50:58.074150, 0] ../lib/util/become_daemon.c:136(daemon_ready)
  268. May 11 14:50:58 freenas winbindd[2345]: [2015/05/11 14:50:58.222171, 0] ../source3/winbindd/winbindd_cache.c:3196(initialize_winbindd_cache)
  269. May 11 14:50:58 freenas winbindd[2345]: initialize_winbindd_cache: clearing cache and re-creating with version number 2
  270. May 11 14:50:58 freenas winbindd[2345]: [2015/05/11 14:50:58.238746, 0] ../lib/util/become_daemon.c:136(daemon_ready)
  271. May 11 14:50:58 freenas smbd[2342]: [2015/05/11 14:50:58.445695, 0] ../lib/util/become_daemon.c:136(daemon_ready)
  272. May 11 14:50:58 freenas smbd[2342]: dnssd_clientstub ConnectToServer: connect()-> No of tries: 1
  273. May 11 14:50:59 freenas smbd[2342]: dnssd_clientstub ConnectToServer: connect()-> No of tries: 2
  274. May 11 14:50:58 freenas ntpd[2082]: time reset -0.854447 s
  275. May 11 14:50:59 freenas smbd[2342]: dnssd_clientstub ConnectToServer: connect()-> No of tries: 3
  276. May 11 14:51:00 freenas smbd[2342]: dnssd_clientstub ConnectToServer: connect() failed Socket:32 Err:-1 Errno:2 No such file or directory
  277. May 11 14:51:05 freenas netatalk[2598]: Netatalk AFP server starting
  278. May 11 14:51:05 freenas netatalk[2598]: Registered with Zeroconf
  279. May 11 14:51:05 freenas cnid_metad[2614]: CNID Server listening on localhost:4700
  280. May 11 14:51:05 freenas afpd[2613]: Netatalk AFP/TCP listening on 192.168.1.197:548
  281. May 11 14:51:23 freenas bridge0: Ethernet address: 02:3c:a8:87:51:00
  282. May 11 14:51:23 freenas kernel: bridge0: link state changed to UP
  283. May 11 14:51:23 freenas kernel: bridge0: link state changed to UP
  284. May 11 14:51:23 freenas kernel: re0: promiscuous mode enabled
  285. May 11 14:51:23 freenas epair0a: Ethernet address: 02:e3:fb:00:0c:0a
  286. May 11 14:51:23 freenas epair0b: Ethernet address: 02:e3:fb:00:0d:0b
  287. May 11 14:51:23 freenas kernel: epair0a: link state changed to UP
  288. May 11 14:51:23 freenas kernel: epair0a: link state changed to UP
  289. May 11 14:51:23 freenas kernel: epair0b: link state changed to UP
  290. May 11 14:51:23 freenas kernel: epair0b: link state changed to UP
  291. May 11 14:51:23 freenas kernel: re0: link state changed to DOWN
  292. May 11 14:51:23 freenas kernel: re0: link state changed to DOWN
  293. May 11 14:51:23 freenas kernel: epair0a: promiscuous mode enabled
  294. May 11 14:51:23 freenas kernel: ng_ether_ifnet_arrival_event: can't re-name node epair0b
  295. May 11 14:51:23 freenas kernel: ng_ether_ifnet_arrival_event: can't re-name node epair0b
  296. May 11 14:51:24 freenas nmbd[2339]: STATUS=daemon 'nmbd' finished starting up and ready to serve connectionsPacket send failed to 192.168.1.255(137) ERRNO=No route to host
  297. May 11 14:51:24 freenas nmbd[2339]: [2015/05/11 14:51:24.290269, 0] ../source3/nmbd/nmbd_packets.c:1638(retransmit_or_expire_response_records)
  298. May 11 14:51:24 freenas nmbd[2339]: retransmit_or_expire_response_records: Failed to resend packet id 9449 to IP 192.168.1.255 on subnet 192.168.1.197
  299. May 11 14:51:24 freenas ntpd[2082]: sendto(66.228.42.59) (fd=22): No route to host
  300. May 11 14:51:25 freenas nmbd[2339]: [2015/05/11 14:51:25.290769, 0] ../source3/libsmb/nmblib.c:873(send_udp)
  301. May 11 14:51:25 freenas nmbd[2339]: Packet send failed to 192.168.1.255(137) ERRNO=No route to host
  302. May 11 14:51:25 freenas nmbd[2339]: [2015/05/11 14:51:25.290850, 0] ../source3/nmbd/nmbd_packets.c:1638(retransmit_or_expire_response_records)
  303. May 11 14:51:25 freenas nmbd[2339]: retransmit_or_expire_response_records: Failed to resend packet id 9449 to IP 192.168.1.255 on subnet 192.168.1.197
  304. May 11 14:51:25 freenas kernel: re0: link state changed to UP
  305. May 11 14:51:25 freenas kernel: re0: link state changed to UP
  306. May 11 14:51:30 freenas nmbd[2339]: [2015/05/11 14:51:30.295971, 0] ../source3/nmbd/nmbd_become_lmb.c:397(become_local_master_stage2)
  307. May 11 14:51:30 freenas nmbd[2339]:
  308. May 11 14:51:30 freenas nmbd[2339]: Samba name server FREENAS is now a local master browser for workgroup WORKGROUP on subnet 192.168.1.197
  309. May 11 14:51:30 freenas nmbd[2339]: *****
  310. May 11 14:51:30 freenas epair1a: Ethernet address: 02:f9:40:00:0d:0a
  311. May 11 14:51:30 freenas epair1b: Ethernet address: 02:f9:40:00:0e:0b
  312. May 11 14:51:30 freenas kernel: epair1a: link state changed to UP
  313. May 11 14:51:30 freenas kernel: epair1a: link state changed to UP
  314. May 11 14:51:30 freenas kernel: epair1b: link state changed to UP
  315. May 11 14:51:30 freenas kernel: epair1b: link state changed to UP
  316. May 11 14:51:30 freenas kernel: epair1a: promiscuous mode enabled
  317. May 11 14:51:30 freenas kernel: ng_ether_ifnet_arrival_event: can't re-name node epair1b
  318. May 11 14:51:30 freenas kernel: ng_ether_ifnet_arrival_event: can't re-name node epair1b
  319. May 11 14:51:36 freenas epair2a: Ethernet address: 02:88:c3:00:0e:0a
  320. May 11 14:51:36 freenas epair2b: Ethernet address: 02:88:c3:00:0f:0b
  321. May 11 14:51:36 freenas kernel: epair2a: link state changed to UP
  322. May 11 14:51:36 freenas kernel: epair2a: link state changed to UP
  323. May 11 14:51:36 freenas kernel: epair2b: link state changed to UP
  324. May 11 14:51:36 freenas kernel: epair2b: link state changed to UP
  325. May 11 14:51:36 freenas kernel: epair2a: promiscuous mode enabled
  326. May 11 14:51:36 freenas kernel: ng_ether_ifnet_arrival_event: can't re-name node epair2b
  327. May 11 14:51:36 freenas kernel: ng_ether_ifnet_arrival_event: can't re-name node epair2b
  328. May 11 14:51:42 freenas manage.py: [freeadmin.navtree:604] An error occurred while unserializing from http://192.168.1.197:81/plugins/owncloud/5/_s/treemenu: No JSON object could be decoded
  329. May 11 14:51:46 freenas epair3a: Ethernet address: 02:76:40:00:0f:0a
  330. May 11 14:51:46 freenas epair3b: Ethernet address: 02:76:40:00:10:0b
  331. May 11 14:51:46 freenas kernel: epair3a: link state changed to UP
  332. May 11 14:51:46 freenas kernel: epair3a: link state changed to UP
  333. May 11 14:51:46 freenas kernel: epair3b: link state changed to UP
  334. May 11 14:51:46 freenas kernel: epair3b: link state changed to UP
  335. May 11 14:51:46 freenas kernel: epair3a: promiscuous mode enabled
  336. May 11 14:51:46 freenas kernel: ng_ether_ifnet_arrival_event: can't re-name node epair3b
  337. May 11 14:51:46 freenas kernel: ng_ether_ifnet_arrival_event: can't re-name node epair3b
  338. May 11 14:51:51 freenas epair4a: Ethernet address: 02:05:2b:00:10:0a
  339. May 11 14:51:51 freenas epair4b: Ethernet address: 02:05:2b:00:11:0b
  340. May 11 14:51:51 freenas kernel: epair4a: link state changed to UP
  341. May 11 14:51:51 freenas kernel: epair4a: link state changed to UP
  342. May 11 14:51:51 freenas kernel: epair4b: link state changed to UP
  343. May 11 14:51:51 freenas kernel: epair4b: link state changed to UP
  344. May 11 14:51:51 freenas kernel: epair4a: promiscuous mode enabled
  345. May 11 14:51:51 freenas kernel: ng_ether_ifnet_arrival_event: can't re-name node epair4b
  346. May 11 14:51:51 freenas kernel: ng_ether_ifnet_arrival_event: can't re-name node epair4b
  347. May 11 14:52:13 freenas dhclient: New IP Address (re0): 192.168.1.197
  348. May 11 14:52:13 freenas dhclient: New Subnet Mask (re0): 255.255.255.0
  349. May 11 14:52:13 freenas dhclient: New Broadcast Address (re0): 192.168.1.255
  350. May 11 14:52:13 freenas dhclient: New Routers (re0): 192.168.1.1
  351. May 11 14:52:13 freenas kernel: arp: 192.168.1.197 moved from 02:88:c3:00:0e:0a to 20:cf:30:07:b6:ac on epair2b
  352. May 11 14:52:13 freenas kernel: arp: 192.168.1.197 moved from 02:f9:40:00:0d:0a to 20:cf:30:07:b6:ac on epair1b
  353. May 11 14:52:13 freenas kernel: arp: 192.168.1.197 moved from 02:e3:fb:00:0c:0a to 20:cf:30:07:b6:ac on epair0b
  354. May 11 15:15:03 freenas smbd[32540]: STATUS=daemon 'smbd' finished starting up and ready to serve connectionsget_ea_dos_attribute: Cannot get attribute from EA on file ./..: Error = Operation not supported

Freenas Ahci Time Out On Slots

I'm sorry, but Marvell SE9230 controller there does have multiple issues. Marvell implemented in it some firmware RAID, but same time seems neglected proper general AHCI operation in many ways. We are trying to avoid of those SATA ports for anything other then simple booting. SAS 6/12Gig and AHCI SATA 6Gig are great for HDDs and are still acceptable for for SSDs, but they are nowhere near as optimized and future proof as NVMe. Here's a thought, until there's a way to correlate nvdX to nvmeX devices, why not simply enumerate all present 'nvmeX' devices and add entries to smartd for those regardless of the exported. Other Kernel: ahcich: Timeout in slot. Thread starter WCSN; Start. Please post the contents of /var/run/dmesg.boot so we can see what AHCI controller is used. Also, the 'slot 24' and 'slot 15' make me think there might be a port multiplier in there somewhere. Remember seeing some issues with that JMicron chipset/controller on a FreeBSD.