Bug 8814 - smbclient fails to authenticate/other .pst auth issues
Summary: smbclient fails to authenticate/other .pst auth issues
Status: RESOLVED FIXED
Alias: None
Product: Samba 3.6
Classification: Unclassified
Component: Client Tools (show other bugs)
Version: 3.6.3
Hardware: x86 Solaris
: P5 critical
Target Milestone: ---
Assignee: Volker Lendecke
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-03-15 15:38 UTC by Mike Moya
Modified: 2012-11-05 21:52 UTC (History)
0 users

See Also:

Attachments
debug level 10 logfile (449.80 KB, application/octet-stream)
2012-03-15 17:39 UTC, Mike Moya 		no flags Details
View All 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 Mike Moya 2012-03-15 15:38:19 UTC 
After upgrading from v3.5.13 to 3.6.3 most everything I have tried from XP and Win7 nmachine works fine (with the exception of outlook.pst files). smbclient however fails. This failure occurs on Solaris Sparc and Solaris x86. If I just mount a share. Everything authenticates just fine. Note I am not using a AD. We use Samba to mount shares from Solaris systems only. Here is my smb.conf:

[global]
        workgroup = ECN
        server string = ECN fileserver - archive
        smb passwd file = /etc/smbpasswd
        passdb backend = smbpasswd
        log level = 1
        max log size = 0
        unix extensions = No
        deadtime = 10
        socket options = SO_RCVBUF=65536 SO_SNDBUF=65536 TCP_NODELAY IPTOS_THROUGHPUT
        load printers = No
        printcap name = /dev/null
        local master = No
        wins server = 128.46.154.113
        remote announce = 128.46.154.113
        remote browse sync = 128.46.154.113
        use sendfile = Yes
        aio read size = 8192
        aio write size = 8192
        getwd cache = Yes
        write cache size = 262144
        nt acl support = No
        veto oplock files = /*.xls/
        wide links = Yes

If I try to change my passwd:

archive:/[55] smbpasswd
Old SMB password:
New SMB password:
Retype new SMB password:
Could not connect to machine 127.0.0.1: NT_STATUS_LOGON_FAILURE

Note I can mount any share just fine. If I try to use smbclient:

breakwater:/[36] smbclient //archive.ecn.purdue.edu/moyman -U moyman
Enter moyman's password: 
session setup failed: NT_STATUS_LOGON_FAILURE

Here the log from the above at log level 3:

[2012/03/15 11:30:56,  0] smbd/server.c:1051(main)
  smbd version 3.6.3 started.
  Copyright Andrew Tridgell and the Samba Team 1992-2011
[2012/03/15 11:30:56,  2] lib/tallocmsg.c:124(register_msg_pool_usage)
  Registered MSG_REQ_POOL_USAGE
[2012/03/15 11:30:56,  2] lib/dmallocmsg.c:78(register_dmalloc_msgs)
  Registered MSG_REQ_DMALLOC_MARK and LOG_CHANGED
[2012/03/15 11:30:56.038367,  3] param/loadparm.c:9572(lp_load_ex)
  lp_load_ex: refreshing parameters
[2012/03/15 11:30:56.038500,  3] param/loadparm.c:5192(init_globals)
  Initialising global parameters
[2012/03/15 11:30:56.038566,  2] param/loadparm.c:4982(max_open_files)
  rlimit_max: increasing rlimit_max (1024) to minimum Windows limit (16384)
[2012/03/15 11:30:56.038729,  3] ../lib/util/params.c:550(pm_process)
  params.c:pm_process() - Processing configuration file "/etc/smb.conf"
[2012/03/15 11:30:56.038804,  3] param/loadparm.c:8310(do_section)
  Processing section "[global]"
[2012/03/15 11:30:56.039365,  2] param/loadparm.c:8327(do_section)
  Processing section "[homes]"
[2012/03/15 11:30:56.039603,  2] param/loadparm.c:8327(do_section)
  Processing section "[pchome]"
[2012/03/15 11:30:56.039774,  2] param/loadparm.c:8327(do_section)
  Processing section "[profile]"
[2012/03/15 11:30:56.040114,  2] param/loadparm.c:8327(do_section)
  Processing section "[tmp]"
[2012/03/15 11:30:56.040247,  2] param/loadparm.c:8327(do_section)
  Processing section "[motd$]"
[2012/03/15 11:30:56.040507,  3] param/loadparm.c:6630(lp_add_ipc)
  adding IPC service
[2012/03/15 11:30:56.041752,  2] lib/interface.c:339(add_interface)
  added interface bge0 ip=128.46.154.147 bcast=128.46.154.255 netmask=255.255.255.0
[2012/03/15 11:30:56.042002,  3] smbd/server.c:1087(main)
  loaded services
[2012/03/15 11:30:56.049334,  3] passdb/lookup_sid.c:1736(get_primary_group_sid)
  Forcing Primary Group to 'Domain Users' for root
[2012/03/15 11:30:56.054212,  3] passdb/lookup_sid.c:1736(get_primary_group_sid)
  Forcing Primary Group to 'Domain Users' for root
[2012/03/15 11:30:56.058284,  3] auth/token_util.c:437(finalize_local_nt_token)
  Failed to fetch domain sid for ECN
[2012/03/15 11:30:56.058487,  3] auth/token_util.c:468(finalize_local_nt_token)
  Failed to fetch domain sid for ECN
[2012/03/15 11:30:56.061558,  3] passdb/lookup_sid.c:1736(get_primary_group_sid)
  Forcing Primary Group to 'Domain Users' for nobody
[2012/03/15 11:30:56.061758,  3] auth/token_util.c:437(finalize_local_nt_token)
  Failed to fetch domain sid for ECN
[2012/03/15 11:30:56.061931,  3] auth/token_util.c:468(finalize_local_nt_token)
  Failed to fetch domain sid for ECN
[2012/03/15 11:30:56.066091,  3] rpc_server/svcctl/srv_svcctl_reg.c:569(svcctl_init_winreg)
  Initialise the svcctl registry keys if needed.
[2012/03/15 11:30:56.069198,  3] rpc_server/rpc_handles.c:281(close_policy_hnd)
  Closed policy
[2012/03/15 11:30:56.069877,  3] rpc_server/rpc_handles.c:281(close_policy_hnd)
  Closed policy
[2012/03/15 11:30:56.070663,  3] rpc_server/rpc_handles.c:281(close_policy_hnd)
  Closed policy
[2012/03/15 11:30:56.071294,  3] rpc_server/rpc_handles.c:281(close_policy_hnd)
  Closed policy
[2012/03/15 11:30:56.072093,  3] rpc_server/rpc_handles.c:281(close_policy_hnd)
  Closed policy
[2012/03/15 11:30:56.072732,  3] rpc_server/rpc_handles.c:281(close_policy_hnd)
  Closed policy
[2012/03/15 11:30:56.073554,  3] rpc_server/rpc_handles.c:281(close_policy_hnd)
  Closed policy
[2012/03/15 11:30:56.074132,  3] rpc_server/rpc_handles.c:281(close_policy_hnd)
  Closed policy
[2012/03/15 11:30:56.074215,  3] rpc_server/rpc_handles.c:281(close_policy_hnd)
  Closed policy
[2012/03/15 11:30:56.074402,  3] rpc_server/eventlog/srv_eventlog_reg.c:59(eventlog_init_winreg)
  Initialise the eventlog registry keys if needed.
[2012/03/15 11:30:56.075330,  3] rpc_server/rpc_handles.c:281(close_policy_hnd)
  Closed policy
[2012/03/15 11:30:56.075455,  3] printing/pcap.c:138(pcap_cache_reload)
  reloading printcap cache
[2012/03/15 11:30:56.075784,  3] printing/pcap.c:189(pcap_cache_reload)
  reload status: ok
[2012/03/15 11:30:56.078051,  3] lib/access.c:336(allow_access)
  Allowed connection from 128.46.154.241 (128.46.154.241)
[2012/03/15 11:30:56.078132,  3] smbd/oplock.c:922(init_oplocks)
  init_oplocks: initializing messages.
[2012/03/15 11:30:56.078410,  3] smbd/process.c:1661(process_smb)
  Transaction 0 of length 194 (0 toread)
[2012/03/15 11:30:56.078474,  3] smbd/process.c:1466(switch_message)
  switch message SMBnegprot (pid 18156) conn 0x0
[2012/03/15 11:30:56.079058,  3] smbd/negprot.c:597(reply_negprot)
  Requested protocol [PC NETWORK PROGRAM 1.0]
[2012/03/15 11:30:56.079133,  3] smbd/negprot.c:597(reply_negprot)
  Requested protocol [MICROSOFT NETWORKS 1.03]
[2012/03/15 11:30:56.079217,  3] smbd/negprot.c:597(reply_negprot)
  Requested protocol [MICROSOFT NETWORKS 3.0]
[2012/03/15 11:30:56.079268,  3] smbd/negprot.c:597(reply_negprot)
  Requested protocol [LANMAN1.0]
[2012/03/15 11:30:56.079313,  3] smbd/negprot.c:597(reply_negprot)
  Requested protocol [LM1.2X002]
[2012/03/15 11:30:56.079357,  3] smbd/negprot.c:597(reply_negprot)
  Requested protocol [DOS LANMAN2.1]
[2012/03/15 11:30:56.079401,  3] smbd/negprot.c:597(reply_negprot)
  Requested protocol [LANMAN2.1]
[2012/03/15 11:30:56.079444,  3] smbd/negprot.c:597(reply_negprot)
  Requested protocol [Samba]
[2012/03/15 11:30:56.079487,  3] smbd/negprot.c:597(reply_negprot)
  Requested protocol [NT LANMAN 1.0]
[2012/03/15 11:30:56.079530,  3] smbd/negprot.c:597(reply_negprot)
  Requested protocol [NT LM 0.12]
[2012/03/15 11:30:56.079888,  3] smbd/negprot.c:401(reply_nt1)
  not using SPNEGO
[2012/03/15 11:30:56.079944,  3] smbd/negprot.c:704(reply_negprot)
  Selected protocol NT LANMAN 1.0
[2012/03/15 11:30:56.081026,  3] smbd/process.c:1661(process_smb)
  Transaction 1 of length 158 (0 toread)
[2012/03/15 11:30:56.081097,  3] smbd/process.c:1466(switch_message)
  switch message SMBsesssetupX (pid 18156) conn 0x0
[2012/03/15 11:30:56.081159,  3] smbd/sesssetup.c:1333(reply_sesssetup_and_X)
  wct=13 flg2=0xc001
[2012/03/15 11:30:56.081256,  3] smbd/sesssetup.c:1534(reply_sesssetup_and_X)
  Domain=[ECN]  NativeOS=[Unix] NativeLanMan=[Samba] PrimaryDomain=[null]
[2012/03/15 11:30:56.081302,  3] smbd/sesssetup.c:1551(reply_sesssetup_and_X)
  sesssetupX:name=[ECN]\[moyman]@[128.46.154.241]
[2012/03/15 11:30:56.081417,  3] auth/auth.c:218(check_ntlm_password)
  check_ntlm_password:  Checking password for unmapped user [ECN]\[moyman]@[128.46.154.241] with the new password interface
[2012/03/15 11:30:56.081473,  3] auth/auth.c:221(check_ntlm_password)
  check_ntlm_password:  mapped user is: [ARCHIVE]\[moyman]@[128.46.154.241]
[2012/03/15 11:30:56.082173,  3] passdb/lookup_sid.c:1736(get_primary_group_sid)
  Forcing Primary Group to 'Domain Users' for moyman
[2012/03/15 11:30:56.082485,  3] ../libcli/auth/ntlm_check.c:412(ntlm_password_check)
  ntlm_password_check: NT MD4 password check failed for user moyman
[2012/03/15 11:30:56.082999,  2] auth/auth.c:317(check_ntlm_password)
  check_ntlm_password:  Authentication for user [moyman] -> [moyman] FAILED with error NT_STATUS_WRONG_PASSWORD
[2012/03/15 11:30:56.083069,  3] smbd/error.c:77(error_packet_set)
  error packet at smbd/sesssetup.c(1662) cmd=115 (SMBsesssetupX) NT_STATUS_LOGON_FAILURE
[2012/03/15 11:30:56.084291,  3] smbd/server_exit.c:179(exit_server_common)
  Server exit (failed to receive smb request)


Adding:

client ntlmv2 auth = No

to smb.conf has no effect. Although if I then try to change my passwd I get:

archive:/[59] /tmp/smbpasswd
added interface bge0 ip=128.46.154.147 bcast=128.46.154.255 netmask=255.255.255.0
Old SMB password:
New SMB password:
Retype new SMB password:
Connecting to 127.0.0.1 at port 445
Doing spnego session setup (blob length=58)
got OID=1.3.6.1.4.1.311.2.2.10
got principal=NONE
Got challenge flags:
Got NTLMSSP neg_flags=0x608a8215
NTLMSSP: Set final flags:
Got NTLMSSP neg_flags=0x60088215
NTLMSSP Sign/Seal - Initialising with flags:
Got NTLMSSP neg_flags=0x60088215
SPNEGO login failed: Logon failure
Could not connect to machine 127.0.0.1: NT_STATUS_LOGON_FAILURE


Nothing I have tried in smb.conf has had any effect. I can mount a share just fine from Windows XP and Windows7 although from XP machines I see the following a lot in the log:

[2012/03/15 11:33:41.060008,  1] smbd/service.c:769(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2012/03/15 11:33:41.080519,  1] smbd/service.c:769(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2012/03/15 11:33:41.080987,  1] smbd/service.c:769(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2012/03/15 11:33:41.081443,  1] smbd/service.c:769(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2012/03/15 11:33:41.081906,  1] smbd/service.c:769(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2012/03/15 11:33:41.082364,  1] smbd/service.c:769(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2012/03/15 11:33:41.082839,  1] smbd/service.c:769(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2012/03/15 11:33:41.083414,  1] smbd/service.c:769(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2012/03/15 11:33:41.088356,  1] smbd/service.c:769(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2012/03/15 11:33:41.088820,  1] smbd/service.c:769(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2012/03/15 11:33:41.089281,  1] smbd/service.c:769(make_connection_snum)

We do not see it from Windows 7 machines. On XP machines we see a lot of 
outlook.pst files give the following error:

"Cannot display folder. The file P:|Outlook|outlook.ost cannot be
accessed because another workstation has modified it. Close and then
restart all mail-enabled applications. You might need to restart your
computer"

Only the outlook files seem to gripe... so far.
--mike
Comment 1 Volker Lendecke 2012-03-15 16:21:55 UTC 
Did you compile with the SUN compiler? If so, please retry with gcc.
Comment 2 Mike Moya 2012-03-15 17:13:01 UTC 
I recompiled with gcc:

./configure  \
        --prefix=/opt/${PACKAGE}/${VERSION} \
        --enable-socket-wrapper \
        --localstatedir=/var/samba \
        --with-acl-support \
        --with-aio-support \
        --with-configdir=/etc \
        --with-pam \
        --with-privatedir=/etc \
        --with-quotas \
        --with-sendfile-support \
        --without-syslog \
        --without-winbind \
        --with-static-modules=vfs_zfsacl \
        --without-ads \
        --without-ldap

No difference. smbclient fails in the same way. Shares from XP/MacOS/Win 7 work 
normally. I am unable to test the outlook.pst issue until after lunch when some users get back.
--mike
Comment 3 Jeremy Allison 2012-03-15 17:32:09 UTC 
Debug level 10 log please.
Comment 4 Mike Moya 2012-03-15 17:34:03 UTC 
I am seeing this error in the log now for Windows XP users. Which is odd. I
am not using a domain controller:

[2012/03/15 13:31:27.754357,  1] ../librpc/ndr/ndr.c:414(ndr_pull_error)
  ndr_pull_error(11): Pull bytes 8 (../librpc/ndr/ndr_basic.c:268)
[2012/03/15 13:31:28.646033,  1] ../librpc/ndr/ndr.c:414(ndr_pull_error)
  ndr_pull_error(11): Pull bytes 8 (../librpc/ndr/ndr_basic.c:268)
[2012/03/15 13:31:29.469788,  1] ../librpc/ndr/ndr.c:414(ndr_pull_error)
  ndr_pull_error(11): Pull bytes 8 (../librpc/ndr/ndr_basic.c:268)
[2012/03/15 13:31:31.246791,  1] ../librpc/ndr/ndr.c:414(ndr_pull_error)
  ndr_pull_error(11): Pull bytes 8 (../librpc/ndr/ndr_basic.c:268)
[2012/03/15 13:31:33.246088,  1] ../librpc/ndr/ndr.c:414(ndr_pull_error)
  ndr_pull_error(11): Pull bytes 8 (../librpc/ndr/ndr_basic.c:268)
[2012/03/15 13:31:33.608285,  1] ../librpc/ndr/ndr.c:414(ndr_pull_error)
  ndr_pull_error(11): Pull bytes 8 (../librpc/ndr/ndr_basic.c:268)
[2012/03/15 13:31:33.694687,  0] lib/fault.c:47(fault_report)
  ===============================================================
[2012/03/15 13:31:33.694746,  0] lib/fault.c:48(fault_report)
  INTERNAL ERROR: Signal 11 in pid 26065 (3.6.3)
  Please read the Trouble-Shooting section of the Samba3-HOWTO
[2012/03/15 13:31:33.694781,  0] lib/fault.c:50(fault_report)
  
  From: http://www.samba.org/samba/docs/Samba3-HOWTO.pdf
[2012/03/15 13:31:33.694814,  0] lib/fault.c:51(fault_report)
  ===============================================================
[2012/03/15 13:31:33.694836,  0] lib/util.c:1117(smb_panic)
  PANIC (pid 26065): internal error
[2012/03/15 13:31:33.694875,  0] lib/util.c:1271(log_stack_trace)
  unable to produce a stack trace on this platform
[2012/03/15 13:31:33.694924,  0] lib/fault.c:372(dump_core)
  dumping core in /var/samba/cores/smbd
Comment 5 Mike Moya 2012-03-15 17:39:19 UTC 
Created attachment 7388 [details]
debug level 10 logfile

Here is the log
Comment 6 Mike Moya 2012-03-15 19:15:05 UTC 
For Windows XP machines the following three filetypes seem to be affected via samba 3.6.3 mounts:

Outlook's pst and ost .tmp (format:
~filename.pst.tmp
~filename.ost.tmp

Firefox's .json OR .sqlite files

TBird's panacea.dat

All seem to be DB files ...
Comment 7 Mike Moya 2012-03-15 20:26:52 UTC 
Removing:

write cache size = 262144

from smb.conf seems to fix the issue with DB files. It worked fine under 3.5.13 however. The smbclient problem remains. I am reverting back to v3.5.13 at this point as the villagers are coming for me with pitchforks ...
Comment 8 Mike Moya 2012-03-15 20:46:06 UTC 
Version 3.5.13 works as expected:

breakwater:/home/pier/a/moyman[1] smbclient //archive.ecn.purdue.edu/moyman -U moyman
Enter moyman's password: 
Domain=[ECN] OS=[Unix] Server=[Samba 3.5.13]
smb: \> quit

I have left a few test machines with 3.6.3 so I can continue working this issue.
Note that as long as the client is 3.5.13 it will connect with a 3.6.3 machine:

breakwater:/home/pier/a/moyman[2] smbclient //pier.ecn.purdue.edu/moyman -U moyman
Enter moyman's password: 
Domain=[ECN] OS=[Unix] Server=[Samba 3.6.3]
smb: \> quit

In reverse fails however (the client being 3.6.3):

pier:/home/pier/a/moyman[238] smbclient //breakwater.ecn.purdue.edu/moyman -U moyman
Enter moyman's password: 
session setup failed: NT_STATUS_LOGON_FAILURE

--mike
Comment 9 Mike Moya 2012-11-05 21:52:20 UTC 
I just downloaded and installed v3.6.8 (and then 3.6.9). This issue is fixed in both versions. Never heard anything back from submision of this item however. I have resolved the item.