Project

General

Profile

Bug #16847

can't update 9.10 from GUI

Added by Christian Wilke about 3 years ago. Updated over 1 year ago.

Status:
Resolved
Priority:
Important
Assignee:
Sean Fagan
Category:
OS
Target version:
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:
ChangeLog Required:
No

Description

  1. freenas-update -T FreeNAS-9.10-STABLE check

Verify command = ['/usr/local/libexec/verify_signature', '-K', '/usr/local/share/certs/freenas-update.pem', '-C', '/usr/local/share/certs/iX-CA.pem', '-S', u'qclWu8kvPGZ5lb2vTsls5ypq8onsEjYgN+BYczAaCKJoBP/RzLOQzlBCANJhOGTv+SnvIKr9D16N+NeOoEziAC7Evxuzvw9W8LQaI+54EpGbNfh+I0mIpEWZmH/4bvqHYskG00jB7PaaoiMCpgipn+Z34fALhbMqES5xE8N2Mo78iNq9GJilV/HejKODYw+8T9/TgAKn1KdJyo0K+RqX6L79NeV6gp3CWuVMB3VyFGezVL6hsKh7jJb8PnBWQhImrQDHOkBujCEgTB1lsZ+FmqL1hDuqafa+gFo8pfDqOzlivZgvExzdQmxPdAj7jUxEcoJ9PKBXMymsgWKfSVfbiw==', '-R', '/tmp/tmpg3ib3t.pem']
Signature check succeeded
Verify command = ['/usr/local/libexec/verify_signature', '-K', '/usr/local/share/certs/freenas-update.pem', '-C', '/usr/local/share/certs/iX-CA.pem', '-S', u'qclWu8kvPGZ5lb2vTsls5ypq8onsEjYgN+BYczAaCKJoBP/RzLOQzlBCANJhOGTv+SnvIKr9D16N+NeOoEziAC7Evxuzvw9W8LQaI+54EpGbNfh+I0mIpEWZmH/4bvqHYskG00jB7PaaoiMCpgipn+Z34fALhbMqES5xE8N2Mo78iNq9GJilV/HejKODYw+8T9/TgAKn1KdJyo0K+RqX6L79NeV6gp3CWuVMB3VyFGezVL6hsKh7jJb8PnBWQhImrQDHOkBujCEgTB1lsZ+FmqL1hDuqafa+gFo8pfDqOzlivZgvExzdQmxPdAj7jUxEcoJ9PKBXMymsgWKfSVfbiw==', '-R', '/tmp/tmpp6ai8c.pem']
Signature check succeeded
Could not open sequence file in cache directory /var/db/system/update: [Errno 2] No such file or directory: '/var/db/system/update/SEQUENCE'
Incomplete cache directory, will try continuing
Going to try checking cached manifest /var/db/system/update/MANIFEST
Going to try loading manifest file now
Verify command = ['/usr/local/libexec/verify_signature', '-K', '/usr/local/share/certs/freenas-update.pem', '-C', '/usr/local/share/certs/iX-CA.pem', '-S', u'qclWu8kvPGZ5lb2vTsls5ypq8onsEjYgN+BYczAaCKJoBP/RzLOQzlBCANJhOGTv+SnvIKr9D16N+NeOoEziAC7Evxuzvw9W8LQaI+54EpGbNfh+I0mIpEWZmH/4bvqHYskG00jB7PaaoiMCpgipn+Z34fALhbMqES5xE8N2Mo78iNq9GJilV/HejKODYw+8T9/TgAKn1KdJyo0K+RqX6L79NeV6gp3CWuVMB3VyFGezVL6hsKh7jJb8PnBWQhImrQDHOkBujCEgTB1lsZ+FmqL1hDuqafa+gFo8pfDqOzlivZgvExzdQmxPdAj7jUxEcoJ9PKBXMymsgWKfSVfbiw==', '-R', '/tmp/tmpprT8V2.pem']
Signature check succeeded
Loaded manifest file
Cached manifest file has sequence ca82ba222c0be179a6983636c50732c3, latest_manfest has sequence ca82ba222c0be179a6983636c50732c3
[Errno 13] Permission denied
Received exception during download phase, cannot update

  1. manifest_util verify
    TryGetNetworkFile(['https://web.ixsystems.com/updates/ix_crl.pem'])
    TryGetNetworkFile(['https://web.ixsystems.com/updates/ix_crl.pem']): Read 1028 bytes total
    Verify command = ['/usr/local/libexec/verify_signature', '-K', '/usr/local/share/certs/freenas-update.pem', '-C', '/usr/local/share/certs/iX-CA.pem', '-S', u'oTYOIKidYBjgZsS8dhD8A7wfEMopDe983+rIHgADJD2P2za6kIWqLAXL8KErRgLcYJWb9M7TNQ/6+dHIU7ZmZxNP1G9gJId4kI2H+ObzTwLUuPKKnVIKPmef3InFBHRquA36W5Pp0ZyY9rXs40IVKcAvmj5Hh8nvAnyKf5xAnNM=', '-R', '/tmp/tmpqjyfUv.pem']
    Signature check succeeded
    Verified

