Project

General

Profile

Bug #66927

Virtualized FreeNAS 11.2 ESXi 6.0 - vmkernel.log full of vscsi Invalid Opcode messages

Added by Andy Lahtinen almost 2 years ago. Updated over 1 year ago.

Status:
Done
Priority:
No priority
Assignee:
Vladimir Vinogradenko
Category:
Middleware
Seen in:
Severity:
New
Reason for Closing:
Reason for Blocked:
Needs QA:
No
Needs Doc:
No
Needs Merging:
No
Needs Automation:
No
Support Suite Ticket:
n/a
Hardware Configuration:
ChangeLog Required:
No

Description

Hi Team,

I have been running FreeNAS as a VM in ESXi 6.0 for years and it has been flawless. Recently, I upgraded to 11.2 and just discovered new messages showing up in the vmkernel.log of the host every 5 minutes that were not present in 11.1. The SCSI devices it is referring to are .VMDK disks used for Boot and Jails storage. There are no error messages seen to any of the HDD disks connected to the PCI Passthrough Controller (zpool).

2019-01-02T13:00:13.831Z cpu4:35434)VSCSIFs: 2235: handle 8194(vscsi1:0):Invalid Opcode (0x4d) from (vmm0:FreeNAS-11)
2019-01-02T13:00:13.831Z cpu7:35433)VSCSIFs: 2235: handle 8195(vscsi1:1):Invalid Opcode (0xb7) from (vmm0:FreeNAS-11)
2019-01-02T13:00:13.831Z cpu4:35434)VSCSIFs: 2235: handle 8194(vscsi1:0):Invalid Opcode (0xb7) from (vmm0:FreeNAS-11)
2019-01-02T13:00:13.831Z cpu10:35431)VSCSIFs: 2235: handle 8195(vscsi1:1):Invalid Opcode (0x37) from (vmm0:FreeNAS-11)
2019-01-02T13:00:13.831Z cpu7:35433)VSCSIFs: 2235: handle 8194(vscsi1:0):Invalid Opcode (0x37) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.820Z cpu11:35433)VSCSIFs: 2235: handle 8195(vscsi1:1):Invalid Opcode (0x4d) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.820Z cpu11:35433)VSCSIFs: 2235: handle 8195(vscsi1:1):Invalid Opcode (0x4d) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.820Z cpu11:35433)VSCSIFs: 2235: handle 8194(vscsi1:0):Invalid Opcode (0x4d) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.820Z cpu1:35434)VSCSIFs: 2235: handle 8194(vscsi1:0):Invalid Opcode (0x4d) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.820Z cpu1:35434)VSCSIFs: 2235: handle 8195(vscsi1:1):Invalid Opcode (0xb7) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.820Z cpu1:35434)VSCSIFs: 2235: handle 8194(vscsi1:0):Invalid Opcode (0xb7) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.820Z cpu1:35434)VSCSIFs: 2235: handle 8195(vscsi1:1):Invalid Opcode (0x37) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.820Z cpu1:35434)VSCSIFs: 2235: handle 8194(vscsi1:0):Invalid Opcode (0x37) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.824Z cpu11:35433)VSCSIFs: 2235: handle 8193(vscsi0:0):Invalid Opcode (0x4d) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.824Z cpu7:35435)VSCSIFs: 2235: handle 8193(vscsi0:0):Invalid Opcode (0x4d) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.824Z cpu7:35435)VSCSIFs: 2235: handle 8193(vscsi0:0):Invalid Opcode (0xb7) from (vmm0:FreeNAS-11)
2019-01-02T13:05:13.824Z cpu7:35435)VSCSIFs: 2235: handle 8193(vscsi0:0):Invalid Opcode (0x37) from (vmm0:FreeNAS-11)
2019-01-02T13:10:13.824Z cpu10:35434)VSCSIFs: 2235: handle 8194(vscsi1:0):Invalid Opcode (0x4d) from (vmm0:FreeNAS-11)
2019-01-02T13:10:13.824Z cpu10:35434)VSCSIFs: 2235: handle 8194(vscsi1:0):Invalid Opcode (0x4d) from (vmm0:FreeNAS-11)
2019-01-02T13:10:13.824Z cpu6:35433)VSCSIFs: 2235: handle 8193(vscsi0:0):Invalid Opcode (0x4d) from (vmm0:FreeNAS-11)

Looking at the SCSI commands, they include 'Log Sense' and 'Read Defect Data'. Most likely, these commands are not supported by the VMDK virtual disks and throw this message instead. Curious as I had not seen this before on any previous version of FreeNAS.

Also note, SMART is disabled for these VMDK devices but is enabled for the HDD connected to the PCI Passthrough controller.

We have also started chatting about it - https://forums.freenas.org/index.ph...-to-a-pool-every-5-minutes.70574/#post-500044

and -

https://forums.freenas.org/index.php?threads/virtualized-freenas-11-2-esxi-6-0-vmkernel-log-full-of-vscsi-invalid-opcode-messages.72206/#post-501751

As I understand it, there is little to no impact from these messages but I am still puzzled as I hadn't seen any of these in previous versions. Is there anything that can be done to avoid sending these SCSI Commands to VMDK disks? Were there any changes made on this topic from the previous version 11.1?


Related issues

Copied to FreeNAS - Bug #76531: Do not poll for temperature on drives with SMART disabledDone

History

#1 Updated by Dru Lavigne almost 2 years ago

  • Private changed from No to Yes
  • Reason for Blocked set to Need additional information from Author

Andy: please attach a debug (System -> Advanced -> Save debug) to this ticket.

#2 Updated by Andy Lahtinen almost 2 years ago

  • File debug-freenas-20190103091034.tgz added

Thanks for taking a look. Here is the requested debug tgz.

#3 Updated by Dru Lavigne almost 2 years ago

  • Assignee changed from Release Council to Alexander Motin
  • Reason for Blocked deleted (Need additional information from Author)

#4 Updated by Alexander Motin almost 2 years ago

  • Category changed from OS to Middleware
  • Assignee changed from Alexander Motin to William Grzybowski

I agree that those commands are likely related to SMART. I don't see a reason why VMware would log them as errors, since for SCSI it is generally normal to report that some command is not supported, unlike ATA, where IDENTIFY data provide all information about drive capabilities and errors like that should be avoided completely.

I don't see what can we do here on the OS side, so I am pushing this to middleware team to check whether we are respecting UI SMART settings and not sending SMART requests when requested not to.

#5 Updated by William Grzybowski almost 2 years ago

  • Assignee changed from William Grzybowski to Vladimir Vinogradenko

#6 Updated by Bug Clerk over 1 year ago

  • Status changed from Unscreened to In Progress

#7 Updated by Bug Clerk over 1 year ago

  • Status changed from In Progress to Ready for Testing

#8 Updated by Bug Clerk over 1 year ago

  • Target version changed from Backlog to 11.3-BETA1

#9 Updated by Bug Clerk over 1 year ago

  • Copied to Bug #76531: Do not poll for temperature on drives with SMART disabled added

#10 Updated by Dru Lavigne over 1 year ago

  • File deleted (debug-freenas-20190103091034.tgz)

#11 Updated by Dru Lavigne over 1 year ago

  • Status changed from Ready for Testing to Done
  • Target version changed from 11.3-BETA1 to Master - FreeNAS Nightlies
  • Private changed from Yes to No
  • Needs QA changed from Yes to No
  • Needs Doc changed from Yes to No
  • Needs Merging changed from Yes to No

Also available in: Atom PDF