OPNsense Forum

English Forums => Hardware and Performance => Topic started by: bob@afrinet.eu on June 20, 2018, 01:01:42 pm

Title: Impossible to boot from USB Key : "CAM status: Command timeout"
Post by: bob@afrinet.eu on June 20, 2018, 01:01:42 pm
I was trying to install OPNSense on a box and bumped into this problem :

Quote
Booting...                                                                     
KDB: debugger backends: ddb                                                     
KDB: current backend: ddb                                                       
Copyright (c) 1992-2017 The FreeBSD Project.                                   
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994       
        The Regents of the University of California. All rights reserved.       
FreeBSD is a registered trademark of The FreeBSD Foundation.                   
FreeBSD 11.1-RELEASE-p9  e86703e30(stable/18.1) amd64                           
FreeBSD clang version 4.0.0 (tags/RELEASE_400/final 297347) (based on LLVM 4.0.)
VT(vga): resolution 640x480                                                     
[HBSD LOG] logging to system: enabled                                           
[HBSD LOG] logging to user: disabled                                           
[HBSD HARDENING] procfs hardening: enabled                                     
[HBSD ASLR] status: opt-out                                                     
[HBSD ASLR] mmap: 30 bit                                                       
[HBSD ASLR] exec base: 30 bit                                                   
[HBSD ASLR] stack: 42 bit                                                       
[HBSD ASLR] vdso: 28 bit                                                       
[HBSD ASLR] map32bit: 18 bit                                                   
[HBSD ASLR] disallow MAP_32BIT mode mmap: opt-in                               
[HBSD ASLR (compat)] status: opt-out                                           
[HBSD ASLR (compat)] mmap: 14 bit                                               
[HBSD ASLR (compat)] exec base: 14 bit                                         
[HBSD ASLR (compat)] stack: 14 bit                                             
[HBSD ASLR (compat)] vdso: 8 bit                                               
[HBSD SEGVGUARD] status: opt-out                                               
[HBSD SEGVGUARD] expiry: 120 sec                                               
[HBSD SEGVGUARD] suspension: 600 sec                                           
[HBSD SEGVGUARD] maxcrashes: 5                                                 
CPU: Intel(R) Atom(TM) CPU C3558 @ 2.20GHz (2200.07-MHz K8-class CPU)           
  Origin="GenuineIntel"  Id=0x506f1  Family=0x6  Model=0x5f  Stepping=1         
  Features=0xbfebfbff<FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,>
  Features2=0x4ff8ebbf<SSE3,PCLMULQDQ,DTES64,MON,DS_CPL,VMX,EST,TM2,SSSE3,SDBG,>
  AMD Features=0x2c100800<SYSCALL,NX,Page1GB,RDTSCP,LM>                         
  AMD Features2=0x101<LAHF,Prefetch>                                           
  Structured Extended Features=0x2294e283<FSGSBASE,TSCADJ,SMEP,ERMS,NFPUSG,MPX,>
  Structured Extended Features3=0x2c000000<IBPB,STIBP,ARCH_CAP>                 
  XSAVE Features=0xf<XSAVEOPT,XSAVEC,XINUSE,XSAVES>                             
  IA32_ARCH_CAPS=0x1<RDCL_NO>                                                   
  VT-x: PAT,HLT,MTF,PAUSE,EPT,UG,VPID,VID,PostIntr                             
  TSC: P-state invariant, performance statistics                               
