process killed: text file modification

[Gergely Czuczy]

On 2017. 03. 09. 19:44, John Baldwin wrote:
> On Thursday, March 09, 2017 03:31:56 PM Gergely Czuczy wrote:
>> [+freebsd-fs]
>>
>>
>> On 2017. 03. 09. 14:20, Gergely Czuczy wrote:
>>> On 2017. 03. 09. 11:27, Gergely Czuczy wrote:
>>>> Hello,
>>>>
>>>> I'm trying to build a few things from ports on an rpi3, the ports
>>>> collection is mounted over NFS from another machine. When it's trying
>>>> to build pkg i'm getting the error message in syslog:
>>>>
>>>> rpi3 kernel: pid 4451 (sh), uid 0, was killed: text file modification
>>>>
>>>> The report to pkg@:
>>>> https://lists.freebsd.org/pipermail/freebsd-pkg/2017-March/002048.html
>>>>
>>>> In ports-mgmt/pkg's config.log It fails at the following entry:
>>>> configure:3726: checking whether we are cross compiling
>>>> configure:3734: cc -o conftest -O2 -pipe  -Wno-error
>>>> -fno-strict-aliasing   conftest.c  >&5
>>>> configure:3738: $? = 0
>>>> configure:3745: ./conftest
>>>> configure:3749: $? = 137
>>>> configure:3756: error: in `/usr/ports/ports-mgmt/pkg/work/pkg-1.10.0':
>>>> configure:3760: error: cannot run C compiled programs.
>>>> If you meant to cross compile, use `--host'.
>>>> See `config.log' for more details
>>>>
>>>> # uname -a
>>>> FreeBSD rpi3 12.0-CURRENT FreeBSD 12.0-CURRENT #0 r314949: Thu Mar 9
>>>> 08:58:46 CET 2017
>>>> aegir at marvin.harmless.hu:/tank/rpi3/crochet/work/obj/arm64.aarch64/tank/rpi3/src/sys/AEGIR
>>>> arm64
>>> So far, a few additions:
>>> Time is synced between the NFS server and the client.
>>> it's an open() call which is getting the kill, and it's not the file
>>> what's being opened, but the process executing it.
>>> Here's a simple code that reproduces it:
>>> #include <stdio.h>
>>>
>>> int main() {
>>>
>>>    FILE *f = fopen ("/bar", "w");
>>>
>>>    fclose(f);
>>>    return 0;
>>> }
>>>
>>> Conditions to reproduce it:
>>>   - The resulting binary must be executed from the nfs mount
>>>   - The binary must be built after mounting the NFS share.
>>>
>>> I haven't tried building it on a different host, I don't have access
>>> to multiple RPis. Also, if I build the binary, umount/remount the NFS
>>> mount point, which has the binary, execute it, then it works.
>>>
>>> I've also tried this with the raspbsd.org's image, I could reproduce
>>> it as well.
>>>
>>> Another interesting thing is, when I first booted the RPi up, the NFS
>>> server was a 10.2-STABLE, and later got updated to 11-STABLE. While it
>>> was 10.2 I've tried to build some port, and I don't remember having
>>> this issue.
>>>
>>> So, could someone please help me figure this out and fix it? This
>>> stuff should work pretty much.
>>>
>> So, this error message comes from here:
>> https://svnweb.freebsd.org/base/head/sys/fs/nfsclient/nfs_clbio.c?revision=314436&view=markup#l1674
>>
>> It's the NFS_TIMESPEC_COMPARE(&np->n_mtime, &np->n_vattr.na_mtime)
>> comparision that fails, np should be the NFS node structure, from the
>> vnode's v_data, and n_vattr is the attribute cache. As I've seen these
>> two are being updated together, so I don't really see by the code why
>> they might differ. Could someone please take a look at it, with more
>> experience in the NFS code? -czg
> Can you print out the two mtimes?  I wonder if what's happening is that
> your server uses different granularity (for example just seconds) than
> your client, so on the client we generate a timestamp with a non-zero
> nanoseconds but when the server receives that timestamp it "truncates"
> it.  During open() we forcefully re-fetch the timestamp (for CTO
> consistency) and then notice it doesn't match.  For now I would start
> with comparing the timestamps and maybe the vfs.timestamp_precision
> sysctls on client and server (if server is a FreeBSD box).
Here are the time values:
Mar  9 19:46:01 rpi3 kernel: np->n_mtime: -3298114786344 + 
-3298114786336  &np->n_vattr.na_mtime: -3298114786616 + -3298114786608
Mar  9 19:46:01 rpi3 kernel: pid 912 (csh), uid 0, was killed: text file 
modification
Mar  9 19:46:01 rpi3 kernel: np->n_mtime: -3298114786344 + 
-3298114786336  &np->n_vattr.na_mtime: -3298114786616 + -3298114786608
Mar  9 19:46:01 rpi3 kernel: pid 912 (csh), uid 0, was killed: text file 
modification

Printed this way:
                          printf("np->n_mtime: %ji + %ji 
&np->n_vattr.na_mtime: %ji + %ji",
(intmax_t)(&np->n_mtime.tv_sec),
(intmax_t)(&np->n_mtime.tv_nsec),
(intmax_t)(&np->n_vattr.na_mtime.tv_sec),
(intmax_t)(&np->n_vattr.na_mtime.tv_nsec));