This discussion is archived
11 Replies Latest reply: Jul 23, 2010 1:32 AM by 807567 RSS

Daily Messages relating to (invalid field in cdb)

807567 Newbie
Currently Being Moderated
Hello all,

I am investigating a set of messages that occur at the same time every day. See excerpt below. They occur at 9:41 everyday and are shown in the oldest messages file which go as far back as May 1st. Is there anyway to find out what is causing these messages? The server is a Sun-Fire V440 running Solaris 9 with c1t0d0 and c1t1d0 hardware raided. I was not a part of the original setup so I do not have much details on how the initial configurations went. I have searched the net and found that the ASC:0x24 basically indicates an illegal request was sent to the device and is of no harm, but I want to know why they occur at the same time every day. Any help will be greatly appreciated. Thanks

May 29 09:41:15 servername scsi: [ID 107833 kern.warning] WARNING: /pci@1f,700000/scsi@2/sd@0,0 (sd1):
May 29 09:41:15 servername      Error for Command: inquiry Error Level: Informational
May 29 09:41:15 servername scsi: [ID 107833 kern.notice]      Requested Block: 0 Error Block: 0ear
May 29 09:41:15 servername scsi: [ID 107833 kern.notice]      Vendor: LSILOGIC Serial Number: LSI INTERNAL
May 29 09:41:15 servername scsi: [ID 107833 kern.notice]      Sense Key: Illegal Request
May 29 09:41:15 servername scsi: [ID 107833 kern.notice]      ASC: 0x24 (invalid field in cdb), ASCQ: 0x0, FRU: 0x0
May 30 09:41:16 servername scsi: [ID 107833 kern.warning] WARNING: /pci@1f,700000/scsi@2/sd@0,0 (sd1):
May 30 09:41:16 servername      Error for Command: inquiry Error Level: Informational
May 30 09:41:16 servername scsi: [ID 107833 kern.notice]      Requested Block: 0 Error Block: 0
May 30 09:41:16 servername scsi: [ID 107833 kern.notice]      Vendor: LSILOGIC Serial Number: LSI INTERNAL
May 30 09:41:16 servername scsi: [ID 107833 kern.notice]      Sense Key: Illegal Request
May 30 09:41:16 servername scsi: [ID 107833 kern.notice]      ASC: 0x24 (invalid field in cdb), ASCQ: 0x0, FRU: 0x0
May 31 09:41:16 servername scsi: [ID 107833 kern.warning] WARNING: /pci@1f,700000/scsi@2/sd@0,0 (sd1):
May 31 09:41:16 servername      Error for Command: inquiry Error Level: Informational
May 31 09:41:16 servername scsi: [ID 107833 kern.notice]      Requested Block: 0 Error Block: 0
May 31 09:41:16 servername scsi: [ID 107833 kern.notice]      Vendor: LSILOGIC Serial Number: LSI INTERNAL
May 31 09:41:16 servername scsi: [ID 107833 kern.notice]      Sense Key: Illegal Request
May 31 09:41:16 servername scsi: [ID 107833 kern.notice]      ASC: 0x24 (invalid field in cdb), ASCQ: 0x0, FRU: 0x0
  • 1. Re: Daily Messages relating to (invalid field in cdb)
    807567 Newbie
    Currently Being Moderated
    For something like that, I'd start with the cron tables and see if there is some script that runs at that time.

    'cdb' stands for command description block. I'm hazarding a guess here, but it looks like something is sending a NULL or zero values that happens to align to the cdb field of your driver code. Fortunately your driver just shrugs them off. Probably it's the hardware LSI card driver sending a bogus value to the scsi driver.
  • 2. Re: Daily Messages relating to (invalid field in cdb)
    807567 Newbie
    Currently Being Moderated
    Hi Michael,
    Thanks for your reply, I did check the cron and found nothing scheduled for even near that time. Closest time was at 5am in the morning. From the ps -ef output I am seeing an iostat -x 15 99999 and some vmstat processes which I am not sure why they are there. I am not sure if that might have anything to do with it. It happened again today 9:41:16 exactly as in most previous cases.
  • 3. Re: Daily Messages relating to (invalid field in cdb)
    807567 Newbie
    Currently Being Moderated
    I managed to obtain some old explorers for the server (from 2007 and 2008) and it seems the messages occurred once a day back then as well. The times were different from now but they are coherent as well.
  • 4. Re: Daily Messages relating to (invalid field in cdb)
    807567 Newbie
    Currently Being Moderated
    Well, the iostat process is puzzling...it will produce a standard iostat report every fifteen seconds for one less than 100k iterations. Maybe you can run ptree on that PID and see where it comes from? Same with the vmstat. I can't think of a (very) good reason to run those monitoring tools all the time.

    But that's also a good hint you've got other scripts that might be going off in the system, perhaps using its own timing mechanism. There's not a whole lot you can do on Solaris 9 that is simple, lightweight and helpful to identify what's evoking that message. Or at least I have a hard time remembering a good way to attack such an issue that isn't brute-force in approach: with DTrace on Solaris 10, it's gotten easy to forget the hard way to investigate such things.

    For starters, you could run prstat -a to see who the active (non-root) users are, then check their home directories for a cache of "special" scripts.

    You might also ptree the vmstat/iostat PIDs in hopes of finding an underlying script. Possibly the script resides in a directory common to some special toolkit that's been put on the system. Maybe your culprit also resides there.

    Another thing to try: start running prstat -c 1 >> some_file at 9:41 for 20 seconds and see if you get lucky and trap an unusual process or two.

    These approaches are a bit on the clumsy side but they don't require much work either.
  • 5. Re: Daily Messages relating to (invalid field in cdb)
    807567 Newbie
    Currently Being Moderated
    Well from the old explorers I am inclined to think maybe its something else and not processes. Maybe what you said about the LSI card drivers sending bad values to the scsi drivers. From the old explorers also there was no iostat or vmstat or anything that looks suspicious in the process list. I am inclined to believe these messages existed since installation of the server.

    Dec 26 15:05:06 servername scsi: [ID 107833 kern.warning] WARNING: /pci@1f,700000/scsi@2/sd@0,0 (sd1):
    Dec 26 15:05:06 servername Error for Command: inquiry Error Level: Informational
    Dec 26 15:05:06 servername scsi: [ID 107833 kern.notice] Requested Block: 0 Error Block: 0
    Dec 26 15:05:06 servername scsi: [ID 107833 kern.notice] Vendor: LSILOGIC Serial Number: LSI INTERNAL
    Dec 26 15:05:06 servername scsi: [ID 107833 kern.notice] Sense Key: Illegal Request
    Dec 26 15:05:06 servername scsi: [ID 107833 kern.notice] ASC: 0x24 (invalid field in cdb), ASCQ: 0x0, FRU: 0x0
    Dec 27 15:05:07 servername scsi: [ID 107833 kern.warning] WARNING: /pci@1f,700000/scsi@2/sd@0,0 (sd1):
    Dec 27 15:05:07 servername Error for Command: inquiry Error Level: Informational
    Dec 27 15:05:07 servername scsi: [ID 107833 kern.notice] Requested Block: 0 Error Block: 0
    Dec 27 15:05:07 servername scsi: [ID 107833 kern.notice] Vendor: LSILOGIC Serial Number: LSI INTERNAL
    Dec 27 15:05:07 servername scsi: [ID 107833 kern.notice] Sense Key: Illegal Request
    Dec 27 15:05:07 servername scsi: [ID 107833 kern.notice] ASC: 0x24 (invalid field in cdb), ASCQ: 0x0, FRU: 0x0
    Dec 28 15:05:06 servername scsi: [ID 107833 kern.warning] WARNING: /pci@1f,700000/scsi@2/sd@0,0 (sd1):
    Dec 28 15:05:06 servername Error for Command: inquiry Error Level: Informational
    Dec 28 15:05:06 servername scsi: [ID 107833 kern.notice] Requested Block: 0 Error Block: 0
    Dec 28 15:05:06 servername scsi: [ID 107833 kern.notice] Vendor: LSILOGIC Serial Number: LSI INTERNAL
    Dec 28 15:05:06 servername scsi: [ID 107833 kern.notice] Sense Key: Illegal Request
    Dec 28 15:05:06 servername scsi: [ID 107833 kern.notice] ASC: 0x24 (invalid field in cdb), ASCQ: 0x0, FRU: 0x0
  • 6. Re: Daily Messages relating to (invalid field in cdb)
    807567 Newbie
    Currently Being Moderated
    Perhaps the data passed by the LSI card to scsi inquiry is off. But the 24-hour cycle thing...hm. I presume the HW RAID card has an on-board battery and TOD chip? Is it programmable?
  • 7. Re: Daily Messages relating to (invalid field in cdb)
    807567 Newbie
    Currently Being Moderated
    The precise timing everyday is indeed peculiar. I'm afraid I don't know how to verify the TOD chip and if its programmable. Is there anyway that can be done from the OS level?
  • 8. Re: Daily Messages relating to (invalid field in cdb)
    807567 Newbie
    Currently Being Moderated
    Maybe. I didn't expect to find much googling around, but I did find this:

    http://docs.sun.com/source/820-4922-15/chapter9.html

    So maybe there's a raidctl program on the system that allows you some controls to the HW RAID thing?
  • 9. Re: Daily Messages relating to (invalid field in cdb)
    807567 Newbie
    Currently Being Moderated
    I've put this case down for the time being as it does not seem to have any adverse effects on the server. Thanks for all your help Michael. I'll be doing some further investigations from time to time whenever I get some time as I'm curious about the 24 hrs cycle
  • 10. Re: Daily Messages relating to (invalid field in cdb)
    807567 Newbie
    Currently Being Moderated
    [thanks for your information ,i had the same problem , now i know how to do ,!|http://www.highwaytowatches.com]
  • 11. Re: Daily Messages relating to (invalid field in cdb)
    807567 Newbie
    Currently Being Moderated
    Best guess is a application on the host is sending a scsi command to the lsi device which it does not understand. Check cron to determine if anything is set to run at the same time. Is there any management software installed on the host which is probing devices? If it was Solaris 10 would be easy to determine what using dtrace.