4680 – net ads join prompting for password then errors with SPNEGO login failed: Client not found in Kerberos database

Bug 4680 - net ads join prompting for password then errors with SPNEGO login failed: Client not found in Kerberos database

Summary: net ads join prompting for password then errors with SPNEGO login failed: Cli...

Status:	RESOLVED WORKSFORME

Alias:	None

Product:	Samba 3.0
Classification:	Unclassified
Component:	net utility (show other bugs)
Version:	3.0.25
Hardware:	Sparc Solaris

Importance:	P3 normal
Target Milestone:	none
Assignee:	Jim McDonough
QA Contact:	Samba QA Contact

URL:
Keywords:

Depends on:
Blocks:

Reported:	2007-06-04 12:13 UTC by Wayne Rasmussen
Modified:	2016-12-05 15:40 UTC (History)
CC List:	1 user (show)

See Also:

Attachments
Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.

Description Wayne Rasmussen 2007-06-04 12:13:04 UTC

Samba-3.025 running on Solaris 9 Sparc system for use with AD.  DC is MS Windows 2000 server.  Change noticed when tranistioning from Samba-3.0.10 to Samba-3.0.25.


/usr/local/bin/kinit  stevelongname@ADTEST.COM < /etc/DII.kinitkey #where /etc/DII.kinitkey is the password for stevelongname@ADTEST.COM #we can't get a keytab file in the real world situation.
/usr/local/samba/bin/net ads join
We are now getting a prompt for a password.  
Password for stevelongname@ADTEST.COM:
Password:

If I type in the password for stevelongname@ADTEST.COM, we get the following error message: 
[2007/05/31 14:00:02, 0] libsmb/cliconnect.c:cli_session_setup_spnego(853)
  Kinit failed: Client not found in Kerberos database Failed to join domain: Improperly formed account name

If I just hit return it continues.

Results of /usr/local/samba/bin/net -d10 ads join when the correct password is
typed:

[2007/06/04 12:56:16, 5] lib/debug.c:debug_dump_status(391)
  INFO: Current debug levels:
    all: True/10
    tdb: False/0
    printdrivers: False/0
    lanman: False/0
    smb: False/0
    rpc_parse: False/0
    rpc_srv: False/0
    rpc_cli: False/0
    passdb: False/0
    sam: False/0
    auth: False/0
    winbind: False/0
    vfs: False/0
    idmap: False/0
    quota: False/0
    acls: False/0
    locking: False/0
    msdfs: False/0
    dmapi: False/0
[2007/06/04 12:56:16, 3] param/loadparm.c:lp_load(5024)
  lp_load: refreshing parameters
[2007/06/04 12:56:16, 3] param/loadparm.c:init_globals(1424)
  Initialising global parameters
[2007/06/04 12:56:16, 3] param/params.c:pm_process(572)
  params.c:pm_process() - Processing configuration file "/usr/local/samba/lib/smb.conf"
[2007/06/04 12:56:16, 3] param/loadparm.c:do_section(3763)
  Processing section "[global]"
  doing parameter hide unreadable = Yes
  doing parameter workgroup = adtestnetbios
  doing parameter realm = adtest.com
  doing parameter security = ADS
  doing parameter encrypt passwords = yes
  doing parameter log level = 4
  doing parameter idmap uid = 10000-35000
  doing parameter idmap gid = 10000-35000
  doing parameter winbind enum users = yes
  doing parameter winbind enum groups = yes
  doing parameter template homedir = /u/%U
  doing parameter template shell = /bin/csh
  doing parameter winbind use default domain = yes
  doing parameter winbind cache time = 600
  doing parameter client schannel = no
  doing parameter username map = /usr/local/samba/lib/users.map
[2007/06/04 12:56:16, 4] param/loadparm.c:lp_load(5055)
  pm_process() returned Yes
[2007/06/04 12:56:16, 7] param/loadparm.c:lp_servicenumber(5193)
  lp_servicenumber: couldn't find homes
[2007/06/04 12:56:16, 10] param/loadparm.c:set_server_role(4299)
  set_server_role: role = ROLE_DOMAIN_MEMBER
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(105)
  Attempting to register new charset UCS-2LE
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(113)
  Registered charset UCS-2LE
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(105)
  Attempting to register new charset UTF-16LE
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(113)
  Registered charset UTF-16LE
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(105)
  Attempting to register new charset UCS-2BE
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(113)
  Registered charset UCS-2BE
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(105)
  Attempting to register new charset UTF-16BE
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(113)
  Registered charset UTF-16BE
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(105)
  Attempting to register new charset UTF8
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(113)
  Registered charset UTF8
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(105)
  Attempting to register new charset UTF-8
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(113)
  Registered charset UTF-8
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(105)
  Attempting to register new charset ASCII
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(113)
  Registered charset ASCII
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(105)
  Attempting to register new charset 646
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(113)
  Registered charset 646
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(105)
  Attempting to register new charset ISO-8859-1
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(113)
  Registered charset ISO-8859-1
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(105)
  Attempting to register new charset UCS2-HEX
