GNU bug report logs - #51407
parted didn’t check the returned sense data

Previous Next

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 51407 in the body.
You can then email your comments to 51407 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: <Johnson.Yan <at> microchip.com>
To: <bug-parted <at> gnu.org>
Subject: parted didn’t check the returned sense data
Date: Tue, 26 Oct 2021 09:55:02 +0000

[Message part 1 (text/plain, inline)]

Hi,
When we did secure erase for large capacity drive (18TB), the drive capacity will changed to 0. This issue can be reproduced each time, please refer to attached files for details.

From the system log we found parted send Read(16) to sde at Oct 13 01:30:02, due to security erase in progress “Not Ready” is returned from this drive which is expected.
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] CDB: Read(16) 88 00 00 00 00 00 00 00 00 00 00 00 00 08 00 00
Oct 13 01:30:02 localhost kernel: blk_update_request: I/O error, dev sde, sector 0
Oct 13 01:30:02 localhost kernel: Buffer I/O error on dev sde, logical block 0, async page read
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] CDB: Read(16) 88 00 00 00 00 00 00 00 00 00 00 00 00 08 00 00
Oct 13 01:30:02 localhost kernel: blk_update_request: I/O error, dev sde, sector 0
Oct 13 01:30:02 localhost kernel: Buffer I/O error on dev sde, logical block 0, async page read
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] CDB: Synchronize Cache(10) 35 00 00 00 00 00 00 00 00 00
Oct 13 01:30:02 localhost kernel: blk_update_request: I/O error, dev sde, sector 0
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] CDB: Read(16) 88 00 00 00 00 00 00 00 00 00 00 00 00 20 00 00
Oct 13 01:30:02 localhost kernel: blk_update_request: I/O error, dev sde, sector 0
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] CDB: Read(16) 88 00 00 00 00 00 00 00 00 00 00 00 00 08 00 00
Oct 13 01:30:02 localhost kernel: blk_update_request: I/O error, dev sde, sector 0
Oct 13 01:30:02 localhost kernel: Buffer I/O error on dev sde, logical block 0, async page read
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] CDB: Read(16) 88 00 00 00 00 00 00 00 00 00 00 00 00 08 00 00
Oct 13 01:30:02 localhost kernel: blk_update_request: I/O error, dev sde, sector 0
Oct 13 01:30:02 localhost kernel: Buffer I/O error on dev sde, logical block 0, async page read
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] CDB: Read(16) 88 00 00 00 00 00 00 00 00 00 00 00 00 08 00 00
Oct 13 01:30:02 localhost kernel: blk_update_request: I/O error, dev sde, sector 0
Oct 13 01:30:02 localhost kernel: Buffer I/O error on dev sde, logical block 0, async page read
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] CDB: Read(16) 88 00 00 00 00 00 00 00 00 00 00 00 00 08 00 00
Oct 13 01:30:02 localhost kernel: blk_update_request: I/O error, dev sde, sector 0
Oct 13 01:30:02 localhost kernel: Buffer I/O error on dev sde, logical block 0, async page read
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] CDB: Read(16) 88 00 00 00 00 00 00 00 00 00 00 00 00 08 00 00
Oct 13 01:30:02 localhost kernel: blk_update_request: I/O error, dev sde, sector 0
Oct 13 01:30:02 localhost kernel: Buffer I/O error on dev sde, logical block 0, async page read
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] CDB: Read(16) 88 00 00 00 00 00 00 00 00 00 00 00 00 08 00 00
Oct 13 01:30:02 localhost kernel: blk_update_request: I/O error, dev sde, sector 0
Oct 13 01:30:02 localhost kernel: Buffer I/O error on dev sde, logical block 0, async page read
Oct 13 01:30:02 localhost kernel: Buffer I/O error on dev sde, logical block 0, async page read
Oct 13 01:30:02 localhost kernel: Buffer I/O error on dev sde, logical block 0, async page read

// host tried to recover this drive by spinning up but no responding, which due to the same reason, i.e. security erase in progress.
Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Spinning up disk...
Oct 13 01:31:43 localhost kernel: ....................................................................................................not responding...

// host send Read Capacity(16) and Read Capacity(10) but still failed (security erase in progress), finally host changed the capacity to zero.
Oct 13 01:31:43 localhost kernel: sd 13:0:3:0: [sde] Read Capacity(16) failed: Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:31:43 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:31:43 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:31:43 localhost kernel: sd 13:0:3:0: [sde] Read Capacity(10) failed: Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 13 01:31:43 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
Oct 13 01:31:43 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
Oct 13 01:31:43 localhost kernel: sde: detected capacity change from 18000207937536 to 0

I suppose parted should check the returned sense data and not change drive capacity to 0, could you please help to check this issue? Many thanks.

Regards,
Johnson

[Message part 2 (text/html, inline)]

[sde_test.log (application/octet-stream, attachment)]

[messages.log (application/octet-stream, attachment)]

Message #8 received at 51407 <at> debbugs.gnu.org (full text, mbox):

From: <Johnson.Yan <at> microchip.com>
To: <51407 <at> debbugs.gnu.org>
Subject: parted didn’t check the returned sense data
Date: Wed, 27 Oct 2021 09:20:59 +0000

[Message part 1 (text/plain, inline)]

Hi,
Some further information.


  1.  We already tried the latest parted-3.4.tar.xz, issue still exists.
  2.  For below sense data, the corresponding KCQ=2:04:0E, i.e. SENSE KEY: 2, ADDITIONAL SENSE CODE: 04, ADDITIONAL SENSE CODE QUALIFIER: 0E.

Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]

Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress

You can find ASC and ASCQ assignments from SPC spec as below.
[cid:image001.png <at> 01D7CB56.D375FCF0]