History

#1 Updated by Christian Wilke about 3 years ago

  • File debug-freenas-20160815184832.txz added

#2 Updated by Sean Fagan about 3 years ago

  • Status changed from Unscreened to 15

Well, that's fascinating: EACCESS is an unusual error to get.

Please do:

  1. id
  2. ls -ldo /var/db/system
  3. ls -ldo /var/db/system/update
  4. getfacl /var/db/system
  5. getfacl /var/dbsystem/update

#3 Updated by Christian Wilke about 3 years ago

  1. id
    uid=0(root) gid=0(wheel) groups=0(wheel)
  1. ls ldo /var/db/system
    drwxrwxr-
    9 cwi cwi uarch 11 Aug 15 20:28 /var/db/system/
  1. ls -ldo /var/db/system/update
    drwxr-xr-x 2 root cwi uarch 4 Aug 15 18:53 /var/db/system/update/
  1. getfacl /var/db/system
  2. file: /var/db/system
  3. owner: cwi
  4. group: cwi
    owner@:rwxp--aARWcCos:-------:allow
    group@:rwxp--a-R-c--s:-------:allow
    everyone@:r-----a-R-c--s:-------:allow
  1. getfacl /var/db/system/update
  2. file: /var/db/system/update
  3. owner: root
  4. group: cwi
    owner@:rwxp--aARWcCos:-------:allow
    group@:r-x---a-R-c--s:-------:allow
    everyone@:r-x---a-R-c--s:-------:allow

#4 Updated by Sean Fagan about 3 years ago

Hm... This error has never come up before.

Can you do:

ls -l /var/db/system/update/MANIFEST
touch /var/db/system/update/testfile

#5 Updated by Christian Wilke about 3 years ago

[root@freenas] ~# ls l /var/db/system/update/MANIFEST
-rw-r--r-
1 root cwi 9262 Aug 15 18:53 /var/db/system/update/MANIFEST

[root@freenas] ~# touch /var/db/system/update/testfile
[root@freenas] ~# ls l /var/db/system/update/
total 26
drwxr-xr-x 2 root cwi 5 Aug 15 21:03 ./
drwxrwxr-
9 cwi cwi 11 Aug 15 20:28 ../
rw-r--r- 1 root cwi 9262 Aug 15 18:53 MANIFEST
r-xr-xr-x 1 root cwi 187 Aug 15 18:53 ValidateUpdate*
-rw-r--r-
1 root cwi 0 Aug 15 21:03 testfile

#6 Updated by Sean Fagan about 3 years ago

Okay... honestly that sounds like there is a stuck update process, but it should give a different error message.

A reboot might fix it. But you can also, I think, simply do an "rm -rf /var/db/system/update" and try the "freenas-update -v check" again.

If that doesn't work, then we'll get some more information from it.

#7 Updated by Christian Wilke about 3 years ago