[2007/06/04 12:56:16, 5] lib/iconv.c:smb_register_charset(113)
  Registered charset UCS2-HEX
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/charcnv.c:charset_name(82)
  Substituting charset '646' for LOCALE
[2007/06/04 12:56:16, 5] lib/util.c:init_names(287)
  Netbios name list:-
  my_netbios_names[0]="MCSJUMP"
[2007/06/04 12:56:16, 2] lib/interface.c:add_interface(81)
  added interface ip=10.10.10.91 bcast=10.10.10.255 nmask=255.255.255.0
[2007/06/04 12:56:16, 5] lib/gencache.c:gencache_init(61)
  Opening cache file at /usr/local/samba/var/locks/gencache.tdb
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = AD_SITENAME/DOMAIN/ADTEST.COM, value = Default-First-Site-Name, timeout = Mon Jan 18 22:14:07 2038
[2007/06/04 12:56:16, 5] libads/dns.c:sitename_fetch(679)
  sitename_fetch: Returning sitename for ADTEST.COM: "Default-First-Site-Name"
[2007/06/04 12:56:16, 4] libsmb/namequery_dc.c:ads_dc_name(73)
  ads_dc_name: domain=ADTESTNETBIOS
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = AD_SITENAME/DOMAIN/ADTEST.COM, value = Default-First-Site-Name, timeout = Mon Jan 18 22:14:07 2038
[2007/06/04 12:56:16, 5] libads/dns.c:sitename_fetch(679)
  sitename_fetch: Returning sitename for ADTEST.COM: "Default-First-Site-Name"
[2007/06/04 12:56:16, 6] libads/ldap.c:ads_find_dc(294)
  ads_find_dc: looking for realm 'ADTEST.COM'
[2007/06/04 12:56:16, 8] libsmb/namequery.c:get_sorted_dc_list(1626)
  get_sorted_dc_list: attempting lookup for name ADTEST.COM (sitename Default-First-Site-Name) using [ads]
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = SAF/DOMAIN/ADTEST.COM, value = 10.10.10.48, timeout = Mon Jun  4 13:10:59 2007
[2007/06/04 12:56:16, 5] libsmb/namequery.c:saf_fetch(136)
  saf_fetch: Returning "10.10.10.48" for "ADTEST.COM" domain
[2007/06/04 12:56:16, 3] libsmb/namequery.c:get_dc_list(1489)
  get_dc_list: preferred server list: "10.10.10.48, *"
[2007/06/04 12:56:16, 10] libsmb/namequery.c:internal_resolve_name(1166)
  internal_resolve_name: looking up ADTEST.COM#1c (sitename Default-First-Site-Name)
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = NBT/ADTEST.COM#1C, value = 10.10.10.48:389, timeout = Mon Jun  4 13:06:59 2007
[2007/06/04 12:56:16, 5] libsmb/namecache.c:namecache_fetch(214)
  name ADTEST.COM#1C found.
[2007/06/04 12:56:16, 8] libsmb/namequery.c:get_dc_list(1505)
  Adding 1 DC's from auto lookup
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = AD_SITENAME/DOMAIN/ADTEST.COM, value = Default-First-Site-Name, timeout = Mon Jan 18 22:14:07 2038
[2007/06/04 12:56:16, 5] libads/dns.c:sitename_fetch(679)
  sitename_fetch: Returning sitename for ADTEST.COM: "Default-First-Site-Name"
[2007/06/04 12:56:16, 10] libsmb/namequery.c:remove_duplicate_addrs2(435)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2007/06/04 12:56:16, 4] libsmb/namequery.c:get_dc_list(1599)
  get_dc_list: returning 1 ip addresses in an ordered list
[2007/06/04 12:56:16, 4] libsmb/namequery.c:get_dc_list(1600)
  get_dc_list: 10.10.10.48:389 
[2007/06/04 12:56:16, 5] libads/ldap.c:ads_try_connect(180)
  ads_try_connect: sending CLDAP request to 10.10.10.48 (realm: ADTEST.COM)
[2007/06/04 12:56:16, 10] libads/dns.c:sitename_store(640)
  sitename_store: realm = [ADTEST.COM], sitename = [Default-First-Site-Name], expire = [2147483647]
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_set(140)
  Adding cache entry with key = AD_SITENAME/DOMAIN/ADTEST.COM; value = Default-First-Site-Name and timeout = Mon Jan 18 22:14:07 2038
   (966507471 seconds ahead)
