Bug 8814 - smbclient fails to authenticate/other .pst auth issues
smbclient fails to authenticate/other .pst auth issues
Status: RESOLVED FIXED
Product: Samba 3.6
Classification: Unclassified
Component: Client Tools
3.6.3
x86 Solaris
: P5 critical
: ---
Assigned To: Volker Lendecke
Samba QA Contact
:
Depends on:
Blocks:
  Show dependency treegraph
 
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

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.