[Samba] Certain systems can no longer access samba post upgrade to 4.3.9

[Jeff Hodge]

On Tue, Aug 30, 2016 at 11:57 AM, Jeff Hodge <jeff.hodge55 at gmail.com> wrote:

> On Mon, Aug 29, 2016 at 6:13 PM, Jeremy Allison <jra at samba.org> wrote:
>
>> On Mon, Aug 29, 2016 at 11:41:53AM -0400, Jeff Hodge via samba wrote:
>> > During an ubuntu 14.04 update samba was updated from 4.1.6 to 4.3.9.  We
>> > had no problems with any windows system accessing the server prior to
>> the
>> > upgrade to 4.3.9.  It seems to affect access to the entire samba server
>> as
>> > no shares are able to be seen or accessed when trying to view
>> \\servername
>> > or \\servname.domain.local
>> >
>> > The "fix" seems to be to use the fully qualified name, but after a while
>> > that will stop working and you have to change to the short name and vice
>> > versa.  I am trying to correlate the times to see if there is a pattern,
>> > but no pattern has emerged yet.
>> >
>> > What is odd is if the short name is failing and you change to fully
>> > qualified and the share comes up, you will then be able to use the short
>> > name to pull up the share after you have made the successful connection
>> to
>> > the fully qualified name.
>> >
>> > The one log entry that seems to identify systems with this issue is
>> this,
>> > repeated over and over:
>> >
>> > [2016/08/29 08:35:56.694436,  0]
>> > ../source3/param/loadparm.c:1460(canonicalize_servicename)
>> >   canonicalize_servicename: NULL source name!
>> >
>> > [2016/08/29 08:35:57.694984,  0]
>> > ../source3/param/loadparm.c:1460(canonicalize_servicename)
>> >   canonicalize_servicename: NULL source name!
>> >
>> > [2016/08/29 08:35:58.694495,  0]
>> > ../source3/param/loadparm.c:1460(canonicalize_servicename)
>> >   canonicalize_servicename: NULL source name!
>> >
>> > The majority of our servers are not having any problems accessing the
>> samba
>> > shares, but a few key high use systems are having this issue.
>> >
>> > Has anyone seen this error and may have an idea what may be causing and
>> > possible system setting that may need to be changed/enabled in 4.3.9 to
>> > allow all systems to connect reliably?
>>
>> Can you post your smb.conf, plus a debug level 10 log from one
>> of the machines having the problem ?
>>
>
> It seems a workaround is to to set guest ok = yes on the user share.  We
> have not seen the error since we made that change.
>
> We also changed another share from user share to one configured in the
> smb.conf file and have not seen the issue on that server since yesterday.
> This may be a more permanent fix as we did not have to set guest ok = yes
> on its share.
>
> I will try to get an output of the logs at log level 10, however I have
> been unable to reproduce this in our Dev environment.  Which class do you
> want me to set logging level 10 on, or to be safe just use all?
>
> Here is the smb.conf file in case anyone sees anything in there:
>
> [global]
> security = ads
> netbios name = server104
> netbios aliases = server04
> realm = DOMAIN.LOCAL
> idmap config * : range = 500-10000000
> idmap config * : backend = tdb
> winbind enum users = no
> winbind enum groups = no
> winbind refresh tickets = true
> template homedir = /home/%D/%U
> template shell = /bin/bash
> client use spnego = yes
> domain master = no
> create mask = 0664
> directory mask = 0775
> machine password timeout = 0
> hosts deny = 172.17.4.0/255.255.255.0
> interfaces = eth1
> bind interfaces only = yes
> winbind max clients = 1000
> winbind max domain connections = 10
> log level = 1
>
>    workgroup = DOMAIN
>    server string = %h server (Samba, Ubuntu)
>    dns proxy = no
>    log file = /var/log/samba/log.%m
>    max log size = 1000
>    syslog = 0
>    panic action = /usr/share/samba/panic-action %d
>    encrypt passwords = true
>    passdb backend = tdbsam
>    obey pam restrictions = yes
>    unix password sync = yes
>    passwd program = /usr/bin/passwd %u
>    passwd chat = *Enter\snew\s*\spassword:* %n\n
> *Retype\snew\s*\spassword:* %n\n *password\supdated\ssuccessfully* .
>    pam password change = yes
>    map to guest = bad user
>    usershare allow guests = yes
>
> [printers]
>    comment = All Printers
>    browseable = no
>    path = /var/spool/samba
>    printable = yes
>    guest ok = no
>    read only = yes
>    create mask = 0700
> [print$]
>    comment = Printer Drivers
>    path = /var/lib/samba/printers
>    browseable = yes
>    read only = yes
>    guest ok = no
>
>
> User share:
>
> #VERSION 2
> path=/home/DOMAIN/
> comment=
> usershare_acl=S-1-1-0:F
> guest ok = yes
>
>
>
>
We were able to reproduce the incident in dev.  Here are the log entries
with log level set to 10, this repeats over and over:


