[Samba] dfree is broken on this system

[Thomas Schulz]

> 
>> On Tue, Jun 07, 2016 at 01:36:52PM -0400, Thomas Schulz wrote:
>>> Running Samba 4.3.4 on a Solaris 10 i386 box and Samba 4.4.3 on a
>>> Solaris 10 sparc box.
>>> I have not looked at the logs for awhile. Just checking now and I see
>>> many of the following on both systems.
>>> 
>>> [2016/06/01 11:22:04.402945,  0] ../source3/smbd/dfree.c:139(sys_disk_free)
>>>   WARNING: dfree is broken on this system
>>> 
>>> What could be the cause of this?
>> 
>> The code that creates this is:
>> 
>>         if ((*dsize)<1) {
>>                 if (!dfree_broken) {
>>                         DEBUG(0,("WARNING: dfree is broken on this system\n"));
>>                         dfree_broken=true;
>>                 }
>> 
>> 
>> Where dsize is calculated as:
>> 
>>         if (disk_quotas(path, &bsize_q, &dfree_q, &dsize_q)) {
>>                 uint64_t min_bsize = MIN(*bsize, bsize_q);
>> 
>>                 (*dfree) = (*dfree) * (*bsize) / min_bsize;
>>                 (*dsize) = (*dsize) * (*bsize) / min_bsize;
>>                 dfree_q = dfree_q * bsize_q / min_bsize;
>>                 dsize_q = dsize_q * bsize_q / min_bsize;
>> 
>>                 (*bsize) = min_bsize;
>>                 (*dfree) = MIN(*dfree,dfree_q);
>>                 (*dsize) = MIN(*dsize,dsize_q);
>>         }
>> 
>> Can you add DEBUG statements to see what is
>> going on in Solaris 10 here ?
> 
> I added debuging as follows:
> 
> --- dfree.c.orig        2016-02-09 04:40:29.000000000 -0500
> +++ dfree.c     2016-06-08 11:48:05.267240000 -0400
> @@ -121,12 +121,19 @@
>                 DBG_ERR("VFS disk_free failed. Error was : %s\n",
>                         strerror(errno));
>                 return (uint64_t)-1;
>         }
>  
> +       if (!dfree_broken) {
> +               DEBUG (0, ("dsize %u bsize %u dfree %u \n", (*dsize), (*bsize), (*dfree) ));
> +       }
> +
>         if (disk_quotas(conn, path, &bsize_q, &dfree_q, &dsize_q)) {
>                 uint64_t min_bsize = MIN(*bsize, bsize_q);
> +               if (!dfree_broken) {
> +                       DEBUG (0, ("dsize %u bsize %u dfree %u dsize_q %u bsize_q %u dfree_q %u \n", (*dsize), (*bsize), (*dfree), dsize_q, bsize_q, dfree_q));
> +               }
>  
>                 (*dfree) = (*dfree) * (*bsize) / min_bsize;
>                 (*dsize) = (*dsize) * (*bsize) / min_bsize;
>                 dfree_q = dfree_q * bsize_q / min_bsize;
>                 dsize_q = dsize_q * bsize_q / min_bsize;
> 
> So far the error has not been logged. I am getting output such as:
> 
> [2016/06/08 11:56:52.493274,  0] ../source3/smbd/dfree.c:127(sys_disk_free)
>   dsize 0 bsize 1143062772 dfree 0 
> 
> [2016/06/08 12:01:50.331024,  0] ../source3/smbd/dfree.c:127(sys_disk_free)
>   dsize 0 bsize 1795693380 dfree 0 
> 
> I will wait until the error is logged and then see what things look like.
> Perhaps degugging statements in different locations will be needed.

I finally got the error. The following was logged:

[2016/06/09 11:19:00.350226,  0] ../source3/smbd/dfree.c:127(sys_disk_free)
  dsize 0 bsize 0 dfree 0 
[2016/06/09 11:19:00.355547,  0] ../source3/smbd/dfree.c:154(sys_disk_free)
  WARNING: dfree is broken on this system

Note that the second debug statement is not hit which makes sense as 
quotas are not enabled. But that should mean that none of those
calculations are done. So bsize being 0 should not change the value of
dfree. I have no idea why all of those values are 0. Am I using DEBUG
correctly? I have added a third debug statement and have debugging as
follows:

--- dfree.c.orig        2016-02-09 04:40:29.000000000 -0500
+++ dfree.c     2016-06-09 13:07:02.491325000 -0400
@@ -123,8 +123,15 @@
                return (uint64_t)-1;
        }
 
+       if (!dfree_broken) {
+               DEBUG (0, ("dsize %u bsize %u dfree %u \n", (*dsize), (*bsize), (*dfree) ));
+       }
+
        if (disk_quotas(conn, path, &bsize_q, &dfree_q, &dsize_q)) {
                uint64_t min_bsize = MIN(*bsize, bsize_q);
+               if (!dfree_broken) {
+                       DEBUG (0, ("dsize %u bsize %u dfree %u dsize_q %u bsize_q %u dfree_q %u \n", (*dsize), (*bsize), (*dfree), dsize_q, bsize_q, dfree_q));
+               }
 
                (*dfree) = (*dfree) * (*bsize) / min_bsize;
                (*dsize) = (*dsize) * (*bsize) / min_bsize;
@@ -136,6 +143,10 @@
                (*dsize) = MIN(*dsize,dsize_q);
        }
 
+       if (!dfree_broken) {
+               DEBUG (0, ("dsize %u bsize %u dfree %u \n", (*dsize), (*bsize), (*dfree) ));
+       }
+
        /* FIXME : Any reason for this assumption ? */
        if (*bsize < 256) {
                DEBUG(5,("disk_free:Warning: bsize == %d < 256 . Changing to assumed correct bsize = 512\n",(int)*bsize));


Tom Schulz
Applied Dynamics Intl.
schulz at adi.com