[2007/06/04 12:56:16, 3] libads/ldap.c:ads_connect(394)
  Connected to LDAP server 10.10.10.48
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = AD_SITENAME/DOMAIN/ADTEST.COM, value = Default-First-Site-Name, timeout = Mon Jan 18 22:14:07 2038
[2007/06/04 12:56:16, 5] libads/dns.c:sitename_fetch(679)
  sitename_fetch: Returning sitename for ADTEST.COM: "Default-First-Site-Name"
[2007/06/04 12:56:16, 10] libads/ldap.c:ads_closest_dc(149)
  ads_closest_dc: ADS_CLOSEST flag set
[2007/06/04 12:56:16, 10] libads/kerberos.c:create_local_private_krb5_conf_for_domain(611)
  create_local_private_krb5_conf_for_domain: fname = /usr/local/samba/var/locks/smb_krb5/krb5.conf.ADTESTNETBIOS, realm = ADTEST.COM, domain = ADTESTNETBIOS
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = SAF/DOMAIN/ADTEST.COM, value = 10.10.10.48, timeout = Mon Jun  4 13:10:59 2007
[2007/06/04 12:56:16, 5] libsmb/namequery.c:saf_fetch(136)
  saf_fetch: Returning "10.10.10.48" for "ADTEST.COM" domain
[2007/06/04 12:56:16, 3] libsmb/namequery.c:get_dc_list(1489)
  get_dc_list: preferred server list: "10.10.10.48, *"
[2007/06/04 12:56:16, 10] libsmb/namequery.c:internal_resolve_name(1166)
  internal_resolve_name: looking up ADTEST.COM#1c (sitename Default-First-Site-Name)
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = NBT/ADTEST.COM#1C, value = 10.10.10.48:389, timeout = Mon Jun  4 13:06:59 2007
[2007/06/04 12:56:16, 5] libsmb/namecache.c:namecache_fetch(214)
  name ADTEST.COM#1C found.
[2007/06/04 12:56:16, 8] libsmb/namequery.c:get_dc_list(1505)
  Adding 1 DC's from auto lookup
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = AD_SITENAME/DOMAIN/ADTEST.COM, value = Default-First-Site-Name, timeout = Mon Jan 18 22:14:07 2038
[2007/06/04 12:56:16, 5] libads/dns.c:sitename_fetch(679)
  sitename_fetch: Returning sitename for ADTEST.COM: "Default-First-Site-Name"
[2007/06/04 12:56:16, 10] libsmb/namequery.c:remove_duplicate_addrs2(435)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2007/06/04 12:56:16, 4] libsmb/namequery.c:get_dc_list(1599)
  get_dc_list: returning 1 ip addresses in an ordered list
[2007/06/04 12:56:16, 4] libsmb/namequery.c:get_dc_list(1600)
  get_dc_list: 10.10.10.48:389 
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = SAF/DOMAIN/ADTEST.COM, value = 10.10.10.48, timeout = Mon Jun  4 13:10:59 2007
[2007/06/04 12:56:16, 5] libsmb/namequery.c:saf_fetch(136)
  saf_fetch: Returning "10.10.10.48" for "ADTEST.COM" domain
[2007/06/04 12:56:16, 3] libsmb/namequery.c:get_dc_list(1489)
  get_dc_list: preferred server list: "10.10.10.48, *"
[2007/06/04 12:56:16, 10] libsmb/namequery.c:internal_resolve_name(1166)
  internal_resolve_name: looking up ADTEST.COM#1c (sitename (NULL))
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = NBT/ADTEST.COM#1C, value = 10.10.10.48:389, timeout = Mon Jun  4 13:06:59 2007
[2007/06/04 12:56:16, 5] libsmb/namecache.c:namecache_fetch(214)
  name ADTEST.COM#1C found.
[2007/06/04 12:56:16, 8] libsmb/namequery.c:get_dc_list(1505)
  Adding 1 DC's from auto lookup
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = AD_SITENAME/DOMAIN/ADTEST.COM, value = Default-First-Site-Name, timeout = Mon Jan 18 22:14:07 2038
[2007/06/04 12:56:16, 5] libads/dns.c:sitename_fetch(679)
  sitename_fetch: Returning sitename for ADTEST.COM: "Default-First-Site-Name"
[2007/06/04 12:56:16, 10] libsmb/namequery.c:remove_duplicate_addrs2(435)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2007/06/04 12:56:16, 4] libsmb/namequery.c:get_dc_list(1599)
  get_dc_list: returning 1 ip addresses in an ordered list
[2007/06/04 12:56:16, 4] libsmb/namequery.c:get_dc_list(1600)
  get_dc_list: 10.10.10.48:389 