[root@freenas] ~# freenas-update -v check
TryGetNetworkFile([u'http://update-master.freenas.org/FreeNAS/FreeNAS-9.10-STABLE/LATEST'])
TryGetNetworkFile([u'http://update-master.freenas.org/FreeNAS/FreeNAS-9.10-STABLE/LATEST']): Read 9262 bytes total
TryGetNetworkFile(['https://web.ixsystems.com/updates/ix_crl.pem'])
TryGetNetworkFile(['https://web.ixsystems.com/updates/ix_crl.pem']): Read 1028 bytes total
Verify command = ['/usr/local/libexec/verify_signature', '-K', '/usr/local/share/certs/freenas-update.pem', '-C', '/usr/local/share/certs/iX-CA.pem', '-S', u'qclWu8kvPGZ5lb2vTsls5ypq8onsEjYgN+BYczAaCKJoBP/RzLOQzlBCANJhOGTv+SnvIKr9D16N+NeOoEziAC7Evxuzvw9W8LQaI+54EpGbNfh+I0mIpEWZmH/4bvqHYskG00jB7PaaoiMCpgipn+Z34fALhbMqES5xE8N2Mo78iNq9GJilV/HejKODYw+8T9/TgAKn1KdJyo0K+RqX6L79NeV6gp3CWuVMB3VyFGezVL6hsKh7jJb8PnBWQhImrQDHOkBujCEgTB1lsZ+FmqL1hDuqafa+gFo8pfDqOzlivZgvExzdQmxPdAj7jUxEcoJ9PKBXMymsgWKfSVfbiw==', '-R', '/tmp/tmpqPhsSa.pem']
Signature check succeeded
Going to try checking cached manifest /var/db/system/update/MANIFEST
Got this exception: [Errno 2] No such file or directory: '/var/db/system/update/MANIFEST'
TryGetNetworkFile([u'http://update.freenas.org/FreeNAS/Validators/ValidateUpdate-dAn5lU.txt', u'http://update-master.freenas.org/FreeNAS/Validators/ValidateUpdate-dAn5lU.txt'])
TryGetNetworkFile([u'http://update.freenas.org/FreeNAS/Validators/ValidateUpdate-dAn5lU.txt', u'http://update-master.freenas.org/FreeNAS/Validators/ValidateUpdate-dAn5lU.txt']): Read 187 bytes total
[Errno 13] Permission denied
Received exception during download phase, cannot update

#8 Updated by Sean Fagan about 3 years ago

Dumb question: what happens if you run

/var/db/system/update/ValidateUpdate

?

Assuming that works, the next one is annoying:

ktrace -i -f /tmp/ktrace.out freenas-update check
gzip /tmp/ktrace.out

and attach /tmp/ktrace.out.gz to the bug (or email it to me, or otherwise make it accessible).

Thanks!

#9 Updated by Christian Wilke about 3 years ago

  • File ktrace.out.gz added

here it is

#10 Updated by Sean Fagan about 3 years ago

Okay. This is the source of the error:

13321 python2.7 NAMI  "/var/db/system/update/ValidateUpdate" 
13321 python2.7 RET execve -1 errno 13 Permission denied

The update system downloads a validation program, and attempts to run it.

However, it runs it as nobody.

What this most likely means is that something along the path to /var/db/system/update/ValidateUpdate is not searchable by uid -2.

The test for this is:

ls -ldo / /var /var/db /var/db/system /var/db/system/update /var/db/system/update/ValidateUpdate

I can give you a modified Manifest.py to work around the problem if that is it, but let's ensure that's it.

Thanks again!

#11 Updated by Christian Wilke about 3 years ago

[root@freenas] ~# ls ldo / /var /var/db /var/db/system /var/db/system/update /var/db/system/update/ValidateUpdate
drwxr-xr-x 19 root wheel uarch 26 Aug 15 21:09 //
drwxr-xr-x 30 root wheel uarch 1920 Aug 15 21:09 /var/
drwxr-xr-x 20 root wheel uarch 1728 Aug 16 07:09 /var/db/
drwxrwxr-
9 cwi cwi uarch 11 Aug 16 03:00 /var/db/system/
drwxr-xr-x 2 root cwi uarch 4 Aug 15 21:11 /var/db/system/update/
-r-xr-xr-x 1 root cwi uarch 187 Aug 15 21:11 /var/db/system/update/ValidateUpdate*

#12 Updated by Sean Fagan about 3 years ago

Do a "chown root:wheel /var/db/system" (oh, also "chgrp -R wheel /var/db/system" for good measure).