real memory  = 8589934592 (8192 MB)                                             
avail memory = 8187076608 (7807 MB)                                             
Event timer "LAPIC" quality 600                                                 
ACPI APIC Table: <INTEL  TIANO   >                                             
WARNING: L1 data cache covers less APIC IDs than a core                         
0 < 1                                                                           
FreeBSD/SMP: Multiprocessor System Detected: 4 CPUs                             
FreeBSD/SMP: 1 package(s) x 4 core(s)                                           
random: unblocking device.                                                     
ioapic0 <Version 2.0> irqs 0-23 on motherboard                                 
SMP: AP CPU #1 Launched!                                                       
SMP: AP CPU #2 Launched!                                                       
SMP: AP CPU #3 Launched!                                                       
Timecounter "TSC-low" frequency 1100035729 Hz quality 1000                     
random: entropy device external interface                                       
wlan: mac acl policy registered                                                 
netmap: loaded module                                                           
module_register_init: MOD_LOAD (vesa, 0xffffffff810ab110, 0) error 19           
random: registering fast source Intel Secure Key RNG                           
random: fast provider: "Intel Secure Key RNG"                                   
kbd1 at kbdmux0                                                                 
nexus0                                                                         
vtvga0: <VT VGA driver> on motherboard                                         
cryptosoft0: <software crypto> on motherboard                                   
acpi0: <ALASKA A M I > on motherboard                                           
acpi0: Power Button (fixed)                                                     
cpu0: <ACPI CPU> on acpi0                                                       
cpu1: <ACPI CPU> on acpi0                                                       
cpu2: <ACPI CPU> on acpi0                                                       
cpu3: <ACPI CPU> on acpi0                                                       
hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff on acpi0       
Timecounter "HPET" frequency 24000000 Hz quality 950                           
Event timer "HPET" frequency 24000000 Hz quality 550                           
Event timer "HPET1" frequency 24000000 Hz quality 440                           
Event timer "HPET2" frequency 24000000 Hz quality 440                           
Event timer "HPET3" frequency 24000000 Hz quality 440                           
Event timer "HPET4" frequency 24000000 Hz quality 440                           
atrtc0: <AT realtime clock> port 0x70-0x77 irq 8 on acpi0                       
atrtc0: Warning: Couldn't map I/O.                                             
Event timer "RTC" frequency 32768 Hz quality 0                                 
attimer0: <AT timer> port 0x40-0x43,0x50-0x53 irq 0 on acpi0                   
Timecounter "i8254" frequency 1193182 Hz quality 0                             
Event timer "i8254" frequency 1193182 Hz quality 100                           
Timecounter "ACPI-fast" frequency 3579545 Hz quality 900                       
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1808-0x180b on acpi0         
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff on acpi0                         
pcib0: _OSC returned error 0x10                                                 
pci0: <ACPI PCI bus> on pcib0                                                   
pcib1: <ACPI PCI-PCI bridge> at device 6.0 on pci0                             
pci1: <ACPI PCI bus> on pcib1                                                   
pci1: <processor> at device 0.0 (no driver attached)                           
pcib2: <ACPI PCI-PCI bridge> mem 0xdff60000-0xdff7ffff irq 20 at device 14.0 on0
pci2: <ACPI PCI bus> on pcib2                                                   
pcib3: <ACPI PCI-PCI bridge> mem 0xdff40000-0xdff5ffff irq 21 at device 15.0 on0
pci3: <ACPI PCI bus> on pcib3                                                   
igb0: <Intel(R) PRO/1000 Network Connection, Version - 2.5.3-k> port 0xd000-0xd3
igb0: Using MSIX interrupts with 5 vectors                                     
igb0: Ethernet address: 00:90:00:00:00:01                                       
igb0: Bound queue 0 to cpu 0                                                   
igb0: Bound queue 1 to cpu 1                                                   
igb0: Bound queue 2 to cpu 2                                                   
igb0: Bound queue 3 to cpu 3                                                   
igb0: netmap queues/slots: TX 4/1024, RX 4/1024                                 
pcib4: <ACPI PCI-PCI bridge> mem 0xdff20000-0xdff3ffff irq 22 at device 16.0 on0
pci4: <ACPI PCI bus> on pcib4                                                   
igb1: <Intel(R) PRO/1000 Network Connection, Version - 2.5.3-k> port 0xc000-0xc4
igb1: Using MSIX interrupts with 5 vectors                                     
igb1: Ethernet address: 00:90:00:00:00:02                                       
igb1: Bound queue 0 to cpu 0                                                   
igb1: Bound queue 1 to cpu 1                                                   
igb1: Bound queue 2 to cpu 2                                                   
igb1: Bound queue 3 to cpu 3                                                   
igb1: netmap queues/slots: TX 4/1024, RX 4/1024                                 
pcib5: <ACPI PCI-PCI bridge> mem 0xdff00000-0xdff1ffff irq 23 at device 17.0 on0
pci5: <ACPI PCI bus> on pcib5                                                   
ahci0: <AHCI SATA controller> port 0xe0c0-0xe0c7,0xe0b0-0xe0b3,0xe040-0xe05f me0
ahci0: AHCI v1.31 with 1 6Gbps ports, Port Multiplier supported                 
ahcich0: <AHCI channel> at channel 0 on ahci0                                   
ahciem0: <AHCI enclosure management bridge> on ahci0                           
ahci1: <AHCI SATA controller> port 0xe0a0-0xe0a7,0xe090-0xe093,0xe020-0xe03f me0
ahci1: AHCI v1.31 with 1 6Gbps ports, Port Multiplier supported                 
ahcich8: <AHCI channel> at channel 7 on ahci1                                   
ahciem1: <AHCI enclosure management bridge> on ahci1                           
xhci0: <XHCI (generic) USB 3.0 controller> mem 0xdff80000-0xdff8ffff irq 19 at 0
xhci0: 32 bytes context size, 64-bit DMA                                       
usbus0 on xhci0                                                                 
usbus0: 5.0Gbps Super Speed USB v3.0                                           
pcib6: <ACPI PCI-PCI bridge> irq 16 at device 22.0 on pci0                     
pci6: <ACPI PCI bus> on pcib6                                                   
pci6: <network, ethernet> at device 0.0 (no driver attached)                   
pci6: <network, ethernet> at device 0.1 (no driver attached)                   
pcib7: <ACPI PCI-PCI bridge> at device 23.0 on pci0                             
pci7: <ACPI PCI bus> on pcib7                                                   
pci7: <network, ethernet> at device 0.0 (no driver attached)                   
pci7: <network, ethernet> at device 0.1 (no driver attached)                   
pci0: <simple comms> at device 24.0 (no driver attached)                       
pci0: <simple comms, UART> at device 26.0 (no driver attached)                 
pci0: <simple comms, UART> at device 26.1 (no driver attached)                 
pci0: <simple comms, UART> at device 26.2 (no driver attached)                 
isab0: <PCI-ISA bridge> at device 31.0 on pci0                                 
isa0: <ISA bus> on isab0                                                       
pci0: <memory> at device 31.2 (no driver attached)                             
pci0: <serial bus> at device 31.5 (no driver attached)                         
acpi_tz0: <Thermal Zone> on acpi0                                               
uart0: <16550 or compatible> port 0x3f8-0x3ff irq 7 flags 0x10 on acpi0         
uart0: console (115200,n,8,1)                                                   
uart1: <16550 or compatible> port 0x2f8-0x2ff irq 10 on acpi0                   
ppc0: cannot reserve I/O port range                                             
est0: <Enhanced SpeedStep Frequency Control> on cpu0                           
est: CPU supports Enhanced Speedstep, but is not recognized.                   
est: cpu_vendor GenuineIntel, msr 21eb00001600                                 
device_attach: est0 attach returned 6                                           
est1: <Enhanced SpeedStep Frequency Control> on cpu1                           
est: CPU supports Enhanced Speedstep, but is not recognized.                   
est: cpu_vendor GenuineIntel, msr 21eb00001600                                 
device_attach: est1 attach returned 6                                           
est2: <Enhanced SpeedStep Frequency Control> on cpu2                           
est: CPU supports Enhanced Speedstep, but is not recognized.                   
est: cpu_vendor GenuineIntel, msr 21eb00001600                                 
device_attach: est2 attach returned 6                                           
est3: <Enhanced SpeedStep Frequency Control> on cpu3                           
est: CPU supports Enhanced Speedstep, but is not recognized.                   
est: cpu_vendor GenuineIntel, msr 21eb00001600                                 
device_attach: est3 attach returned 6                                           
Timecounters tick every 1.000 msec                                             
nvme cam probe device init                                                     
ugen0.1: <0x8086 XHCI root HUB> at usbus0                                       
uhub0: <0x8086 XHCI root HUB, class 9/0, rev 3.00/1.00, addr 1> on usbus0       
uhub0: 8 ports with 8 removable, self powered                                   
ugen0.2: <UFD 3.0 Silicon-Power16G> at usbus0                                   
umass0 on uhub0                                                                 
umass0: <UFD 3.0 Silicon-Power16G, class 0/0, rev 3.00/11.00, addr 1> on usbus0
umass0:  SCSI over Bulk-Only; quirks = 0x4000                                   
umass0:4:0: Attached to scbus4                                                 
ahcich8: Timeout on slot 5 port 0                                               
ahcich8: is 00000002 cs 00000000 ss 00000000 rs 00000020 tfd 50 serr 00000000 c7
(aprobe0:ahcich8:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe0:ahcich8:0:0:0): CAM status: Command timeout                           
(aprobe0:ahcich8:0:0:0): Retrying command                                       
run_interrupt_driven_hooks: still waiting after 60 seconds for xpt_config       
ahcich8: Timeout on slot 6 port 0                                               
ahcich8: is 00000002 cs 00000000 ss 00000000 rs 00000040 tfd 50 serr 00000000 c7
(aprobe0:ahcich8:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe0:ahcich8:0:0:0): CAM status: Command timeout                           
(aprobe0:ahcich8:0:0:0): Error 5, Retries exhausted                             
ahcich8: Timeout on slot 11 port 0                                             
ahcich8: is 00000002 cs 00000000 ss 00000000 rs 00000800 tfd 50 serr 00000000 c7
(aprobe0:ahcich8:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe0:ahcich8:0:0:0): CAM status: Command timeout                           
(aprobe0:ahcich8:0:0:0): Retrying command                                       
run_interrupt_driven_hooks: still waiting after 120 seconds for xpt_config     
ahcich8: Timeout on slot 12 port 0                                             
ahcich8: is 00000002 cs 00000000 ss 00000000 rs 00001000 tfd 50 serr 00000000 c7
(aprobe0:ahcich8:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe0:ahcich8:0:0:0): CAM status: Command timeout                           
(aprobe0:ahcich8:0:0:0): Error 5, Retries exhausted                             
ses0 at ahciem0 bus 0 scbus1 target 0 lun 0                                     
ses0: <AHCI SGPIO Enclosure 1.00 0001> SEMB S-E-S 2.00 device                   
ses0: SEMB SES Device                                                           
ses1 at ahciem1 bus 0 scbus3 target 0 lun 0                                     
ses1: <AHCI SGPIO Enclosure 1.00 0001> SEMB S-E-S 2.00 device                   
ses1: SEMB SES Device                                                           
da0 at umass-sim0 bus 0 scbus4 target 0 lun 0                                   
da0: <UFD 3.0 Silicon-Power16G 1100> Removable Direct Access SPC-4 SCSI device 
da0: Serial Number P1503809737151200347                                         
da0: 400.000MB/s transfers                                                     
da0: 15376MB (31490048 512 byte sectors)                                       
da0: quirks=0x2<NO_6_BYTE>                                                     
Trying to mount root from ufs:/dev/ufs/OPNsense_Install [ro,noatime]...         
Mounting filesysahcich8: Timeout on slot 16 port 0                             
ahcich8: is 00000002 cs 00000000 ss 00000000 rs 00010000 tfd 50 serr 00000000 c7
(aprobe0:ahcich8:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe0:ahcich8:0:0:0): CAM status: Command timeout                           
(aprobe0:ahcich8:0:0:0): Error 5, Retries exhausted 


