Project

General

Profile

Bug #23410

While booting, the lines that read "null" during boot transform in tracebacks if the pool is encrypted with new pass-phrase

Added by Steve Sousa over 4 years ago. Updated about 4 years ago.

Status:
Resolved
Priority:
Expected
Assignee:
William Grzybowski
Category:
Middleware
Target version:
Seen in:
Severity:
New
Reason for Closing:
Reason for Blocked:
Needs QA:
Yes
Needs Doc:
Yes
Needs Merging:
Yes
Needs Automation:
No
Support Suite Ticket:
n/a
Hardware Configuration:

WD RED WD40EFRX - 4TB
HGST Deskstar NAS - 4TB HDS724040ALE640 DK7SAF400
InnoDisk Innolite mSata D150G 16Gb SSD
Samsung HD160JJ/P 160GB
Supermicro A1SAi-2550F
2X Kingston ValueRAM Hynix B-Die DDR3L 8GB 1600MHz KVR16LSE11/8HB
Ablecom cs-m50 case
CYBERPOWER CP900EPFCLCD 900VA/540W Line-Interactive

ChangeLog Required:
No

Description

Hello:

I've been trying different settings for a while before committing to freenas, then noticed that i was getting dtrace (see Bug #23409) and tracebacks on boot.
My hardware is two nearly identical, new boxes, fulfilling all the recommended configuration requirements (basically a freenas mini) and has been burned
in for days as recommended in other threads with no issues. It happens in both boxes and in both bios and uefi.
I'll post the line before and after the traceback, the full dmesg is anexed in a file.
It took me a while to figure out why and to make many tests so i can reduce the causes and how to reproduce it. My findings are bellow.

Description:

While booting, the lines that read null during boot transform in traceback if the pool is encryted

Symptoms:

Starting devd.
ums0: <vendor 0x0557 product 0x2419, class 0/0, rev 1.10/1.00, addr 4> on usbus1
ums0: 3 buttons and [Z] coordinates ID=0
Traceback (most recent call last):
File "/usr/local/lib/python2.7/site-packages/middlewared/main.py", line 157, in call_method
'result': self.middleware.call_method(self, message),
File "/usr/local/lib/python2.7/site-packages/middlewared/main.py", line 389, in call_method
return methodobj(*args)
File "/usr/local/www/freenasUI/middleware/notifier.py", line 4836, in sync_encrypted
zpool = self.zpool_parse(vol.vol_name)
File "/usr/local/www/freenasUI/middleware/notifier.py", line 4570, in zpool_parse
parse = zfs.parse_status(name, doc, res)
File "/usr/local/www/freenasUI/middleware/zfs.py", line 766, in parse_status
status = data.split('config:')[1]
IndexError: list index out of range

Starting ums0 moused.

To reproduce:
Destroy pool, mark as new
Wipe first and last 10MB of pool disk with:
dd if=/dev/zero of=/dev/ada1 bs=1m count=10
dd if=/dev/zero of=/dev/ada1 bs=512 oseek=`diskinfo ada1 | awk '{print int ( $3 ) / 512 - 20480 ;}'` (without this the pool reappears sometimes)
Install FreeNAS-9.10.2-U2 (from scratch or upgrade).
Exit wizard
In Services enable SSH, allow root pwd
Reboot->everything is fine.

notice the following lines:
Starting devd.
ums0: <vendor 0x0557 product 0x2419, class 0/0, rev 1.10/1.00, addr 4> on usbus1
ums0: 3 buttons and [Z] coordinates ID=0
null
Starting ums0 moused.

In Storage: add pool, name: pool_pt, select encrypted, click the plus sign box, click add.
Reboot

notice the 1 null becomes 4 nulls:

Starting devd.
ums0: <vendor 0x0557 product 0x2419, class 0/0, rev 1.10/1.00, addr 4> on usbus1
ums0: 3 buttons and [Z] coordinates ID=0
null
null
null
null
Starting ums0 moused.

If you now go to Storage: create a passphrase: test confirm: test
Reboot-> now you get the full traceback

Starting devd.
ums0: <vendor 0x0557 product 0x2419, class 0/0, rev 1.10/1.00, addr 4> on usbus1
ums0: 3 buttons and [Z] coordinates ID=0
Traceback (most recent call last):
File "/usr/local/lib/python2.7/site-packages/middlewared/main.py", line 157, in call_method
'result': self.middleware.call_method(self, message),
File "/usr/local/lib/python2.7/site-packages/middlewared/main.py", line 389, in call_method
return methodobj(*args)
File "/usr/local/www/freenasUI/middleware/notifier.py", line 4836, in sync_encrypted
zpool = self.zpool_parse(vol.vol_name)
File "/usr/local/www/freenasUI/middleware/notifier.py", line 4570, in zpool_parse
parse = zfs.parse_status(name, doc, res)
File "/usr/local/www/freenasUI/middleware/zfs.py", line 766, in parse_status
status = data.split('config:')[1]
IndexError: list index out of range

Starting ums0 moused.

I hope this bug report is useful.
The attached file consist of 3 boot sequences, the first with the wiped pool, the second with the added pool, the third after creating the passphrase.
The file name consist of box name - boot device(last 2 digits of serial num.) - pool device - bios/uefi - version.

Best Regards
Steve


Related issues

Has duplicate FreeNAS - Bug #21427: Missing error checking in zpool_parse() cause backtrace.Closed: Duplicate2017-02-23

History

#1 Updated by Steve Sousa over 4 years ago

  • Subject changed from While booting, the lines that read "null" during boot transform in tracebacks if the pool is encryted to While booting, the lines that read "null" during boot transform in tracebacks if the pool is encrypted

#2 Updated by Steve Sousa over 4 years ago

  • Subject changed from While booting, the lines that read "null" during boot transform in tracebacks if the pool is encrypted to While booting, the lines that read "null" during boot transform in tracebacks if the pool is encrypted with new pass-phrase

#3 Updated by Sean Fagan over 4 years ago

  • Category changed from 123 to 201

#4 Updated by Bonnie Follweiler over 4 years ago

  • Assignee set to Kris Moore

#5 Updated by Bonnie Follweiler over 4 years ago

  • Related to Bug #23409: Diferent boot disks cause diferent dtrace on UEFI boot with encrypted pool added

#6 Updated by William Grzybowski over 4 years ago

  • Status changed from Unscreened to Resolved
  • Assignee changed from Kris Moore to William Grzybowski
  • Priority changed from No priority to Expected
  • Target version set to 9.10.3

I believe this is already fixed and will be available in 9.10.3.

Thanks for the detailed bug report!

2d2b5e0931f0f

#7 Updated by William Grzybowski over 4 years ago

  • Related to deleted (Bug #23409: Diferent boot disks cause diferent dtrace on UEFI boot with encrypted pool)

#8 Avatar?id=14398&size=24x24 Updated by Kris Moore over 4 years ago

  • Target version changed from 9.10.3 to 11.0

#9 Updated by Vaibhav Chauhan about 4 years ago

  • Target version changed from 11.0 to 11.0-RC

#10 Updated by Dru Lavigne over 3 years ago

  • Has duplicate Bug #21427: Missing error checking in zpool_parse() cause backtrace. added

#11 Updated by Dru Lavigne over 3 years ago

  • File deleted (box left - innolite-1c wd bios U2.txt)

Also available in: Atom PDF