Oracle ZFS Storage Appliance: SMB issue after upgrade to 2013.1.2.0

Asset ID:	1-72-1910199.1
Update Date:	2018-05-10
Keywords:

Solution Type Problem Resolution Sure

Solution 1910199.1 : Oracle ZFS Storage Appliance: SMB issue after upgrade to 2013.1.2.0

Applies to:

Sun ZFS Storage 7320 - Version All Versions and later
Sun ZFS Storage 7120 - Version All Versions and later
Oracle ZFS Storage ZS3-4 - Version All Versions and later
Oracle ZFS Storage ZS3-2 - Version All Versions and later
Sun ZFS Storage 7420 - Version All Versions and later
7000 Appliance OS (Fishworks)

Symptoms

THREE symptoms noticed by the customer:

  * Identity mapping no longer works
  * SMB is in a State of "Restarting too quickly"
  * The service Active Directory displays "Selected Domain Controller: "

FMA shows the SMB service "Restarting too quickly":

--------------- ------------------------------------ -------------- ---------
TIME EVENT-ID MSG-ID SEVERITY
--------------- ------------------------------------ -------------- ---------
Jul 01 2014 be078374-30a2-cee3-fc31-a8e07973e7bf SMF-8000-YX Major

Problem Status : resolved
Diag Engine : fmd / 1.2
System
  Manufacturer : unknown
  Name : unknown
  Part_Number : unknown
  Serial_Number : unknown

System Component
  Manufacturer : innotek-GmbH
  Name : VirtualBox
  Part_Number : unknown
  Serial_Number : 0
  Host_ID : 00000000
  Server_Name : zfs-test

----------------------------------------
Suspect 1 of 1 :
  Fault class : defect.sunos.smf.svc.maintenance
  Certainty : 100%
  Affects : svc:///network/smb/server:default
  Status : ok and in service

  Resource
  Name : "svc:///network/smb/server:default"
  Status : repaired

Description : Service svc:/network/smb/server:default failed - the instance is restarting too quickly.
Refer to http://support.oracle.com/msg/SMF-8000-YX for more information.

Response : The service has been placed into the maintenance state.

Impact : svc:/network/smb/server:default is unavailable.

Action : If the service corresponds to one of the configurable services on the appliance,
check the service configuration and log files for any errors.
Correct the errors and restart the service.
If the service is an internal appliance service, mark the fault repaired.
If the problem persists, contact your service provider.

debug.sys