[2007/06/04 12:56:16, 10] libads/kerberos.c:get_kdc_ip_string(562)
  get_kdc_ip_string: Returning 	kdc = 10.10.10.48
  
[2007/06/04 12:56:16, 5] libads/kerberos.c:create_local_private_krb5_conf_for_domain(680)
  create_local_private_krb5_conf_for_domain: wrote file /usr/local/samba/var/locks/smb_krb5/krb5.conf.ADTESTNETBIOS with realm ADTEST.COM KDC = 10.10.10.48
[2007/06/04 12:56:16, 4] libsmb/namequery_dc.c:ads_dc_name(131)
  ads_dc_name: using server='ADTESTSERVER01.ADTEST.COM' IP=10.10.10.48
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = AD_SITENAME/DOMAIN/ADTEST.COM, value = Default-First-Site-Name, timeout = Mon Jan 18 22:14:07 2038
[2007/06/04 12:56:16, 5] libads/dns.c:sitename_fetch(679)
  sitename_fetch: Returning sitename for ADTEST.COM: "Default-First-Site-Name"
[2007/06/04 12:56:16, 6] libads/ldap.c:ads_find_dc(294)
  ads_find_dc: looking for realm 'ADTEST.COM'
[2007/06/04 12:56:16, 8] libsmb/namequery.c:get_sorted_dc_list(1626)
  get_sorted_dc_list: attempting lookup for name ADTEST.COM (sitename Default-First-Site-Name) using [ads]
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = SAF/DOMAIN/ADTEST.COM, value = 10.10.10.48, timeout = Mon Jun  4 13:10:59 2007
[2007/06/04 12:56:16, 5] libsmb/namequery.c:saf_fetch(136)
  saf_fetch: Returning "10.10.10.48" for "ADTEST.COM" domain
[2007/06/04 12:56:16, 3] libsmb/namequery.c:get_dc_list(1489)
  get_dc_list: preferred server list: "10.10.10.48, *"
[2007/06/04 12:56:16, 10] libsmb/namequery.c:internal_resolve_name(1166)
  internal_resolve_name: looking up ADTEST.COM#1c (sitename Default-First-Site-Name)
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = NBT/ADTEST.COM#1C, value = 10.10.10.48:389, timeout = Mon Jun  4 13:06:59 2007
[2007/06/04 12:56:16, 5] libsmb/namecache.c:namecache_fetch(214)
  name ADTEST.COM#1C found.
[2007/06/04 12:56:16, 8] libsmb/namequery.c:get_dc_list(1505)
  Adding 1 DC's from auto lookup
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = AD_SITENAME/DOMAIN/ADTEST.COM, value = Default-First-Site-Name, timeout = Mon Jan 18 22:14:07 2038
[2007/06/04 12:56:16, 5] libads/dns.c:sitename_fetch(679)
  sitename_fetch: Returning sitename for ADTEST.COM: "Default-First-Site-Name"
[2007/06/04 12:56:16, 10] libsmb/namequery.c:remove_duplicate_addrs2(435)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2007/06/04 12:56:16, 4] libsmb/namequery.c:get_dc_list(1599)
  get_dc_list: returning 1 ip addresses in an ordered list
[2007/06/04 12:56:16, 4] libsmb/namequery.c:get_dc_list(1600)
  get_dc_list: 10.10.10.48:389 
[2007/06/04 12:56:16, 5] libads/ldap.c:ads_try_connect(180)
  ads_try_connect: sending CLDAP request to 10.10.10.48 (realm: ADTEST.COM)
[2007/06/04 12:56:16, 10] libads/dns.c:sitename_store(640)
  sitename_store: realm = [ADTEST.COM], sitename = [Default-First-Site-Name], expire = [2147483647]
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_set(140)
  Adding cache entry with key = AD_SITENAME/DOMAIN/ADTEST.COM; value = Default-First-Site-Name and timeout = Mon Jan 18 22:14:07 2038
   (966507471 seconds ahead)
[2007/06/04 12:56:16, 3] libads/ldap.c:ads_connect(394)
  Connected to LDAP server 10.10.10.48
[2007/06/04 12:56:16, 10] libads/ldap.c:ads_closest_dc(149)
  ads_closest_dc: ADS_CLOSEST flag set
[2007/06/04 12:56:16, 10] libsmb/namequery.c:saf_store(74)
  saf_store: domain = [ADTESTNETBIOS], server = [10.10.10.48], expire = [1180977076]
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_set(140)
  Adding cache entry with key = SAF/DOMAIN/ADTESTNETBIOS; value = 10.10.10.48 and timeout = Mon Jun  4 13:11:16 2007
   (900 seconds ahead)