[2016/08/31 08:00:40.640956, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/smb2_server.c:3539(smbd_smb2_io_handler)
  smbd_smb2_request idx[1] of 5 vectors
[2016/08/31 08:00:40.641051, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/smb2_server.c:654(smb2_validate_sequence_number)
  smb2_validate_sequence_number: clearing id 66899 (position 1363) from
bitmap
[2016/08/31 08:00:40.641074, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/smb2_server.c:2018(smbd_smb2_request_dispatch)
  smbd_smb2_request_dispatch: opcode[SMB2_OP_CREATE] mid = 66899
[2016/08/31 08:00:40.641105, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/share_access.c:237(user_ok_token)
  user_ok_token: share (null) is ok for unix user DOMAIN\ish-prd-svc
[2016/08/31 08:00:40.641123, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/share_access.c:284(is_share_read_only_for_token)
  is_share_read_only_for_user: share (null) is read-write for unix user
DOMAIN\ish-prd-svc
[2016/08/31 08:00:40.641139,  0, pid=6463, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1460(canonicalize_servicename)
  canonicalize_servicename: NULL source name!
[2016/08/31 08:00:40.641155,  3, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/uid.c:153(check_user_share_access)
  user DOMAIN\ish-prd-svc connection to (null) denied due to share security
descriptor.
[2016/08/31 08:00:40.641169,  2, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/uid.c:302(change_to_user_internal)
  SMB user ish-prd-svc (unix user DOMAIN\ish-prd-svc) not permitted access
to share (null).
[2016/08/31 08:00:40.641183, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/smb2_server.c:2789(smbd_smb2_request_error_ex)
  smbd_smb2_request_error_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] || at
../source3/smbd/smb2_server.c:2207
[2016/08/31 08:00:40.641203, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/smb2_server.c:2680(smbd_smb2_request_done_ex)
  smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_ACCESS_DENIED] body[8]
dyn[yes:1] at ../source3/smbd/smb2_server.c:2837
[2016/08/31 08:00:40.641255, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/smb2_server.c:906(smb2_set_operation_credit)
  smb2_set_operation_credit: requested 1, charge 1, granted 1, current
possible/max 482/512, total granted/max/low/range 31/8192/66900/31
[2016/08/31 08:00:45.641465, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/smb2_server.c:3539(smbd_smb2_io_handler)
  smbd_smb2_request idx[1] of 5 vectors
[2016/08/31 08:00:45.641551, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/smb2_server.c:654(smb2_validate_sequence_number)
  smb2_validate_sequence_number: clearing id 66900 (position 1364) from
bitmap
[2016/08/31 08:00:45.641575, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/smb2_server.c:2018(smbd_smb2_request_dispatch)
  smbd_smb2_request_dispatch: opcode[SMB2_OP_CREATE] mid = 66900
[2016/08/31 08:00:45.641606, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/share_access.c:237(user_ok_token)
  user_ok_token: share (null) is ok for unix user DOMAIN\ish-prd-svc
[2016/08/31 08:00:45.641624, 10, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/share_access.c:284(is_share_read_only_for_token)
  is_share_read_only_for_user: share (null) is read-write for unix user
DOMAIN\ish-prd-svc
[2016/08/31 08:00:45.641639,  0, pid=6463, effective(0, 0), real(0, 0)]
../source3/param/loadparm.c:1460(canonicalize_servicename)
  canonicalize_servicename: NULL source name!
[2016/08/31 08:00:45.641655,  3, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/uid.c:153(check_user_share_access)
  user DOMAIN\ish-prd-svc connection to (null) denied due to share security
descriptor.
[2016/08/31 08:00:45.641669,  2, pid=6463, effective(0, 0), real(0, 0)]
../source3/smbd/uid.c:302(change_to_user_internal)
  SMB user ish-prd-svc (unix user DOMAIN\ish-prd-svc) not permitted access
to share (null).