Jun 26 15:26:00 zfs-test genunix: [ID 672855 kern.notice] syncing file systems...
Jun 26 15:26:00 zfs-test genunix: [ID 904073 kern.notice] done
Jul 1 17:59:15 zfs-test genunix: [ID 540533 kern.notice] ^MSunOS Release 5.11 Version ak/generic@2013.06.05.2.0,1-1.10 64-bit
Jul 1 17:59:15 zfs-test genunix: [ID 700403 kern.notice] Copyright (c) 1983, 2013, Oracle and/or its affiliates. All rights reserved.
Jul 1 17:59:19 zfs-test unix: [ID 536703 kern.notice] NOTICE: Software memory scrubber exiting.
Jul 1 18:00:06 zfs-test idmap[725]: [ID 702911 auth.notice] GSSAPI Error: Unspecified GSS failure. Minor code may provide more information (Key table entry not found)
Jul 1 18:00:15 zfs-test smbd[941]: [ID 702911 daemon.notice] service initialized
Jul 1 18:00:16 zfs-test smbd[941]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:00:19 zfs-test smbd[941]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:00:30 zfs-test smbd[1074]: [ID 702911 daemon.notice] service initialized
Jul 1 18:00:30 zfs-test smbd[1074]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:00:30 zfs-test smbd[1074]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:00:38 zfs-test smbd[1141]: [ID 702911 daemon.notice] service initialized
Jul 1 18:00:38 zfs-test smbd[1141]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:00:44 zfs-test akd[422]: [ID 950009 user.error] smb_join: Bad file number
Jul 1 18:00:47 zfs-test smbd[1158]: [ID 702911 daemon.notice] service initialized
Jul 1 18:00:47 zfs-test smbd[1158]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:00:58 zfs-test akd[422]: [ID 950009 user.error] smb_join: Bad file number
Jul 1 18:01:00 zfs-test smbd[1186]: [ID 702911 daemon.notice] service initialized
Jul 1 18:01:00 zfs-test smbd[1186]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:01:11 zfs-test smbd[1211]: [ID 702911 daemon.notice] service initialized
Jul 1 18:01:11 zfs-test smbd[1211]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:05 zfs-test smbd[1308]: [ID 702911 daemon.notice] service initialized
Jul 1 18:02:05 zfs-test smbd[1308]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:15 zfs-test smbd[1337]: [ID 702911 daemon.notice] service initialized
Jul 1 18:02:15 zfs-test smbd[1337]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:20 zfs-test akd[422]: [ID 950009 user.error] smb_join: Bad file number
Jul 1 18:02:23 zfs-test smbd[1360]: [ID 702911 daemon.notice] service initialized
Jul 1 18:02:23 zfs-test smbd[1360]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:30 zfs-test smbd[1381]: [ID 702911 daemon.notice] service initialized
Jul 1 18:02:30 zfs-test smbd[1381]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:36 zfs-test smbd[1391]: [ID 702911 daemon.notice] service initialized
Jul 1 18:02:36 zfs-test smbd[1391]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:42 zfs-test smbd[1401]: [ID 702911 daemon.notice] service initialized
Jul 1 18:02:42 zfs-test smbd[1401]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:48 zfs-test svc.startd[115]: [ID 748625 daemon.error] network/smb/server:default failed repeatedly: transitioned to maintenance (see 'svcs -xv' for details) <<<<<<<<
Jul 1 16:03:20 zfs-test smbd[1411]: [ID 702911 daemon.notice] service initialized
Jul 1 16:03:20 zfs-test smbd[1411]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 16:03:27 zfs-test akd[422]: [ID 950009 user.error] smb_join: Bad file number <<<<<<<<
Jul 1 16:03:28 zfs-test smbd[1422]: [ID 702911 daemon.notice] service initialized

system.sys

Jun 26 14:25:17 zfs-test idmap[2408]: [ID 153025 daemon.error] Degraded operation (Global Catalog servers not configured/discoverable).
Jun 26 14:28:18 zfs-test smbd[2253]: [ID 590577 daemon.error] smb_ads_host_update_dsattr: ldap_sasl_interactive_bind_s[dc1.imt.enst.fr] failed (Local error)
Jun 26 16:46:02 zfs-test smbd[954]: [ID 702911 daemon.error] smbns_krb: getting initial credentials (Clock skew too great: 'ZFS-TEST$@IMT.ENST.FR' requesting ticket 'krbtgt/IMT.ENST.FR@IMT.ENST.FR' from KDC 'unknown' (26/06/2014 14:45). Skew is 120m)
Jun 26 16:46:02 zfs-test smbd[954]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Clock skew too great: 'ZFS-TEST$@IMT.ENST.FR' requesting ticket 'krbtgt/IMT.ENST.FR@IMT.ENST.FR' from KDC 'unknown' (26/06/2014 14:45). Skew is 120m)
Jun 26 15:01:06 zfs-test svc.startd[2749]: [ID 748625 daemon.error] network/smb/server:default failed repeatedly: transitioned to maintenance (see 'svcs -xv' for details)
Jun 26 15:04:06 zfs-test idmap[4005]: [ID 499257 daemon.error] Error: smb_lookup_name failed.                                              <<<<<<<<
Jun 26 15:04:06 zfs-test idmap[4005]: [ID 455671 daemon.error] Check SMB service (svc:/network/smb/server).                                 <<<<<<<<
Jun 26 15:04:06 zfs-test idmap[4005]: [ID 174421 daemon.error] Check connectivity to Active Directory.                                      <<<<<<<<
Jun 26 15:04:06 zfs-test idmap[4005]: [ID 499257 daemon.error] Error: smb_lookup_name failed.
Jun 26 15:04:06 zfs-test idmap[4005]: [ID 455671 daemon.error] Check SMB service (svc:/network/smb/server).
Jun 26 15:04:06 zfs-test idmap[4005]: [ID 174421 daemon.error] Check connectivity to Active Directory.
Jul 1 18:00:16 zfs-test smbd[941]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:00:30 zfs-test smbd[1074]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:00:38 zfs-test smbd[1141]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:00:44 zfs-test akd[422]: [ID 950009 user.error] smb_join: Bad file number
Jul 1 18:00:47 zfs-test smbd[1158]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:00:58 zfs-test akd[422]: [ID 950009 user.error] smb_join: Bad file number
Jul 1 18:01:00 zfs-test smbd[1186]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:01:11 zfs-test smbd[1211]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:05 zfs-test smbd[1308]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:15 zfs-test smbd[1337]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:20 zfs-test akd[422]: [ID 950009 user.error] smb_join: Bad file number
Jul 1 18:02:23 zfs-test smbd[1360]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:30 zfs-test smbd[1381]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:36 zfs-test smbd[1391]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:42 zfs-test smbd[1401]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 18:02:48 zfs-test svc.startd[115]: [ID 748625 daemon.error] network/smb/server:default failed repeatedly: transitioned to maintenance (see 'svcs -xv' for details)    <<<<<<<<
Jul 1 16:03:20 zfs-test smbd[1411]: [ID 702911 daemon.error] smbns_krb: getting initial credentials via keytab (Key table entry not found)
Jul 1 16:03:27 zfs-test akd[422]: [ID 950009 user.error] smb_join: Bad file number                                                          <<<<<<<<

