[2007/12/21 12:01:10, 5] lib/debug.c:debug_dump_status(393) 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 registry: False/0 [2007/12/21 12:01:10, 3] param/loadparm.c:lp_load(5657) lp_load: refreshing parameters [2007/12/21 12:01:10, 3] param/loadparm.c:init_globals(1456) Initialising global parameters [2007/12/21 12:01:10, 3] param/params.c:pm_process(569) params.c:pm_process() - Processing configuration file "/usr/local/samba/lib/smb.conf" [2007/12/21 12:01:10, 3] param/loadparm.c:do_section(4350) Processing section "[global]" doing parameter workgroup = MMCLIENT doing parameter security = ads doing parameter realm = MM.PRIVATE doing parameter password server = * doing parameter max log size = 0 doing parameter log file = /var/log/samba/log.%I doing parameter log level = 10 doing parameter debug pid = yes doing parameter debug hires timestamp = yes [2007/12/21 12:01:10.721512, 4, pid=5031] param/loadparm.c:lp_load(5689) pm_process() returned Yes [2007/12/21 12:01:10.721582, 7, pid=5031] param/loadparm.c:lp_servicenumber(5830) lp_servicenumber: couldn't find homes [2007/12/21 12:01:10.721617, 10, pid=5031] param/loadparm.c:set_server_role(4894) set_server_role: role = ROLE_DOMAIN_MEMBER [2007/12/21 12:01:10.721653, 5, pid=5031] lib/iconv.c:smb_register_charset(104) Attempting to register new charset UCS-2LE [2007/12/21 12:01:10.721685, 5, pid=5031] lib/iconv.c:smb_register_charset(112) Registered charset UCS-2LE [2007/12/21 12:01:10.721711, 5, pid=5031] lib/iconv.c:smb_register_charset(104) Attempting to register new charset UTF-16LE [2007/12/21 12:01:10.721747, 5, pid=5031] lib/iconv.c:smb_register_charset(112) Registered charset UTF-16LE [2007/12/21 12:01:10.721773, 5, pid=5031] lib/iconv.c:smb_register_charset(104) Attempting to register new charset UCS-2BE [2007/12/21 12:01:10.721799, 5, pid=5031] lib/iconv.c:smb_register_charset(112) Registered charset UCS-2BE [2007/12/21 12:01:10.721824, 5, pid=5031] lib/iconv.c:smb_register_charset(104) Attempting to register new charset UTF-16BE [2007/12/21 12:01:10.721849, 5, pid=5031] lib/iconv.c:smb_register_charset(112) Registered charset UTF-16BE [2007/12/21 12:01:10.721874, 5, pid=5031] lib/iconv.c:smb_register_charset(104) Attempting to register new charset UTF8 [2007/12/21 12:01:10.721899, 5, pid=5031] lib/iconv.c:smb_register_charset(112) Registered charset UTF8 [2007/12/21 12:01:10.721924, 5, pid=5031] lib/iconv.c:smb_register_charset(104) Attempting to register new charset UTF-8 [2007/12/21 12:01:10.721950, 5, pid=5031] lib/iconv.c:smb_register_charset(112) Registered charset UTF-8 [2007/12/21 12:01:10.721974, 5, pid=5031] lib/iconv.c:smb_register_charset(104) Attempting to register new charset ASCII [2007/12/21 12:01:10.722006, 5, pid=5031] lib/iconv.c:smb_register_charset(112) Registered charset ASCII [2007/12/21 12:01:10.722051, 5, pid=5031] lib/iconv.c:smb_register_charset(104) Attempting to register new charset 646 [2007/12/21 12:01:10.722078, 5, pid=5031] lib/iconv.c:smb_register_charset(112) Registered charset 646 [2007/12/21 12:01:10.722102, 5, pid=5031] lib/iconv.c:smb_register_charset(104) Attempting to register new charset ISO-8859-1 [2007/12/21 12:01:10.722128, 5, pid=5031] lib/iconv.c:smb_register_charset(112) Registered charset ISO-8859-1 [2007/12/21 12:01:10.722152, 5, pid=5031] lib/iconv.c:smb_register_charset(104) Attempting to register new charset UCS2-HEX [2007/12/21 12:01:10.722178, 5, pid=5031] lib/iconv.c:smb_register_charset(112) Registered charset UCS2-HEX [2007/12/21 12:01:10.722354, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.722750, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.722831, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.722871, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.722906, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.722940, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.722975, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.723051, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.723089, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.723155, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.723241, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.723305, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.723387, 5, pid=5031] lib/util.c:init_names(273) Netbios name list:- my_netbios_names[0]="SARGE26" [2007/12/21 12:01:10.724080, 2, pid=5031] lib/interface.c:add_interface(334) added interface eth0 ip=fe80::20c:29ff:fea5:9d07%eth0 bcast=fe80::ffff:ffff:ffff:ffff%eth0 netmask=ffff:ffff:ffff:ffff:: [2007/12/21 12:01:10.724188, 2, pid=5031] lib/interface.c:add_interface(334) added interface eth1 ip=fe80::20c:29ff:fea5:9d11%eth1 bcast=fe80::ffff:ffff:ffff:ffff%eth1 netmask=ffff:ffff:ffff:ffff:: [2007/12/21 12:01:10.724244, 2, pid=5031] lib/interface.c:add_interface(334) added interface eth1 ip=192.168.42.225 bcast=192.168.42.255 netmask=255.255.255.0 [2007/12/21 12:01:10.724276, 2, pid=5031] lib/interface.c:add_interface(334) added interface eth0 ip=10.0.27.2 bcast=10.255.255.255 netmask=255.0.0.0 [2007/12/21 12:01:10.724524, 5, pid=5031] lib/gencache.c:gencache_init(62) Opening cache file at /usr/local/samba/var/locks/gencache.tdb [2007/12/21 12:01:10.724652, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = AD_SITENAME/DOMAIN/MM.PRIVATE, value = Default-First-Site-Name, timeout = Tue Jan 19 04:14:07 2038 [2007/12/21 12:01:10.724705, 5, pid=5031] libads/dns.c:sitename_fetch(791) sitename_fetch: Returning sitename for MM.PRIVATE: "Default-First-Site-Name" [2007/12/21 12:01:10.724741, 4, pid=5031] libsmb/namequery_dc.c:ads_dc_name(73) ads_dc_name: domain=MMCLIENT [2007/12/21 12:01:10.724789, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = AD_SITENAME/DOMAIN/MM.PRIVATE, value = Default-First-Site-Name, timeout = Tue Jan 19 04:14:07 2038 [2007/12/21 12:01:10.724832, 5, pid=5031] libads/dns.c:sitename_fetch(791) sitename_fetch: Returning sitename for MM.PRIVATE: "Default-First-Site-Name" [2007/12/21 12:01:10.724857, 6, pid=5031] libads/ldap.c:ads_find_dc(299) ads_find_dc: looking for realm 'MM.PRIVATE' [2007/12/21 12:01:10.724917, 8, pid=5031] libsmb/namequery.c:get_sorted_dc_list(2087) get_sorted_dc_list: attempting lookup for name MM.PRIVATE (sitename Default-First-Site-Name) using [ads] [2007/12/21 12:01:10.724989, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = SAF/DOMAIN/MM.PRIVATE, value = 10.0.27.1, timeout = Fri Dec 21 12:15:36 2007 [2007/12/21 12:01:10.725034, 5, pid=5031] libsmb/namequery.c:saf_fetch(138) saf_fetch: Returning "10.0.27.1" for "MM.PRIVATE" domain [2007/12/21 12:01:10.725063, 3, pid=5031] libsmb/namequery.c:get_dc_list(1912) get_dc_list: preferred server list: "10.0.27.1, *" [2007/12/21 12:01:10.725134, 10, pid=5031] libsmb/namequery.c:internal_resolve_name(1443) internal_resolve_name: looking up MM.PRIVATE#1c (sitename Default-First-Site-Name) [2007/12/21 12:01:10.725188, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = NBT/MM.PRIVATE#1C, value = 10.0.27.1:389, timeout = Fri Dec 21 12:11:19 2007 [2007/12/21 12:01:10.725238, 5, pid=5031] libsmb/namecache.c:namecache_fetch(233) name MM.PRIVATE#1C found. [2007/12/21 12:01:10.725282, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725322, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725359, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725393, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725437, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725502, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725538, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725586, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725623, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725659, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725698, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725734, 5, pid=5031] lib/charcnv.c:charset_name(81) Substituting charset 'ISO-8859-1' for LOCALE [2007/12/21 12:01:10.725867, 8, pid=5031] libsmb/namequery.c:get_dc_list(1933) Adding 1 DC's from auto lookup [2007/12/21 12:01:10.725974, 10, pid=5031] libsmb/namequery.c:remove_duplicate_addrs2(520) remove_duplicate_addrs2: looking for duplicate address/port pairs [2007/12/21 12:01:10.726006, 4, pid=5031] libsmb/namequery.c:get_dc_list(2045) get_dc_list: returning 1 ip addresses in an ordered list [2007/12/21 12:01:10.726032, 4, pid=5031] libsmb/namequery.c:get_dc_list(2046) get_dc_list: 10.0.27.1:389 [2007/12/21 12:01:10.726062, 5, pid=5031] libads/ldap.c:ads_try_connect(179) ads_try_connect: sending CLDAP request to 10.0.27.1 (realm: MM.PRIVATE) [2007/12/21 12:01:10.726655, 10, pid=5031] libads/dns.c:sitename_store(752) sitename_store: realm = [MM.PRIVATE], sitename = [Default-First-Site-Name], expire = [2147483647] [2007/12/21 12:01:10.726693, 10, pid=5031] lib/gencache.c:gencache_set(138) Adding cache entry with key = AD_SITENAME/DOMAIN/MM.PRIVATE; value = Default-First-Site-Name and timeout = Tue Jan 19 04:14:07 2038 (949248777 seconds ahead) [2007/12/21 12:01:10.726784, 3, pid=5031] libads/ldap.c:ads_connect(403) Connected to LDAP server 10.0.27.1 [2007/12/21 12:01:10.726823, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = AD_SITENAME/DOMAIN/MM.PRIVATE, value = Default-First-Site-Name, timeout = Tue Jan 19 04:14:07 2038 [2007/12/21 12:01:10.726865, 5, pid=5031] libads/dns.c:sitename_fetch(791) sitename_fetch: Returning sitename for MM.PRIVATE: "Default-First-Site-Name" [2007/12/21 12:01:10.726899, 10, pid=5031] libads/ldap.c:ads_closest_dc(148) ads_closest_dc: ADS_CLOSEST flag set [2007/12/21 12:01:10.726958, 10, pid=5031] libads/kerberos.c:create_local_private_krb5_conf_for_domain(807) create_local_private_krb5_conf_for_domain: fname = /usr/local/samba/var/locks/smb_krb5/krb5.conf.MMCLIENT, realm = MM.PRIVATE, domain = MMCLIENT [2007/12/21 12:01:10.727003, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = SAF/DOMAIN/MM.PRIVATE, value = 10.0.27.1, timeout = Fri Dec 21 12:15:36 2007 [2007/12/21 12:01:10.727057, 5, pid=5031] libsmb/namequery.c:saf_fetch(138) saf_fetch: Returning "10.0.27.1" for "MM.PRIVATE" domain [2007/12/21 12:01:10.727087, 3, pid=5031] libsmb/namequery.c:get_dc_list(1912) get_dc_list: preferred server list: "10.0.27.1, *" [2007/12/21 12:01:10.727122, 10, pid=5031] libsmb/namequery.c:internal_resolve_name(1443) internal_resolve_name: looking up MM.PRIVATE#1c (sitename Default-First-Site-Name) [2007/12/21 12:01:10.727157, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = NBT/MM.PRIVATE#1C, value = 10.0.27.1:389, timeout = Fri Dec 21 12:11:19 2007 [2007/12/21 12:01:10.727198, 5, pid=5031] libsmb/namecache.c:namecache_fetch(233) name MM.PRIVATE#1C found. [2007/12/21 12:01:10.727293, 8, pid=5031] libsmb/namequery.c:get_dc_list(1933) Adding 1 DC's from auto lookup [2007/12/21 12:01:10.727362, 10, pid=5031] libsmb/namequery.c:remove_duplicate_addrs2(520) remove_duplicate_addrs2: looking for duplicate address/port pairs [2007/12/21 12:01:10.727393, 4, pid=5031] libsmb/namequery.c:get_dc_list(2045) get_dc_list: returning 1 ip addresses in an ordered list [2007/12/21 12:01:10.727431, 4, pid=5031] libsmb/namequery.c:get_dc_list(2046) get_dc_list: 10.0.27.1:389 [2007/12/21 12:01:10.727490, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = SAF/DOMAIN/MM.PRIVATE, value = 10.0.27.1, timeout = Fri Dec 21 12:15:36 2007 [2007/12/21 12:01:10.727532, 5, pid=5031] libsmb/namequery.c:saf_fetch(138) saf_fetch: Returning "10.0.27.1" for "MM.PRIVATE" domain [2007/12/21 12:01:10.727575, 3, pid=5031] libsmb/namequery.c:get_dc_list(1912) get_dc_list: preferred server list: "10.0.27.1, *" [2007/12/21 12:01:10.727604, 10, pid=5031] libsmb/namequery.c:internal_resolve_name(1443) internal_resolve_name: looking up MM.PRIVATE#1c (sitename (null)) [2007/12/21 12:01:10.727638, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = NBT/MM.PRIVATE#1C, value = 10.0.27.1:389, timeout = Fri Dec 21 12:11:19 2007 [2007/12/21 12:01:10.727679, 5, pid=5031] libsmb/namecache.c:namecache_fetch(233) name MM.PRIVATE#1C found. [2007/12/21 12:01:10.727771, 8, pid=5031] libsmb/namequery.c:get_dc_list(1933) Adding 1 DC's from auto lookup [2007/12/21 12:01:10.727840, 10, pid=5031] libsmb/namequery.c:remove_duplicate_addrs2(520) remove_duplicate_addrs2: looking for duplicate address/port pairs [2007/12/21 12:01:10.727870, 4, pid=5031] libsmb/namequery.c:get_dc_list(2045) get_dc_list: returning 1 ip addresses in an ordered list [2007/12/21 12:01:10.727896, 4, pid=5031] libsmb/namequery.c:get_dc_list(2046) get_dc_list: 10.0.27.1:389 [2007/12/21 12:01:10.727925, 10, pid=5031] libads/kerberos.c:get_kdc_ip_string(756) get_kdc_ip_string: Returning kdc = 10.0.27.1 [2007/12/21 12:01:10.728499, 5, pid=5031] libads/kerberos.c:create_local_private_krb5_conf_for_domain(876) create_local_private_krb5_conf_for_domain: wrote file /usr/local/samba/var/locks/smb_krb5/krb5.conf.MMCLIENT with realm MM.PRIVATE KDC = 10.0.27.1 [2007/12/21 12:01:10.728577, 4, pid=5031] libsmb/namequery_dc.c:ads_dc_name(143) ads_dc_name: using server='WIN2008.MM.PRIVATE' IP=10.0.27.1 [2007/12/21 12:01:13.285449, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = AD_SITENAME/DOMAIN/MM.PRIVATE, value = Default-First-Site-Name, timeout = Tue Jan 19 04:14:07 2038 [2007/12/21 12:01:13.285526, 5, pid=5031] libads/dns.c:sitename_fetch(791) sitename_fetch: Returning sitename for MM.PRIVATE: "Default-First-Site-Name" [2007/12/21 12:01:13.285555, 6, pid=5031] libads/ldap.c:ads_find_dc(299) ads_find_dc: looking for realm 'MM.PRIVATE' [2007/12/21 12:01:13.285582, 8, pid=5031] libsmb/namequery.c:get_sorted_dc_list(2087) get_sorted_dc_list: attempting lookup for name MM.PRIVATE (sitename Default-First-Site-Name) using [ads] [2007/12/21 12:01:13.285676, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = SAF/DOMAIN/MM.PRIVATE, value = 10.0.27.1, timeout = Fri Dec 21 12:15:36 2007 [2007/12/21 12:01:13.285720, 5, pid=5031] libsmb/namequery.c:saf_fetch(138) saf_fetch: Returning "10.0.27.1" for "MM.PRIVATE" domain [2007/12/21 12:01:13.285750, 3, pid=5031] libsmb/namequery.c:get_dc_list(1912) get_dc_list: preferred server list: "10.0.27.1, *" [2007/12/21 12:01:13.285793, 10, pid=5031] libsmb/namequery.c:internal_resolve_name(1443) internal_resolve_name: looking up MM.PRIVATE#1c (sitename Default-First-Site-Name) [2007/12/21 12:01:13.285830, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = NBT/MM.PRIVATE#1C, value = 10.0.27.1:389, timeout = Fri Dec 21 12:11:19 2007 [2007/12/21 12:01:13.285871, 5, pid=5031] libsmb/namecache.c:namecache_fetch(233) name MM.PRIVATE#1C found. [2007/12/21 12:01:13.286001, 8, pid=5031] libsmb/namequery.c:get_dc_list(1933) Adding 1 DC's from auto lookup [2007/12/21 12:01:13.286079, 10, pid=5031] libsmb/namequery.c:remove_duplicate_addrs2(520) remove_duplicate_addrs2: looking for duplicate address/port pairs [2007/12/21 12:01:13.286126, 4, pid=5031] libsmb/namequery.c:get_dc_list(2045) get_dc_list: returning 1 ip addresses in an ordered list [2007/12/21 12:01:13.286175, 4, pid=5031] libsmb/namequery.c:get_dc_list(2046) get_dc_list: 10.0.27.1:389 [2007/12/21 12:01:13.286208, 5, pid=5031] libads/ldap.c:ads_try_connect(179) ads_try_connect: sending CLDAP request to 10.0.27.1 (realm: MM.PRIVATE) [2007/12/21 12:01:13.286848, 10, pid=5031] libads/dns.c:sitename_store(752) sitename_store: realm = [MM.PRIVATE], sitename = [Default-First-Site-Name], expire = [2147483647] [2007/12/21 12:01:13.286886, 10, pid=5031] lib/gencache.c:gencache_set(138) Adding cache entry with key = AD_SITENAME/DOMAIN/MM.PRIVATE; value = Default-First-Site-Name and timeout = Tue Jan 19 04:14:07 2038 (949248774 seconds ahead) [2007/12/21 12:01:13.286943, 3, pid=5031] libads/ldap.c:ads_connect(403) Connected to LDAP server 10.0.27.1 [2007/12/21 12:01:23.297192, 10, pid=5031] libads/ldap.c:ads_closest_dc(148) ads_closest_dc: ADS_CLOSEST flag set [2007/12/21 12:01:23.297659, 10, pid=5031] libsmb/namequery.c:saf_store(75) saf_store: domain = [MM], server = [10.0.27.1], expire = [1198235783] [2007/12/21 12:01:23.297694, 10, pid=5031] lib/gencache.c:gencache_set(138) Adding cache entry with key = SAF/DOMAIN/MM; value = 10.0.27.1 and timeout = Fri Dec 21 12:16:23 2007 (900 seconds ahead) [2007/12/21 12:01:23.297785, 10, pid=5031] libsmb/namequery.c:saf_store(75) saf_store: domain = [MM.PRIVATE], server = [10.0.27.1], expire = [1198235783] [2007/12/21 12:01:23.297836, 10, pid=5031] lib/gencache.c:gencache_set(138) Adding cache entry with key = SAF/DOMAIN/MM.PRIVATE; value = 10.0.27.1 and timeout = Fri Dec 21 12:16:23 2007 (900 seconds ahead) [2007/12/21 12:01:23.300457, 4, pid=5031] libads/ldap.c:ads_current_time(2536) time offset is 10 seconds [2007/12/21 12:01:23.301451, 4, pid=5031] libads/sasl.c:ads_sasl_bind(1110) Found SASL mechanism GSS-SPNEGO [2007/12/21 12:01:23.302743, 3, pid=5031] libads/sasl.c:ads_sasl_spnego_bind(778) ads_sasl_spnego_bind: got OID=1 2 840 48018 1 2 2 [2007/12/21 12:01:23.302775, 3, pid=5031] libads/sasl.c:ads_sasl_spnego_bind(778) ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 [2007/12/21 12:01:23.302801, 3, pid=5031] libads/sasl.c:ads_sasl_spnego_bind(778) ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 3 [2007/12/21 12:01:23.302826, 3, pid=5031] libads/sasl.c:ads_sasl_spnego_bind(778) ads_sasl_spnego_bind: got OID=1 3 6 1 4 1 311 2 2 10 [2007/12/21 12:01:23.302851, 3, pid=5031] libads/sasl.c:ads_sasl_spnego_bind(787) ads_sasl_spnego_bind: got server principal name = not_defined_in_RFC4178@please_ignore [2007/12/21 12:01:23.305823, 3, pid=5031] libsmb/clikrb5.c:ads_krb5_mk_req(657) ads_krb5_mk_req: krb5_cc_get_principal failed (No credentials cache found) [2007/12/21 12:01:23.306379, 10, pid=5031] libads/sasl.c:ads_sasl_spnego_bind(808) ads_sasl_spnego_krb5_bind failed with: No credentials cache found, calling kinit [2007/12/21 12:01:23.306822, 10, pid=5031] libads/kerberos.c:kerberos_kinit_password_ext(214) kerberos_kinit_password: using [MEMORY:net_ads] as ccache and config [/usr/local/samba/var/locks/smb_krb5/krb5.conf.MMCLIENT] [2007/12/21 12:01:23.321787, 4, pid=5031] libsmb/clikrb5.c:ads_krb5_mk_req(674) ads_krb5_mk_req: Advancing clock by 10 seconds to cope with clock skew [2007/12/21 12:01:23.321852, 3, pid=5031] libsmb/clikrb5.c:ads_cleanup_expired_creds(592) ads_cleanup_expired_creds: Ticket in ccache[MEMORY:net_ads] expiration Fri, 21 Dec 2007 22:01:33 CET [2007/12/21 12:01:23.321897, 10, pid=5031] libsmb/clikrb5.c:ads_krb5_mk_req(688) ads_krb5_mk_req: Ticket (ldap/win2008.mm.private@MM.PRIVATE) in ccache (MEMORY:net_ads) is valid until: (Fri, 21 Dec 2007 22:01:33 CET - 1198270893) [2007/12/21 12:01:23.322686, 10, pid=5031] libsmb/clikrb5.c:get_krb5_smb_session_key(799) Got KRB5 session key of length 16 [2007/12/21 12:01:23.325682, 10, pid=5031] lib/gencache.c:gencache_del(168) Deleting cache entry (key = NBT/MM.PRIVATE#1C) [2007/12/21 12:01:23.325739, 10, pid=5031] lib/gencache.c:gencache_del(168) Deleting cache entry (key = NBT/MM#1C) [2007/12/21 12:01:23.326398, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = AD_SITENAME/DOMAIN/MM.PRIVATE, value = Default-First-Site-Name, timeout = Tue Jan 19 04:14:07 2038 [2007/12/21 12:01:23.326446, 5, pid=5031] libads/dns.c:sitename_fetch(791) sitename_fetch: Returning sitename for MM.PRIVATE: "Default-First-Site-Name" [2007/12/21 12:01:23.326657, 6, pid=5031] libads/ldap.c:ads_find_dc(299) ads_find_dc: looking for realm 'MM.PRIVATE' [2007/12/21 12:01:23.326686, 8, pid=5031] libsmb/namequery.c:get_sorted_dc_list(2087) get_sorted_dc_list: attempting lookup for name MM.PRIVATE (sitename Default-First-Site-Name) using [ads] [2007/12/21 12:01:23.326749, 10, pid=5031] lib/gencache.c:gencache_get(219) Returning valid cache entry: key = SAF/DOMAIN/MM.PRIVATE, value = 10.0.27.1, timeout = Fri Dec 21 12:16:23 2007 [2007/12/21 12:01:23.326790, 5, pid=5031] libsmb/namequery.c:saf_fetch(138) saf_fetch: Returning "10.0.27.1" for "MM.PRIVATE" domain [2007/12/21 12:01:23.326820, 3, pid=5031] libsmb/namequery.c:get_dc_list(1912) get_dc_list: preferred server list: "10.0.27.1, *" [2007/12/21 12:01:23.326849, 10, pid=5031] libsmb/namequery.c:internal_resolve_name(1443) internal_resolve_name: looking up MM.PRIVATE#1c (sitename Default-First-Site-Name) [2007/12/21 12:01:23.327363, 10, pid=5031] lib/gencache.c:gencache_get(205) Cache entry with key = NBT/MM.PRIVATE#1C couldn't be found [2007/12/21 12:01:23.327390, 5, pid=5031] libsmb/namecache.c:namecache_fetch(229) no entry for MM.PRIVATE#1C found. [2007/12/21 12:01:23.327429, 5, pid=5031] libsmb/namequery.c:resolve_ads(1336) resolve_ads: Attempting to resolve DCs for MM.PRIVATE using DNS [2007/12/21 12:01:23.329853, 4, pid=5031] libads/dns.c:ads_dns_lookup_srv(406) ads_dns_lookup_srv: 1 records returned in the answer section. [2007/12/21 12:01:23.329899, 10, pid=5031] libsmb/namequery.c:remove_duplicate_addrs2(520) remove_duplicate_addrs2: looking for duplicate address/port pairs [2007/12/21 12:01:23.329927, 5, pid=5031] libsmb/namecache.c:namecache_store(143) namecache_store: storing 1 address for MM.PRIVATE#1c: 10.0.27.1 [2007/12/21 12:01:23.329971, 10, pid=5031] lib/gencache.c:gencache_set(138) Adding cache entry with key = NBT/MM.PRIVATE#1C; value = 10.0.27.1:389 and timeout = Fri Dec 21 12:12:23 2007 (660 seconds ahead) [2007/12/21 12:01:23.330409, 10, pid=5031] libsmb/namequery.c:internal_resolve_name(1596) internal_resolve_name: returning 1 addresses: 10.0.27.1:389 [2007/12/21 12:01:23.330440, 8, pid=5031] libsmb/namequery.c:get_dc_list(1933) Adding 1 DC's from auto lookup [2007/12/21 12:01:23.330774, 10, pid=5031] libsmb/namequery.c:remove_duplicate_addrs2(520) remove_duplicate_addrs2: looking for duplicate address/port pairs [2007/12/21 12:01:23.330811, 4, pid=5031] libsmb/namequery.c:get_dc_list(2045) get_dc_list: returning 1 ip addresses in an ordered list [2007/12/21 12:01:23.330838, 4, pid=5031] libsmb/namequery.c:get_dc_list(2046) get_dc_list: 10.0.27.1:389 [2007/12/21 12:01:23.330869, 5, pid=5031] libads/ldap.c:ads_try_connect(179) ads_try_connect: sending CLDAP request to 10.0.27.1 (realm: MM.PRIVATE) [2007/12/21 12:01:23.332652, 10, pid=5031] libads/dns.c:sitename_store(752) sitename_store: realm = [MM.PRIVATE], sitename = [Default-First-Site-Name], expire = [2147483647] [2007/12/21 12:01:23.332690, 10, pid=5031] lib/gencache.c:gencache_set(138) Adding cache entry with key = AD_SITENAME/DOMAIN/MM.PRIVATE; value = Default-First-Site-Name and timeout = Tue Jan 19 04:14:07 2038 (949248764 seconds ahead) [2007/12/21 12:01:23.332745, 3, pid=5031] libads/ldap.c:ads_connect(403) Connected to LDAP server 10.0.27.1 [2007/12/21 12:01:30.138751, 10, pid=5031] libads/ldap.c:ads_closest_dc(148) ads_closest_dc: ADS_CLOSEST flag set [2007/12/21 12:01:30.138866, 10, pid=5031] libsmb/namequery.c:saf_store(75) saf_store: domain = [MM], server = [10.0.27.1], expire = [1198235790] [2007/12/21 12:01:30.138898, 10, pid=5031] lib/gencache.c:gencache_set(138) Adding cache entry with key = SAF/DOMAIN/MM; value = 10.0.27.1 and timeout = Fri Dec 21 12:16:30 2007 (900 seconds ahead) [2007/12/21 12:01:30.138967, 10, pid=5031] libsmb/namequery.c:saf_store(75) saf_store: domain = [MM.PRIVATE], server = [10.0.27.1], expire = [1198235790] [2007/12/21 12:01:30.138997, 10, pid=5031] lib/gencache.c:gencache_set(138) Adding cache entry with key = SAF/DOMAIN/MM.PRIVATE; value = 10.0.27.1 and timeout = Fri Dec 21 12:16:30 2007 (900 seconds ahead) [2007/12/21 12:01:30.139752, 4, pid=5031] libads/ldap.c:ads_current_time(2536) time offset is 10 seconds [2007/12/21 12:01:30.140062, 4, pid=5031] libads/sasl.c:ads_sasl_bind(1110) Found SASL mechanism GSS-SPNEGO [2007/12/21 12:01:30.140639, 3, pid=5031] libads/sasl.c:ads_sasl_spnego_bind(778) ads_sasl_spnego_bind: got OID=1 2 840 48018 1 2 2 [2007/12/21 12:01:30.140672, 3, pid=5031] libads/sasl.c:ads_sasl_spnego_bind(778) ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 [2007/12/21 12:01:30.140697, 3, pid=5031] libads/sasl.c:ads_sasl_spnego_bind(778) ads_sasl_spnego_bind: got OID=1 2 840 113554 1 2 2 3 [2007/12/21 12:01:30.140723, 3, pid=5031] libads/sasl.c:ads_sasl_spnego_bind(778) ads_sasl_spnego_bind: got OID=1 3 6 1 4 1 311 2 2 10 [2007/12/21 12:01:30.140748, 3, pid=5031] libads/sasl.c:ads_sasl_spnego_bind(787) ads_sasl_spnego_bind: got server principal name = not_defined_in_RFC4178@please_ignore [2007/12/21 12:01:30.141291, 4, pid=5031] libsmb/clikrb5.c:ads_krb5_mk_req(674) ads_krb5_mk_req: Advancing clock by 3 seconds to cope with clock skew [2007/12/21 12:01:30.141327, 3, pid=5031] libsmb/clikrb5.c:ads_cleanup_expired_creds(592) ads_cleanup_expired_creds: Ticket in ccache[MEMORY:net_ads] expiration Fri, 21 Dec 2007 22:01:33 CET [2007/12/21 12:01:30.141367, 10, pid=5031] libsmb/clikrb5.c:ads_krb5_mk_req(688) ads_krb5_mk_req: Ticket (ldap/win2008.mm.private@MM.PRIVATE) in ccache (MEMORY:net_ads) is valid until: (Fri, 21 Dec 2007 22:01:33 CET - 1198270893) [2007/12/21 12:01:30.141511, 10, pid=5031] libsmb/clikrb5.c:get_krb5_smb_session_key(799) Got KRB5 session key of length 16 [2007/12/21 12:01:30.143483, 3, pid=5031] libsmb/cliconnect.c:cli_start_connection(1594) Connecting to host=win2008.mm.private [2007/12/21 12:01:30.143612, 3, pid=5031] lib/util_sock.c:open_socket_out(1457) Connecting to 10.0.27.1 at port 445 [2007/12/21 12:01:30.155947, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option SO_KEEPALIVE = 0 [2007/12/21 12:01:30.156013, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option SO_REUSEADDR = 0 [2007/12/21 12:01:30.156047, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option SO_BROADCAST = 0 [2007/12/21 12:01:30.156078, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option TCP_NODELAY = 1 [2007/12/21 12:01:30.156105, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option TCP_KEEPCNT = 9 [2007/12/21 12:01:30.156132, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option TCP_KEEPIDLE = 7200 [2007/12/21 12:01:30.156159, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option TCP_KEEPINTVL = 75 [2007/12/21 12:01:30.156187, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option IPTOS_LOWDELAY = 0 [2007/12/21 12:01:30.156233, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option IPTOS_THROUGHPUT = 0 [2007/12/21 12:01:30.156260, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option SO_SNDBUF = 16384 [2007/12/21 12:01:30.156287, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option SO_RCVBUF = 87380 [2007/12/21 12:01:30.156314, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option SO_SNDLOWAT = 1 [2007/12/21 12:01:30.156341, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option SO_RCVLOWAT = 1 [2007/12/21 12:01:30.156367, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option SO_SNDTIMEO = 0 [2007/12/21 12:01:30.156394, 5, pid=5031] lib/util_sock.c:print_socket_options(776) socket option SO_RCVTIMEO = 0 [2007/12/21 12:01:30.156452, 6, pid=5031] libsmb/clientgen.c:write_socket(255) write_socket(7,194) [2007/12/21 12:01:30.156502, 6, pid=5031] libsmb/clientgen.c:write_socket(258) write_socket(7,194) wrote 194 [2007/12/21 12:01:30.157444, 10, pid=5031] lib/util_sock.c:read_smb_length_return_keepalive(1161) got smb length of 193 [2007/12/21 12:01:30.157506, 5, pid=5031] lib/util.c:show_msg(572) [2007/12/21 12:01:30.157528, 5, pid=5031] lib/util.c:show_msg(582) size=193 smb_com=0x72 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51201 smb_tid=0 smb_pid=5031 smb_uid=0 smb_mid=1 smt_wct=17 smb_vwv[ 0]= 9 (0x9) smb_vwv[ 1]=12815 (0x320F) smb_vwv[ 2]= 256 (0x100) smb_vwv[ 3]= 1024 (0x400) smb_vwv[ 4]= 17 (0x11) 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]= 499 (0x1F3) smb_vwv[11]=44160 (0xAC80) smb_vwv[12]=26022 (0x65A6) smb_vwv[13]=49373 (0xC0DD) smb_vwv[14]=51267 (0xC843) smb_vwv[15]=50177 (0xC401) smb_vwv[16]= 255 (0xFF) smb_bcc=124 [2007/12/21 12:01:30.157739, 10, pid=5031] lib/util.c:dump_data(2192) [000] B3 2A 63 D3 9B CC E7 48 95 24 0C 3E 32 FA 95 DB ³*cÓ.ÌçH .$.>2ú.Û [010] 60 6A 06 06 2B 06 01 05 05 02 A0 60 30 5E A0 30 `j..+... .. `0^ 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 2A 30 28 A0 26 1B 24 6E 6F 74 5F 64 65 66 69 £*0( &.$ not_defi [060] 6E 65 64 5F 69 6E 5F 52 46 43 34 31 37 38 40 70 ned_in_R FC4178@p [070] 6C 65 61 73 65 5F 69 67 6E 6F 72 65 lease_ig nore [2007/12/21 12:01:30.157961, 5, pid=5031] lib/util.c:show_msg(572) [2007/12/21 12:01:30.157981, 5, pid=5031] lib/util.c:show_msg(582) size=193 smb_com=0x72 smb_rcls=0 smb_reh=0 smb_err=0 smb_flg=136 smb_flg2=51201 smb_tid=0 smb_pid=5031 smb_uid=0 smb_mid=1 smt_wct=17 smb_vwv[ 0]= 9 (0x9) smb_vwv[ 1]=12815 (0x320F) smb_vwv[ 2]= 256 (0x100) smb_vwv[ 3]= 1024 (0x400) smb_vwv[ 4]= 17 (0x11) 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]= 499 (0x1F3) smb_vwv[11]=44160 (0xAC80) smb_vwv[12]=26022 (0x65A6) smb_vwv[13]=49373 (0xC0DD) smb_vwv[14]=51267 (0xC843) smb_vwv[15]=50177 (0xC401) smb_vwv[16]= 255 (0xFF) smb_bcc=124 [2007/12/21 12:01:30.158185, 10, pid=5031] lib/util.c:dump_data(2192) [000] B3 2A 63 D3 9B CC E7 48 95 24 0C 3E 32 FA 95 DB ³*cÓ.ÌçH .$.>2ú.Û [010] 60 6A 06 06 2B 06 01 05 05 02 A0 60 30 5E A0 30 `j..+... .. `0^ 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 2A 30 28 A0 26 1B 24 6E 6F 74 5F 64 65 66 69 £*0( &.$ not_defi [060] 6E 65 64 5F 69 6E 5F 52 46 43 34 31 37 38 40 70 ned_in_R FC4178@p [070] 6C 65 61 73 65 5F 69 67 6E 6F 72 65 lease_ig nore [2007/12/21 12:01:30.158498, 3, pid=5031] libsmb/cliconnect.c:cli_session_setup_spnego(792) Doing spnego session setup (blob length=124) [2007/12/21 12:01:30.158575, 3, pid=5031] libsmb/cliconnect.c:cli_session_setup_spnego(817) got OID=1 2 840 48018 1 2 2 [2007/12/21 12:01:30.158615, 3, pid=5031] libsmb/cliconnect.c:cli_session_setup_spnego(817) got OID=1 2 840 113554 1 2 2 [2007/12/21 12:01:30.158642, 3, pid=5031] libsmb/cliconnect.c:cli_session_setup_spnego(817) got OID=1 2 840 113554 1 2 2 3 [2007/12/21 12:01:30.158668, 3, pid=5031] libsmb/cliconnect.c:cli_session_setup_spnego(817) got OID=1 3 6 1 4 1 311 2 2 10 [2007/12/21 12:01:30.158693, 3, pid=5031] libsmb/cliconnect.c:cli_session_setup_spnego(825) got principal=not_defined_in_RFC4178@please_ignore [2007/12/21 12:01:30.159187, 10, pid=5031] libads/kerberos.c:kerberos_kinit_password_ext(214) kerberos_kinit_password: using [MEMORY:cliconnect] as ccache and config [/usr/local/samba/var/locks/smb_krb5/krb5.conf.MMCLIENT] [2007/12/21 12:01:30.162987, 3, pid=5031] libsmb/cliconnect.c:cli_session_setup_spnego(877) cli_session_setup_spnego: got a bad server principal, trying to guess ... [2007/12/21 12:01:30.163240, 5, pid=5031] libads/kerberos.c:kerberos_get_default_realm_from_ccache(509) kerberos_get_default_realm_from_ccache: Trying to read krb5 cache: MEMORY:cliconnect [2007/12/21 12:01:30.163333, 3, pid=5031] libsmb/cliconnect.c:cli_session_setup_spnego(888) cli_session_setup_spnego: guessed server principal=win2008.mm.private$@MM.PRIVATE [2007/12/21 12:01:30.163361, 2, pid=5031] libsmb/cliconnect.c:cli_session_setup_kerberos(612) Doing kerberos session setup [2007/12/21 12:01:30.165178, 1, pid=5031] libsmb/clikrb5.c:ads_krb5_mk_req(666) ads_krb5_mk_req: krb5_get_credentials failed for win2008.mm.private$@MM.PRIVATE (Server not found in Kerberos database) [2007/12/21 12:01:30.165246, 1, pid=5031] libsmb/cliconnect.c:cli_session_setup_kerberos(619) cli_session_setup_kerberos: spnego_gen_negTokenTarg failed: Server not found in Kerberos database [2007/12/21 12:01:30.165276, 3, pid=5031] libsmb/cliconnect.c:cli_session_setup(1001) SPNEGO login failed: Server not found in Kerberos database [2007/12/21 12:01:30.165322, 1, pid=5031] libsmb/cliconnect.c:cli_full_connection(1694) failed session setup with NT_STATUS_INVALID_ACCOUNT_NAME [2007/12/21 12:01:30.165429, 1, pid=5031] utils/net.c:connect_to_ipc_krb5(293) Cannot connect to server using kerberos. Error was NT_STATUS_INVALID_ACCOUNT_NAME [2007/12/21 12:01:30.165462, 1, pid=5031] utils/net_ads.c:net_ads_join(1567) call of net_join_domain failed: Improperly formed account name [2007/12/21 12:01:30.165578, 10, pid=5031] intl/lang_tdb.c:lang_tdb_init(134) lang_tdb_init: /usr/local/samba/lib/en_DE:en_US:en_GB:en.msg: No such file or directory [2007/12/21 12:01:30.166289, 2, pid=5031] utils/net.c:main(1124) return code = -1 Failed to join domain: Improperly formed account name