[2007/06/04 12:56:16, 10] libsmb/namequery.c:saf_store(74)
  saf_store: domain = [ADTEST.COM], server = [10.10.10.48], expire = [1180977076]
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_set(140)
  Adding cache entry with key = SAF/DOMAIN/ADTEST.COM; value = 10.10.10.48 and timeout = Mon Jun  4 13:11:16 2007
   (900 seconds ahead)
[2007/06/04 12:56:16, 4] libads/ldap.c:ads_current_time(2414)
  time offset is 3 seconds
[2007/06/04 12:56:16, 4] libads/sasl.c:ads_sasl_bind(521)
  Found SASL mechanism GSS-SPNEGO
[2007/06/04 12:56:16, 3] libads/sasl.c:ads_sasl_spnego_bind(213)
  ads_sasl_spnego_bind: got OID=1 2 840 48018 1 2 2
[2007/06/04 12:56:16, 3] libads/sasl.c:ads_sasl_spnego_bind(213)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2
[2007/06/04 12:56:16, 3] libads/sasl.c:ads_sasl_spnego_bind(213)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 3
[2007/06/04 12:56:16, 3] libads/sasl.c:ads_sasl_spnego_bind(213)
  ads_sasl_spnego_bind: got OID=1 3 6 1 4 1 311 2 2 10
[2007/06/04 12:56:16, 3] libads/sasl.c:ads_sasl_spnego_bind(222)
  ads_sasl_spnego_bind: got server principal name = adtestserver01$@ADTEST.COM
[2007/06/04 12:56:16, 3] libsmb/clikrb5.c:ads_cleanup_expired_creds(528)
  ads_cleanup_expired_creds: Ticket in ccache[FILE:/tmp/krb5cc_0] expiration Mon, 04 Jun 2007 22:49:24 EDT
[2007/06/04 12:56:16, 10] libsmb/clikrb5.c:ads_krb5_mk_req(624)
  ads_krb5_mk_req: Ticket (adtestserver01$@ADTEST.COM) in ccache (FILE:/tmp/krb5cc_0) is valid until: (Mon, 04 Jun 2007 22:49:24 EDT - 1181011764)