Then system endlessly loops into :

Quote
Trying to mount root from ufs:/dev/ufs/OPNsense_Install [ro,noatime]...         
Mounting filesysahcich0: Timeout on slot 16 port 0                             
ahcich0: is 00000002 cs 00000000 ss 00000000 rs 00010000 tfd 50 serr 00000000 c7
(aprobe0:ahcich0:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe0:ahcich0:0:0:0): CAM status: Command timeout                           
(aprobe0:ahcich0:0:0:0): Error 5, Retries exhausted
 

I am not really sure what to try from there on… ??

Title: Re: Impossible to boot from USB Key : "CAM status: Command timeout"
Post by: marjohn56 on June 20, 2018, 02:29:59 pm
What device are you installing on?
Title: Re: Impossible to boot from USB Key : "CAM status: Command timeout"
Post by: bob@afrinet.eu on June 20, 2018, 03:44:48 pm
    Intel® Atom™ C3758, C3558 (Denverton)
    4x GbE RJ45 Intel® SoC Integrated MAC and 2x GbE SFP or 2x RJ45 Intel® i210
    1x 204-pin SODIMM, DDR4 2400MHz ECC/Non-ECC DIMM, Max. 16GB
    Intel® AES-NI Support
    1x Mini USB Console, 2x USB 3.0, 1x 2.5” HDD/SSD Bay, 1x Onboard EMMC 8GB (BIOS deactivated)
    1x Mini-PCIe (PCIe), 1x M.2 (USB3.0/SATA)


