Date: Thu, 9 Mar 2017 21:07:59 +0100 From: Gergely Czuczy <gergely.czuczy@harmless.hu> To: freebsd-current@freebsd.org Subject: Re: process killed: text file modification Message-ID: <5ac94b9a-7ced-9eff-d746-7dddaaeca516@harmless.hu> In-Reply-To: <3ed3e4a3-23af-7267-39f1-9090093c9c1e@harmless.hu> References: <d4d04499-17f8-e3d7-181f-c8ee8285e32b@harmless.hu> <646c1395-9482-b214-118c-01573243ae5a@harmless.hu> <45436522-77df-f894-0569-737a6a74958f@harmless.hu> <55189643.aaZPuY77s8@ralph.baldwin.cx> <3ed3e4a3-23af-7267-39f1-9090093c9c1e@harmless.hu>
next in thread | previous in thread | raw e-mail | index | archive | help
On 2017. 03. 09. 20:47, Gergely Czuczy wrote: > > > 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@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)); Sorry, I made a typo there. Here's it now: Mar 9 20:05:35 rpi3 kernel: np->n_mtime: 1489089935 + 219323000 &np->n_vattr.na_mtime: 1489089935 + 221438000 Mar 9 20:05:35 rpi3 kernel: pid 847 (csh), uid 0, was killed: text file modification Mar 9 20:05:35 rpi3 kernel: np->n_mtime: 1489089935 + 219323000 &np->n_vattr.na_mtime: 1489089935 + 221438000 Mar 9 20:05:35 rpi3 kernel: pid 847 (csh), uid 0, was killed: text file modification That's a difference of 2115 micro seconds.
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?5ac94b9a-7ced-9eff-d746-7dddaaeca516>