alert.ak.txt

Tue Jul 1 18:02:48 2014
        class = list.suspect
        code = SMF-8000-YX
                        system-mfg = unknown
                        system-name = unknown
                        system-part = unknown
                        system-serial = unknown
                        sys-comp-mfg = innotek-GmbH
                        sys-comp-name = VirtualBox
                        sys-comp-part = unknown
                        sys-comp-serial = 0
                        server-name = zfs-test
                        host-id = 00000000
                class = defect.sunos.smf.svc.maintenance
                        svc-name = network/smb/server
                        svc-instance = default
                reason-short = restarting_too_quickly
                reason-long = the instance is restarting too quickly    <<<<<<<<
                svc-string = svc:/network/smb/server:default            <<<<<<<<
                location = SMB (network/smb/server:default)
        severity = Major
        source = appliance/kit/akd:default

network-smb-server:default.log

[ Jun 26 15:00:57 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jun 26 15:00:58 Method "start" exited with status 0. ]
[ Jun 26 15:01:06 Stopping because process dumped core. ] <<<<<<<<
[ Jun 26 15:01:06 Executing stop method (:kill). ]
[ Jun 26 15:01:06 Restarting too quickly, changing state to maintenance. ] <<<<<<<<
[ Jul 1 17:59:28 Enabled. ]
[ Jul 1 17:59:54 Rereading configuration. ]
[ Jul 1 18:00:14 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
[ Jul 1 18:00:15 Method "start" exited with status 0. ]
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 18:00:26 Stopping because process dumped core. ]
[ Jul 1 18:00:27 Executing stop method (:kill). ]
[ Jul 1 18:00:27 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
[ Jul 1 18:00:30 Method "start" exited with status 0. ]
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 18:00:37 Stopping because process dumped core. ]
[ Jul 1 18:00:37 Executing stop method (:kill). ]
[ Jul 1 18:00:37 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 18:00:38 Method "start" exited with status 0. ]
[ Jul 1 18:00:45 Stopping because process dumped core. ]
[ Jul 1 18:00:45 Executing stop method (:kill). ]
[ Jul 1 18:00:46 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 18:00:47 Method "start" exited with status 0. ]
[ Jul 1 18:00:58 Stopping because process dumped core. ]
[ Jul 1 18:00:58 Executing stop method (:kill). ]
[ Jul 1 18:00:58 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
[ Jul 1 18:01:00 Method "start" exited with status 0. ]
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 18:01:09 Stopping because process dumped core. ]
[ Jul 1 18:01:09 Executing stop method (:kill). ]
[ Jul 1 18:01:09 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
smbd: smbd_nicmon_daemon online
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 18:01:11 Method "start" exited with status 0. ]
[ Jul 1 18:01:13 Stopping because service disabled. ]
[ Jul 1 18:01:13 Executing stop method (:kill). ]
[ Jul 1 18:02:04 Enabled. ]
[ Jul 1 18:02:05 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 18:02:05 Method "start" exited with status 0. ]
[ Jul 1 18:02:14 Stopping because process dumped core. ]
[ Jul 1 18:02:14 Executing stop method (:kill). ]
[ Jul 1 18:02:14 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
[ Jul 1 18:02:15 Method "start" exited with status 0. ]
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 18:02:22 Stopping because process dumped core. ]
[ Jul 1 18:02:22 Executing stop method (:kill). ]
[ Jul 1 18:02:22 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
smbd: smbd_refresh_monitor online
[ Jul 1 18:02:23 Method "start" exited with status 0. ]
[ Jul 1 18:02:30 Stopping because process dumped core. ]
[ Jul 1 18:02:30 Executing stop method (:kill). ]
[ Jul 1 18:02:30 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
[ Jul 1 18:02:30 Method "start" exited with status 0. ]
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 18:02:35 Stopping because process dumped core. ]
[ Jul 1 18:02:36 Executing stop method (:kill). ]
[ Jul 1 18:02:36 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 18:02:36 Method "start" exited with status 0. ]
[ Jul 1 18:02:42 Stopping because process dumped core. ]
[ Jul 1 18:02:42 Executing stop method (:kill). ]
[ Jul 1 18:02:42 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
[ Jul 1 18:02:42 Method "start" exited with status 0. ]
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 18:02:48 Stopping because process dumped core. ]
[ Jul 1 18:02:48 Executing stop method (:kill). ]
[ Jul 1 18:02:48 Restarting too quickly, changing state to maintenance. ]
[ Jul 1 16:03:20 Leaving maintenance because clear requested. ]
[ Jul 1 16:03:20 Enabled. ]
[ Jul 1 16:03:20 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
[ Jul 1 16:03:20 Method "start" exited with status 0. ]
[ Jul 1 16:03:27 Stopping because process dumped core. ]
[ Jul 1 16:03:27 Executing stop method (:kill). ]
[ Jul 1 16:03:27 Executing start method ("exec /lib/svc/method/svc-smbd start"). ]
smbd: service initialized
[ Jul 1 16:03:28 Method "start" exited with status 0. ]
smbd: smbd_refresh_monitor online
smbd: smbd_time_monitor online
smbd: smbd_share_publisher online
smbd: smbd_dyndns_publisher online
smbd: smbd_nicmon_daemon online
smbd: print service online

NOTE: SMB service restarting 'too quickly' and dumping core ...

Analysis of the SMB corefiles suggest the NAS is having difficulty joining the Active Directory environment containing 'trusted' domains:

$ mdb -R mdb ./core.smbd.4468

> ::status
debugging core file of smbd (32-bit) from zfs-test
initial argv: /usr/lib/smbd
threading model: native threads
status: process terminated by SIGSEGV (Segmentation Fault), addr=4

> ::stack
libsmb.so.1`smb_sid_tostr+0x1e(0, fcc4f610, 100, fe619f68)
libntsvcs.so.1`lsar_add_trusted_domains_ex+0xa1(82b9df8, fcc4fd78, fcc4f750, fe619b3d)
libntsvcs.so.1`lsar_enum_trusted_domains_ex+0x8a(fcc4f7f0, fcc4f7bc, fcc4fd78, fcc4f7f0)
libntsvcs.so.1`lsa_enum_trusted_domains+0x7f(fcc4f930, fcc4fdb0, fcc4fd78, 806497f)
smbd_ddiscover_query_info_core+0x9f(fcc4fdb0, fcc4f930, fcc4f930, 8064875)
smbd_ddiscover_query_info+0x71(fcc4fdb0, fcc4f930, fcc4f930, 100)
smbd_ddiscover_dns+0x49(fcc4fdb0, fcc4feb0, fcc4f930, 8064416)
smbd_ddiscover_main+0x77(fcc4fdb0)
smbd_ddiscover_service+0x8f(0, fefa2000, fcc4ffe8, fef03719)
libc_hwcap1.so.1`_thrp_setup+0x9d(febf2a40)
libc_hwcap1.so.1`_lwp_start(febf2a40, 0, 0, 0, 0, 0)

Changes

Cause

This is CR 19139233 - Can't join domain after update to 2013.1.2

(Duplicate: CR 19066773 - 7320 smb_ads_host_update_dsattr)

Solution

Upgrade to Appliance Release version 2013.1.3.0.

Checked for relevancy - 10-May-2018

References

<BUG:19139233> - CAN'T JOIN DOMAIN AFTER UPDATE TO 2013.1.2

Attachments

This solution has no attachment