I wonder how it got that way.

#13 Updated by Christian Wilke about 3 years ago

Sean Fagan wrote:

Do a "chown root:wheel /var/db/system" (oh, also "chgrp -R wheel /var/db/system" for good measure).

I wonder how it got that way.

ok, i did it:

[root@freenas] /mnt/Volume1# ls ldo / /var /var/db /var/db/system /var/db/system/update /var/db/system/update/ValidateUpdate
drwxr-xr-x 19 root wheel uarch 26 Aug 16 13:34 //
drwxr-xr-x 30 root wheel uarch 1920 Aug 16 13:34 /var/
drwxr-xr-x 21 root wheel uarch 1792 Aug 16 21:34 /var/db/
drwxrwxr-
9 root wheel uarch 11 Aug 16 22:56 /var/db/system/
drwxr-xr-x 2 root wheel uarch 4 Aug 16 22:54 /var/db/system/update/
-r-xr-xr-x 1 root wheel uarch 187 Aug 16 22:54 /var/db/system/update/ValidateUpdate*

and

root@freenas] /mnt/Volume1# freenas-update -v check
TryGetNetworkFile([u'http://update-master.freenas.org/FreeNAS/FreeNAS-9.10-STABLE/LATEST'])
TryGetNetworkFile([u'http://update-master.freenas.org/FreeNAS/FreeNAS-9.10-STABLE/LATEST']): Read 9262 bytes total
TryGetNetworkFile(['https://web.ixsystems.com/updates/ix_crl.pem'])
TryGetNetworkFile(['https://web.ixsystems.com/updates/ix_crl.pem']): Read 1028 bytes total
Verify command = ['/usr/local/libexec/verify_signature', '-K', '/usr/local/share/certs/freenas-update.pem', '-C', '/usr/local/share/certs/iX-CA.pem', '-S', u'qclWu8kvPGZ5lb2vTsls5ypq8onsEjYgN+BYczAaCKJoBP/RzLOQzlBCANJhOGTv+SnvIKr9D16N+NeOoEziAC7Evxuzvw9W8LQaI+54EpGbNfh+I0mIpEWZmH/4bvqHYskG00jB7PaaoiMCpgipn+Z34fALhbMqES5xE8N2Mo78iNq9GJilV/HejKODYw+8T9/TgAKn1KdJyo0K+RqX6L79NeV6gp3CWuVMB3VyFGezVL6hsKh7jJb8PnBWQhImrQDHOkBujCEgTB1lsZ+FmqL1hDuqafa+gFo8pfDqOzlivZgvExzdQmxPdAj7jUxEcoJ9PKBXMymsgWKfSVfbiw==', '-R', '/tmp/tmpz9aas9.pem']
Signature check succeeded
TryGetNetworkFile(['https://web.ixsystems.com/updates/ix_crl.pem'])
TryGetNetworkFile(['https://web.ixsystems.com/updates/ix_crl.pem']): Read 1028 bytes total
Verify command = ['/usr/local/libexec/verify_signature', '-K', '/usr/local/share/certs/freenas-update.pem', '-C', '/usr/local/share/certs/iX-CA.pem', '-S', u'qclWu8kvPGZ5lb2vTsls5ypq8onsEjYgN+BYczAaCKJoBP/RzLOQzlBCANJhOGTv+SnvIKr9D16N+NeOoEziAC7Evxuzvw9W8LQaI+54EpGbNfh+I0mIpEWZmH/4bvqHYskG00jB7PaaoiMCpgipn+Z34fALhbMqES5xE8N2Mo78iNq9GJilV/HejKODYw+8T9/TgAKn1KdJyo0K+RqX6L79NeV6gp3CWuVMB3VyFGezVL6hsKh7jJb8PnBWQhImrQDHOkBujCEgTB1lsZ+FmqL1hDuqafa+gFo8pfDqOzlivZgvExzdQmxPdAj7jUxEcoJ9PKBXMymsgWKfSVfbiw==', '-R', '/tmp/tmp2GIYgD.pem']
Signature check succeeded
Could not open sequence file in cache directory /var/db/system/update: [Errno 2] No such file or directory: '/var/db/system/update/SEQUENCE'
Incomplete cache directory, will try continuing
Going to try checking cached manifest /var/db/system/update/MANIFEST
Going to try loading manifest file now
TryGetNetworkFile(['https://web.ixsystems.com/updates/ix_crl.pem'])
TryGetNetworkFile(['https://web.ixsystems.com/updates/ix_crl.pem']): Read 1028 bytes total
Verify command = ['/usr/local/libexec/verify_signature', '-K', '/usr/local/share/certs/freenas-update.pem', '-C', '/usr/local/share/certs/iX-CA.pem', '-S', u'qclWu8kvPGZ5lb2vTsls5ypq8onsEjYgN+BYczAaCKJoBP/RzLOQzlBCANJhOGTv+SnvIKr9D16N+NeOoEziAC7Evxuzvw9W8LQaI+54EpGbNfh+I0mIpEWZmH/4bvqHYskG00jB7PaaoiMCpgipn+Z34fALhbMqES5xE8N2Mo78iNq9GJilV/HejKODYw+8T9/TgAKn1KdJyo0K+RqX6L79NeV6gp3CWuVMB3VyFGezVL6hsKh7jJb8PnBWQhImrQDHOkBujCEgTB1lsZ+FmqL1hDuqafa+gFo8pfDqOzlivZgvExzdQmxPdAj7jUxEcoJ9PKBXMymsgWKfSVfbiw==', '-R', '/tmp/tmp_S_9Nt.pem']
Signature check succeeded
Loaded manifest file
Cached manifest file has sequence ca82ba222c0be179a6983636c50732c3, latest_manfest has sequence ca82ba222c0be179a6983636c50732c3
[Errno 13] Permission denied
Received exception during download phase, cannot update