FreeBSD 11.2-RC3 boots like a charm !

So there is an obvious bug in FreeBSD 11.1 because It does not boot either on 11.1
Maybe there is a back-port on 11.1 of the USB device driver (AHCI) ?
Title: Re: Impossible to boot from USB Key : "CAM status: Command timeout"
Post by: marjohn56 on June 20, 2018, 03:48:37 pm
Some drivers have been back-ported for releases 18.7.1.  I don't know which ones though and that does not help you right now.
Title: Re: Impossible to boot from USB Key : "CAM status: Command timeout"
Post by: bob@afrinet.eu on June 20, 2018, 04:20:27 pm
Might be related to this :

o An issue where some Intel SDHCI/eMMC controllers can fail on the first
  attempt after a D3 to D0 transition has been fixed.

https://www.freebsdnews.com/2017/07/18/freebsd-11-1-rc1/

Not 100% sure though.
Title: Re: Impossible to boot from USB Key : "CAM status: Command timeout"
Post by: bob@afrinet.eu on June 20, 2018, 06:17:52 pm
I have nailed down the problem and it is related to the denverton driver.
This is what I have in the boot on FreeBSD 11.2-RC3

Quote
ahcich8: <AHCI channel> at channel 7 on ahci1                                   
ahciem1: <AHCI enclosure management bridge> on ahci1                           
xhci0: <Intel Denverton USB 3.0 controller> mem 0xdff80000-0xdff8ffff irq 19 at
device 21.0 on pci0                                                             
xhci0: 32 bytes context size, 64-bit DMA

