SOLVED SMB shares suddenly read only [or how to troubleshoot samba?]

[Pitfrr]

Hello,

I got an odd behavior on my system and I'd be interested to understand it.
I tried to search the forum and online but I get results mainly focusing on creating shares and such... :-O
I did find some information thought and I used it to try to understand what's happening (see below).

TL;DR summary: SMB share working fine, server does hard reboot (nothing else noticeable), SMB share in read only... What happened? How can I troubleshoot it? (trying to understand)


Context:
I have a main FreeNAS server (v9.3.10, 64GB RAM, Xeon x5760), one user defined (say user1) with several datasets, every dataset has user1 as owner.
SMB shares exist for the datasets.
Nothing fancy, it's a one user set-up and worked very well so far.
There is a backup FreeNAS server (v9.3.10), same user configured (UID and GID are the same), same datasets with user1 as owner.
Client is a windows computer.

Issue:
All of a sudden I only have read access on the SMB shares on the main server with user1.
From a client's perspective, nothing changed.
From a server's perspective: I experience a hard reboot in the morning, that is the only noticeable thing that happened. Don't know if it is linked somehow.

Investigations:
On the backup system:
I tested the shares on the backup server (with user1), works fine.

On the main system:
I tested using a different clients (windows 7, 10 and Linux) with user1 on the main server: only read access.
I created a new dataset, configured with user1 as owner: only read access.
Created a new user, change the owner of the new dataset to this new user: write access.
When accessing over SSH, on the different datasets, the owner is set correclty (user1 for existing datasets or new user for new dataset). So it appears that at system level (linux access rights) it works as expected, so it might be somewhere at samba level that something's not right...

Few things I checked:

• I ran a scrub of the boot drive, no errors (I thought maybe the hard reboot might have get some files corrupted on the boot drive?).
• I checked /etc/local/smb4.conf: they are identical on both servers (main and backup).
• Ran getfacl /mnt/tank/new_dataset, nothing out of order, I get an output like:

Code:

getfacl /mnt/tank/new_dataset/​
# file: /mnt/tank/new_dataset/​
# owner: user1​
# group: workgroup​
owner@:rwxp--aARWcCos:-------:allow​
group@:r-x---a-R-c--s:-------:allow​
everyone@:r-x---a-R-c--s:-------:allow​

​

• Ran pdbedit -L -v -u user1. Outputs are similar for both servers (besides of the user SID and primary group SID, which seems to be expected (I thought first I might have an SID problem but I'm not sure anymore).
• Tried pdbedit -a -u user1 on the main server but didn't have any effect, still only read access.
• Had a look at the samba logs in /var/log/samba4. I'm not saying I understand them! But I compared them with the logs on the backup server and I couldn't see anything really different...

Question:
I'm not familiar with investigating samba and I only have a limited understanding of it... (so far it worked great! :-O) I gathered some pieces from searches but this might not be a very consistent approach.
But this is a good opportunity to understand it better and I'd like to have some guidance in troubleshooting it.

What would be the steps to troubleshoot a problem like that?
So far I have the feeling there is something wrong at samba level with user1 on the main server but I can't pinpoint it.

I could delete user1 and recreate it, it might fix the issue... But before doing that, I'd like to try to understand what's happening, if possible...


Thanks for your guidance.

 

[Samuel Tai]

Look at /var/log/samba4/log.smbd, and try to find a timestamp where write access was denied. This will allow us to see what Samba is complaining about.

 

[Pitfrr]

I just tried it (stopping SMB service, restarting it, connect to the share and get the logs):

log.smdb:

Code:

[2020/08/12 21:42:23.207755,  1] ../source3/smbd/files.c:218(file_init_global)
  file_init_global: Information only: requested 1886546 open files, 59392 are available.
[2020/08/12 21:42:23.212952,  0] ../lib/util/become_daemon.c:124(daemon_ready)
  STATUS=daemon 'smbd' finished starting up and ready to serve connections
[2020/08/14 12:15:59.763116,  1] ../source3/profile/profile_dummy.c:30(set_profile_level)
  INFO: Profiling support unavailable in this build.
[2020/08/14 12:15:59.808223,  1] ../source3/smbd/files.c:218(file_init_global)
  file_init_global: Information only: requested 1886546 open files, 59392 are available.
[2020/08/14 12:15:59.813500,  0] ../lib/util/become_daemon.c:124(daemon_ready)
  STATUS=daemon 'smbd' finished starting up and ready to serve connections

I left the two previous entries from 2 days ago... The latest entries can be found also in the beginning of the log (in May 2020).

I looked in the other logs; but nothing out of the ordinary (i.e. nothing that wouldn't have happened earlier in the log, when the share was working).
For example I get an Error allocating a new GID in log.winbindd-idmap; I thought I might have something.... but if I scroll up this entry is already visible since May 2020.


It looks like from a log perspective, everything is fine (I mean compared to when it was working)...

 

[Pitfrr]

I've noticed something else... Not sure if it is relevant or not but in case... since I haven't paid attention to this before, when it was working!

With the client (under Windows), the properties of a file are shown differently regarding permissions:
(Sorry for the screenshots in French...)

• Properties of a file in a usual share for user1:

"Noms de groupe ou d'utilisateurs" = User or group names​

"Tout le monde" = every one​

"Compte inconnu" = unknown account​

• Properties of a file in a new share with new user

The unknown account is still visible but here the New User is shown, i.e. identified.​

So this made me think that somehow, user1 from the client is not being identified as user1 from FreeNAS?
It's not from the client since I tried with different clients (Windows 7 and 10 and Linux).
Could it be that samba lost the relation between the FreeNAS account and the samba one (if there is such relation; I guess there is)?
This reminds me of a post I read about inconsistencies in group_mapping.tbd...

Looking at the groupmap list I get:

Code:

[MainServer] ~# net groupmap list
ptaz (S-1-5-21-2221559132-1605505609-2342738714-1002) -> ros
ptaze (S-1-5-21-2221559132-1605505609-2342738714-1003) -> invite
syncthing (S-1-5-21-2784862403-693382680-3867564476-1004) -> syncthing

[BackupServer] ~# net groupmap list
ros (S-1-5-21-714365010-1030576331-567247994-1002) -> ros
syncthing (S-1-5-21-714365010-1030576331-567247994-1001) -> syncthing

I don't quite get it... :-O
Is this mapping only done for groups or also for users?

 

[Pitfrr]

I did focus on the user mapping and the tdb files of samba.

I ran some diagnostics with tdbbackup, but it didn't find any problems on the tdb files.
So I tried first deleting group_mapping.tdb but I still had the same behavior, i.e. read access only.

Ok, then I got a bit impatient and I deleted all the tdb files... :-O
I wasn't sure about how these files were created, couldn't find much information on that (I found (later on! ) that some of these files are temporary and other persistent...). So I didn't know what behavior to expect.
Maybe not advisable in a professional environment but for home usage...

Anyway, it turned out it fixed my issue! I can write to the shares again.

What is still unclear is how did this happen?
I guess I'll never find out, not sure if the hard reboot was the cause, but I'd be surprised, it happened at 6.00 in the morning and there were no access to the shares (so I'd guess no reason for the system to open a .tdb file that might get corrupted during the reboot).