Regards,
Johnson

[Message part 2 (text/html, inline)]

[image001.png (image/png, inline)]

Message #11 received at 51407 <at> debbugs.gnu.org (full text, mbox):

From: "Brian C. Lane" <bcl <at> redhat.com>
To: Johnson.Yan <at> microchip.com
Cc: 51407 <at> debbugs.gnu.org
Subject: Re: bug#51407: parted didn’t check
 the returned sense data
Date: Wed, 27 Oct 2021 09:02:45 -0700

On Wed, Oct 27, 2021 at 09:20:59AM +0000, Johnson.Yan--- via Bug reports for the GNU Parted disk partition editor wrote:
> Hi,
> Some further information.
> 
> 
>   1.  We already tried the latest parted-3.4.tar.xz, issue still exists.
>   2.  For below sense data, the corresponding KCQ=2:04:0E, i.e. SENSE KEY: 2, ADDITIONAL SENSE CODE: 04, ADDITIONAL SENSE CODE QUALIFIER: 0E.
> 
> Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not Ready [current] [descriptor]
> 
> Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: Logical unit not ready, security session in progress
> 
> You can find ASC and ASCQ assignments from SPC spec as below.
> [cid:image001.png <at> 01D7CB56.D375FCF0]

Sorry, for some reason I didn't get the first email in this thread.
(https://debbugs.gnu.org/cgi/bugreport.cgi?bug=51407)

The logs you included are from the kernel, not from parted, and parted
doesn't deal with sense data or changing the drive capacity, that's all
in the kernel driver for the drive.

If parted it having problems handling this, that might be something we
can improve. It's possible that whatever errors are returned by the
kernel aren't being checked, but I don't have any way to tell without
either a parted traceback, or doing this myself. I don't think I have
any drives capable of secure erase, so someone with access to one will
need to dig into this more deeply. eg. running parted via strace to
capture any unexpected error codes from the kernel.

Brian

-- 
Brian C. Lane (PST8PDT) - weldr.io - lorax - parted - pykickstart

Message #14 received at 51407 <at> debbugs.gnu.org (full text, mbox):

From: <Johnson.Yan <at> microchip.com>
To: <bcl <at> redhat.com>
Cc: 51407 <at> debbugs.gnu.org
Subject: RE: bug#51407: parted didn’t check the returned sense data
Date: Thu, 28 Oct 2021 02:32:43 +0000

Hi Brian,
Thanks for the reply. 
Seems Kernel called parted to send Read(16) command to the drive, it is more likely kernel didn't check the returned sense data and change the drive capacity to 0.
I suppose this bug#51407 can be closed. Thanks again.

Regards,
Johnson

-----Original Message-----
From: Brian C. Lane <bcl <at> redhat.com> 
Sent: Thursday, October 28, 2021 12:03 AM
To: Johnson Yan - A30689 <Johnson.Yan <at> microchip.com>
Cc: 51407 <at> debbugs.gnu.org
Subject: Re: bug#51407: parted didn’t check the returned sense data

[You don't often get email from bcl <at> redhat.com. Learn why this is important at http://aka.ms/LearnAboutSenderIdentification.]

EXTERNAL EMAIL: Do not click links or open attachments unless you know the content is safe

On Wed, Oct 27, 2021 at 09:20:59AM +0000, Johnson.Yan--- via Bug reports for the GNU Parted disk partition editor wrote:
> Hi,
> Some further information.
>
>
>   1.  We already tried the latest parted-3.4.tar.xz, issue still exists.
>   2.  For below sense data, the corresponding KCQ=2:04:0E, i.e. SENSE KEY: 2, ADDITIONAL SENSE CODE: 04, ADDITIONAL SENSE CODE QUALIFIER: 0E.
>
> Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Sense Key : Not 
> Ready [current] [descriptor]
>
> Oct 13 01:30:02 localhost kernel: sd 13:0:3:0: [sde] Add. Sense: 
> Logical unit not ready, security session in progress
>
> You can find ASC and ASCQ assignments from SPC spec as below.
> [cid:image001.png <at> 01D7CB56.D375FCF0]

Sorry, for some reason I didn't get the first email in this thread.
(https://debbugs.gnu.org/cgi/bugreport.cgi?bug=51407)

The logs you included are from the kernel, not from parted, and parted doesn't deal with sense data or changing the drive capacity, that's all in the kernel driver for the drive.

If parted it having problems handling this, that might be something we can improve. It's possible that whatever errors are returned by the kernel aren't being checked, but I don't have any way to tell without either a parted traceback, or doing this myself. I don't think I have any drives capable of secure erase, so someone with access to one will need to dig into this more deeply. eg. running parted via strace to capture any unexpected error codes from the kernel.

Brian

--
Brian C. Lane (PST8PDT) - weldr.io - lorax - parted - pykickstart

Message #19 received at 51407-close <at> debbugs.gnu.org (full text, mbox):

From: "Brian C. Lane" <bcl <at> redhat.com>
To: 51407-close <at> debbugs.gnu.org
Subject: Re: bug#51407: parted didn’t check
 the returned sense data
Date: Thu, 28 Oct 2021 09:25:16 -0700

On Thu, Oct 28, 2021 at 02:32:43AM +0000, Johnson.Yan <at> microchip.com wrote:
> Hi Brian,
> Thanks for the reply. 
> Seems Kernel called parted to send Read(16) command to the drive, it is more likely kernel didn't check the returned sense data and change the drive capacity to 0.
> I suppose this bug#51407 can be closed. Thanks again.

The kernel doesn't call parted. So this is bound to be something else.

Thanks,

Brian
-- 
Brian C. Lane (PST8PDT) - weldr.io - lorax - parted - pykickstart

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.