#14 Updated by Sean Fagan about 3 years ago

You also need "chmod a+rx /var/db/system" -- note that it's rwxrwxr--, and I'd missed that due to how it got rendered in redmine here.

#15 Updated by Christian Wilke about 3 years ago

Sean Fagan wrote:

You also need "chmod a+rx /var/db/system" -- note that it's rwxrwxr--, and I'd missed that due to how it got rendered in redmine here.

thx sean, i updated my freenas sucessful :)
don't know how i got these permissions :/

#16 Updated by Sean Fagan about 3 years ago

  • Status changed from 15 to Investigation

I'll keep this open because I can probably fix it. But I think there may be some significant other issues if /var/db doesn't have the right permissions, which makes fixing this specific instance a lower priority.

Glad you got it working though!

#17 Avatar?id=14398&size=24x24 Updated by Kris Moore almost 3 years ago

  • Seen in changed from Unspecified to 9.10-STABLE-201606270534

#18 Avatar?id=14398&size=24x24 Updated by Kris Moore almost 3 years ago

  • Priority changed from No priority to Important
  • Target version set to 9.10.1-U3

#19 Updated by Dru Lavigne almost 3 years ago

Will this make it into U3?

#20 Updated by Sean Fagan almost 3 years ago

Probably not. It's not particularly difficult, but it's also not particularly important.

#21 Avatar?id=14398&size=24x24 Updated by Kris Moore almost 3 years ago

  • Target version changed from 9.10.1-U3 to 9.10.2

#22 Updated by Sean Fagan over 2 years ago

  • Status changed from Investigation to 19

commit:0a57f50052606745099df6d7d376ecefaf35b226 in freenas-pkgtools. Also in master.

#23 Updated by Vaibhav Chauhan over 2 years ago

this code is already in 9.10.2-STABLE branch of freenas-pkgtools repo, can this be marked ready for release ?

#24 Updated by Sean Fagan over 2 years ago

  • Status changed from 19 to Ready For Release
  • ChangeLog Entry updated (diff)

Also apparently yes.

#25 Updated by Dru Lavigne about 2 years ago

  • File deleted (debug-freenas-20160815184832.txz)

#26 Updated by Dru Lavigne about 2 years ago

  • File deleted (ktrace.out.gz)

#27 Updated by Dru Lavigne about 2 years ago

  • Private changed from Yes to No

#28 Updated by Dru Lavigne over 1 year ago

  • Status changed from Ready For Release to Resolved

Also available in: Atom PDF