This has to be compared with the boot on OPNSense where I have :

Quote
umass0:4:0: Attached to scbus4                                                 
ahcich8: Timeout on slot 5 port 0                                               
ahcich8: is 00000002 cs 00000000 ss 00000000 rs 00000020 tfd 50 serr 00000000 c7
(aprobe0:ahcich8:0:0:0): ATA_IDENTIFY. ACB: ec 00 00 00 00 40 00 00 00 00 00 00
(aprobe0:ahcich8:0:0:0): CAM status: Command timeout                           
(aprobe0:ahcich8:0:0:0): Retrying command                                       
run_interrupt_driven_hooks: still waiting after 60 seconds for xpt_config       


So the problem is clearly related to the "AHCI enclosure management bridge"

Can anyone tell me if this will be upgraded as part of the 18.7 Release ?

 
Title: Re: Impossible to boot from USB Key : "CAM status: Command timeout"
Post by: opnsenseuser on July 07, 2018, 10:08:16 am
i get the same error.

Strangely, the first installation worked. After about 3 reboots came then this error.

Now i can´t even boot opnsense from harddisc too.

i´m using atom c3558

I was already looking forward to 18.7, because I thought that with it, the atom c3000 works. Pity!
Title: Re: Impossible to boot from USB Key : "CAM status: Command timeout"
Post by: opnsenseuser on July 08, 2018, 04:06:12 pm
by the way...

i´m using a m.2 ssd
Title: Re: Impossible to boot from USB Key : "CAM status: Command timeout"
Post by: Jacob_B on August 02, 2018, 07:35:52 pm
I am also having this issue. Is there a supported/unsupported fix or timeline for getting this hardware working? SYS-E200-9A with onboard m.2. 18.7 drivers seem to detect the NICs but not the storage.
Title: Re: Impossible to boot from USB Key : "CAM status: Command timeout"
Post by: franco on August 03, 2018, 09:57:15 am
We do not have all the Denverton backports in 18.7 as we are still on FreeBSD 11.1.

https://github.com/opnsense/core/issues/2473

We'll begin working on FreeBSD 11.2 shortly.


Cheers,
Franco
Title: Re: Impossible to boot from USB Key : "CAM status: Command timeout"
Post by: spants on August 21, 2018, 04:10:42 pm
It is probably unrelated but I had a similar problem with  ASRock J3455B motherboard.
I had to use the following to boot:

Set hint.hpet.0.clock = 0    <---- you might not need this one
Set hint.ahci.0.msi = 2
Set hint.ahci.1.msi = 2