[2007/06/04 12:56:16, 10] libsmb/clikrb5.c:get_krb5_smb_session_key(735)
  Got KRB5 session key of length 16
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_del(173)
  Deleting cache entry (key = NBT/ADTEST.COM#1C)
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_del(173)
  Deleting cache entry (key = NBT/ADTESTNETBIOS#1C)
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = AD_SITENAME/DOMAIN/ADTEST.COM, value = Default-First-Site-Name, timeout = Mon Jan 18 22:14:07 2038
[2007/06/04 12:56:16, 5] libads/dns.c:sitename_fetch(679)
  sitename_fetch: Returning sitename for ADTEST.COM: "Default-First-Site-Name"
[2007/06/04 12:56:16, 6] libads/ldap.c:ads_find_dc(294)
  ads_find_dc: looking for realm 'ADTEST.COM'
[2007/06/04 12:56:16, 8] libsmb/namequery.c:get_sorted_dc_list(1626)
  get_sorted_dc_list: attempting lookup for name ADTEST.COM (sitename Default-First-Site-Name) using [ads]
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = SAF/DOMAIN/ADTEST.COM, value = 10.10.10.48, timeout = Mon Jun  4 13:11:16 2007
[2007/06/04 12:56:16, 5] libsmb/namequery.c:saf_fetch(136)
  saf_fetch: Returning "10.10.10.48" for "ADTEST.COM" domain
[2007/06/04 12:56:16, 3] libsmb/namequery.c:get_dc_list(1489)
  get_dc_list: preferred server list: "10.10.10.48, *"
[2007/06/04 12:56:16, 10] libsmb/namequery.c:internal_resolve_name(1166)
  internal_resolve_name: looking up ADTEST.COM#1c (sitename Default-First-Site-Name)
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(212)
  Cache entry with key = NBT/ADTEST.COM#1C couldn't be found
[2007/06/04 12:56:16, 5] libsmb/namecache.c:namecache_fetch(210)
  no entry for ADTEST.COM#1C found.
[2007/06/04 12:56:16, 5] libsmb/namequery.c:resolve_ads(1066)
  resolve_ads: Attempting to resolve DC's for ADTEST.COM using DNS
[2007/06/04 12:56:16, 4] libads/dns.c:ads_dns_lookup_srv(356)
  ads_dns_lookup_srv: 1 records returned in the answer section.
[2007/06/04 12:56:16, 10] libsmb/namequery.c:remove_duplicate_addrs2(435)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2007/06/04 12:56:16, 5] libsmb/namecache.c:namecache_store(135)
  namecache_store: storing 1 address for ADTEST.COM#1c: 10.10.10.48:389
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_set(140)
  Adding cache entry with key = NBT/ADTEST.COM#1C; value = 10.10.10.48:389 and timeout = Mon Jun  4 13:07:16 2007
   (660 seconds ahead)
[2007/06/04 12:56:16, 10] libsmb/namequery.c:internal_resolve_name(1293)
  internal_resolve_name: returning 1 addresses: 10.10.10.48:389 
[2007/06/04 12:56:16, 8] libsmb/namequery.c:get_dc_list(1505)
  Adding 1 DC's from auto lookup
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_get(226)
  Returning valid cache entry: key = AD_SITENAME/DOMAIN/ADTEST.COM, value = Default-First-Site-Name, timeout = Mon Jan 18 22:14:07 2038
[2007/06/04 12:56:16, 5] libads/dns.c:sitename_fetch(679)
  sitename_fetch: Returning sitename for ADTEST.COM: "Default-First-Site-Name"
[2007/06/04 12:56:16, 10] libsmb/namequery.c:remove_duplicate_addrs2(435)
  remove_duplicate_addrs2: looking for duplicate address/port pairs
[2007/06/04 12:56:16, 4] libsmb/namequery.c:get_dc_list(1599)
  get_dc_list: returning 1 ip addresses in an ordered list
[2007/06/04 12:56:16, 4] libsmb/namequery.c:get_dc_list(1600)
  get_dc_list: 10.10.10.48:389 
[2007/06/04 12:56:16, 5] libads/ldap.c:ads_try_connect(180)
  ads_try_connect: sending CLDAP request to 10.10.10.48 (realm: ADTEST.COM)
[2007/06/04 12:56:16, 10] libads/dns.c:sitename_store(640)
  sitename_store: realm = [ADTEST.COM], sitename = [Default-First-Site-Name], expire = [2147483647]
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_set(140)
  Adding cache entry with key = AD_SITENAME/DOMAIN/ADTEST.COM; value = Default-First-Site-Name and timeout = Mon Jan 18 22:14:07 2038
   (966507471 seconds ahead)
[2007/06/04 12:56:16, 3] libads/ldap.c:ads_connect(394)
  Connected to LDAP server 10.10.10.48
[2007/06/04 12:56:16, 10] libads/ldap.c:ads_closest_dc(149)
  ads_closest_dc: ADS_CLOSEST flag set
[2007/06/04 12:56:16, 10] libsmb/namequery.c:saf_store(74)
  saf_store: domain = [ADTESTNETBIOS], server = [10.10.10.48], expire = [1180977076]
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_set(140)
  Adding cache entry with key = SAF/DOMAIN/ADTESTNETBIOS; value = 10.10.10.48 and timeout = Mon Jun  4 13:11:16 2007
   (900 seconds ahead)
[2007/06/04 12:56:16, 10] libsmb/namequery.c:saf_store(74)
  saf_store: domain = [ADTEST.COM], server = [10.10.10.48], expire = [1180977076]
[2007/06/04 12:56:16, 10] lib/gencache.c:gencache_set(140)
  Adding cache entry with key = SAF/DOMAIN/ADTEST.COM; value = 10.10.10.48 and timeout = Mon Jun  4 13:11:16 2007
   (900 seconds ahead)
[2007/06/04 12:56:16, 4] libads/ldap.c:ads_current_time(2414)
  time offset is 3 seconds
[2007/06/04 12:56:16, 4] libads/sasl.c:ads_sasl_bind(521)
  Found SASL mechanism GSS-SPNEGO
[2007/06/04 12:56:16, 3] libads/sasl.c:ads_sasl_spnego_bind(213)
  ads_sasl_spnego_bind: got OID=1 2 840 48018 1 2 2
[2007/06/04 12:56:16, 3] libads/sasl.c:ads_sasl_spnego_bind(213)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2
[2007/06/04 12:56:16, 3] libads/sasl.c:ads_sasl_spnego_bind(213)
  ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 3
[2007/06/04 12:56:16, 3] libads/sasl.c:ads_sasl_spnego_bind(213)
  ads_sasl_spnego_bind: got OID=1 3 6 1 4 1 311 2 2 10
[2007/06/04 12:56:16, 3] libads/sasl.c:ads_sasl_spnego_bind(222)
  ads_sasl_spnego_bind: got server principal name = adtestserver01$@ADTEST.COM
[2007/06/04 12:56:16, 3] libsmb/clikrb5.c:ads_cleanup_expired_creds(528)
  ads_cleanup_expired_creds: Ticket in ccache[FILE:/tmp/krb5cc_0] expiration Mon, 04 Jun 2007 22:49:24 EDT
[2007/06/04 12:56:16, 10] libsmb/clikrb5.c:ads_krb5_mk_req(624)
  ads_krb5_mk_req: Ticket (adtestserver01$@ADTEST.COM) in ccache (FILE:/tmp/krb5cc_0) is valid until: (Mon, 04 Jun 2007 22:49:24 EDT - 1181011764)
[2007/06/04 12:56:16, 10] libsmb/clikrb5.c:get_krb5_smb_session_key(735)
  Got KRB5 session key of length 16
Password:
[2007/06/04 12:56:22, 3] libsmb/cliconnect.c:cli_start_connection(1505)
  Connecting to host=adtestserver01.adtest.com
[2007/06/04 12:56:22, 3] lib/util_sock.c:open_socket_out(874)
  Connecting to 10.10.10.48 at port 445
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(206)
  socket option SO_KEEPALIVE = 0
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(206)
  socket option SO_REUSEADDR = 0
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(206)
  socket option SO_BROADCAST = 0
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(206)
  socket option TCP_NODELAY = 1
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(206)
  socket option IPTOS_LOWDELAY = 0
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(206)
  socket option IPTOS_THROUGHPUT = 0
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(206)
  socket option SO_SNDBUF = 49152
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(206)
  socket option SO_RCVBUF = 49640
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(204)
  Could not test socket option SO_SNDLOWAT.
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(204)
  Could not test socket option SO_RCVLOWAT.
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(204)
  Could not test socket option SO_SNDTIMEO.
[2007/06/04 12:56:22, 5] lib/util_sock.c:print_socket_options(204)
  Could not test socket option SO_RCVTIMEO.
[2007/06/04 12:56:22, 6] libsmb/clientgen.c:write_socket(153)
  write_socket(7,194)
[2007/06/04 12:56:22, 6] libsmb/clientgen.c:write_socket(156)
  write_socket(7,194) wrote 194
[2007/06/04 12:56:22, 10] lib/util_sock.c:read_smb_length_return_keepalive(623)
  got smb length of 183
[2007/06/04 12:56:22, 5] lib/util.c:show_msg(484)
[2007/06/04 12:56:22, 5] lib/util.c:show_msg(494)
  size=183
  smb_com=0x72
  smb_rcls=0
  smb_reh=0
  smb_err=0
  smb_flg=136
  smb_flg2=51201
  smb_tid=0
  smb_pid=1378
  smb_uid=0
  smb_mid=1
  smt_wct=17
  smb_vwv[ 0]=    9 (0x9)
  smb_vwv[ 1]=12807 (0x3207)
  smb_vwv[ 2]=  256 (0x100)
  smb_vwv[ 3]= 1024 (0x400)
  smb_vwv[ 4]=   65 (0x41)
  smb_vwv[ 5]=    0 (0x0)
  smb_vwv[ 6]=  256 (0x100)
  smb_vwv[ 7]=    0 (0x0)
  smb_vwv[ 8]=    0 (0x0)
  smb_vwv[ 9]=64768 (0xFD00)
  smb_vwv[10]=  243 (0xF3)
  smb_vwv[11]=30080 (0x7580)
  smb_vwv[12]= 3212 (0xC8C)
  smb_vwv[13]=51529 (0xC949)
  smb_vwv[14]=51110 (0xC7A6)
  smb_vwv[15]=41985 (0xA401)
  smb_vwv[16]=    1 (0x1)
  smb_bcc=114
[2007/06/04 12:56:22, 10] lib/util.c:dump_data(2261)
  [000] 40 B6 6A 80 32 C9 56 46  BC 85 41 05 2C 2F C8 11  @.j.2.VF ..A.,/..
  [010] 60 60 06 06 2B 06 01 05  05 02 A0 56 30 54 A0 30  ``..+... ...V0T.0
  [020] 30 2E 06 09 2A 86 48 82  F7 12 01 02 02 06 09 2A  0...*.H. .......*
  [030] 86 48 86 F7 12 01 02 02  06 0A 2A 86 48 86 F7 12  .H...... ..*.H...
  [040] 01 02 02 03 06 0A 2B 06  01 04 01 82 37 02 02 0A  ......+. ....7...
  [050] A3 20 30 1E A0 1C 1B 1A  61 64 74 65 73 74 73 65  . 0..... adtestse
  [060] 72 76 65 72 30 31 24 40  41 44 54 45 53 54 2E 43  rver01$@ ADTEST.C
  [070] 4F 4D                                             OM 
[2007/06/04 12:56:22, 5] lib/util.c:show_msg(484)
[2007/06/04 12:56:22, 5] lib/util.c:show_msg(494)
  size=183
  smb_com=0x72
  smb_rcls=0
  smb_reh=0
  smb_err=0
  smb_flg=136
  smb_flg2=51201
  smb_tid=0
  smb_pid=1378
  smb_uid=0
  smb_mid=1
  smt_wct=17
  smb_vwv[ 0]=    9 (0x9)
  smb_vwv[ 1]=12807 (0x3207)
  smb_vwv[ 2]=  256 (0x100)
  smb_vwv[ 3]= 1024 (0x400)
  smb_vwv[ 4]=   65 (0x41)
  smb_vwv[ 5]=    0 (0x0)
  smb_vwv[ 6]=  256 (0x100)
  smb_vwv[ 7]=    0 (0x0)
  smb_vwv[ 8]=    0 (0x0)
  smb_vwv[ 9]=64768 (0xFD00)
  smb_vwv[10]=  243 (0xF3)
  smb_vwv[11]=30080 (0x7580)
  smb_vwv[12]= 3212 (0xC8C)
  smb_vwv[13]=51529 (0xC949)
  smb_vwv[14]=51110 (0xC7A6)
  smb_vwv[15]=41985 (0xA401)
  smb_vwv[16]=    1 (0x1)
  smb_bcc=114
[2007/06/04 12:56:22, 10] lib/util.c:dump_data(2261)
  [000] 40 B6 6A 80 32 C9 56 46  BC 85 41 05 2C 2F C8 11  @.j.2.VF ..A.,/..
  [010] 60 60 06 06 2B 06 01 05  05 02 A0 56 30 54 A0 30  ``..+... ...V0T.0
  [020] 30 2E 06 09 2A 86 48 82  F7 12 01 02 02 06 09 2A  0...*.H. .......*
  [030] 86 48 86 F7 12 01 02 02  06 0A 2A 86 48 86 F7 12  .H...... ..*.H...
  [040] 01 02 02 03 06 0A 2B 06  01 04 01 82 37 02 02 0A  ......+. ....7...
  [050] A3 20 30 1E A0 1C 1B 1A  61 64 74 65 73 74 73 65  . 0..... adtestse
  [060] 72 76 65 72 30 31 24 40  41 44 54 45 53 54 2E 43  rver01$@ ADTEST.C
  [070] 4F 4D                                             OM 
[2007/06/04 12:56:22, 3] libsmb/cliconnect.c:cli_session_setup_spnego(789)
  Doing spnego session setup (blob length=114)
[2007/06/04 12:56:22, 3] libsmb/cliconnect.c:cli_session_setup_spnego(814)
  got OID=1 2 840 48018 1 2 2
[2007/06/04 12:56:22, 3] libsmb/cliconnect.c:cli_session_setup_spnego(814)
  got OID=1 2 840 113554 1 2 2
[2007/06/04 12:56:22, 3] libsmb/cliconnect.c:cli_session_setup_spnego(814)
  got OID=1 2 840 113554 1 2 2 3
[2007/06/04 12:56:22, 3] libsmb/cliconnect.c:cli_session_setup_spnego(814)
  got OID=1 3 6 1 4 1 311 2 2 10
[2007/06/04 12:56:22, 3] libsmb/cliconnect.c:cli_session_setup_spnego(822)
  got principal=adtestserver01$@ADTEST.COM
[2007/06/04 12:56:22, 10] libads/kerberos.c:kerberos_kinit_password_ext(91)
  kerberos_kinit_password: using [MEMORY:cliconnect] as ccache and config [/usr/local/samba/var/locks/smb_krb5/krb5.conf.ADTESTNETBIOS]
[2007/06/04 12:56:22, 0] libsmb/cliconnect.c:cli_session_setup_spnego(853)
  Kinit failed: Client not found in Kerberos database
[2007/06/04 12:56:22, 3] libsmb/cliconnect.c:cli_session_setup(957)
  SPNEGO login failed: Client not found in Kerberos database
[2007/06/04 12:56:22, 1] libsmb/cliconnect.c:cli_full_connection(1605)
  failed session setup with NT_STATUS_INVALID_ACCOUNT_NAME
[2007/06/04 12:56:22, 1] utils/net.c:connect_to_ipc_krb5(294)
  Cannot connect to server using kerberos.  Error was NT_STATUS_INVALID_ACCOUNT_NAME
[2007/06/04 12:56:22, 1] utils/net_ads.c:net_ads_join(1548)
  call of net_join_domain failed: Improperly formed account name
[2007/06/04 12:56:22, 2] utils/net.c:main(1032)
  return code = -1
Failed to join domain: Improperly formed account name

Comment 1 Karolin Seeger 2009-12-02 04:21:57 UTC

Is this still an issue in Samba 3.4?

Comment 2 Björn Jacke 2016-12-05 15:40:54 UTC

very old and no feedback. If this is still an issue with the latest Samba release, please file a new bug report for that.