Bug 10382

Summary: master - nightly-mips-lsb failed
Product: [Build System, Metadata & Runtime] OE-Core Reporter: Armin Kuster <akuster>
Component: coreAssignee: Michael Halstead <mhalstead>
Status: RESOLVED FIXED QA Contact:
Severity: normal    
Priority: Medium+ CC: joshuagloe, juro.bystricky, meta.mr.watcher, meta.watcher, randy.macleod, richard.purdie, sgw
Version: 2.3   
Target Milestone: 2.3 M4   
Hardware: x86   
OS: Multiple   
Whiteboard:
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: Don't know

Description Armin Kuster 2016-10-05 19:16:39 UTC
I think the error is:

chmod: cannot access '/srv/www/vhosts/autobuilder.yoctoproject.org/pub/sstate//34/sstate:qt4-x11-free:mips64-poky-linux:4.8.7:r0:mips64:3:34565079648564b3be7ab62e8c2792fd_package_write_deb.tgz.PEDDKJ9E': No such file or directory
Comment 1 Joshua Lock 2016-10-06 15:20:57 UTC
It's unclear whether this is host distro specific but FWIW this failure occurred on the Fedora 24 builder.

I think this could be a case for Randy's container hammer to see if we can reproduce this outside of the AB.
Comment 2 Juro Bystricky 2016-10-06 16:59:45 UTC
AFAIK this is a NFS issue, maybe this can be of some help:
http://serverfault.com/questions/380303/nfs-cache-file-content-not-updated-on-client-when-modified-on-server
Comment 3 Armin Kuster 2016-10-24 18:06:47 UTC
the last build I ran passed this step.
Comment 4 Joshua Lock 2017-03-02 11:13:42 UTC
Saw this again today:

chmod: cannot access '/srv/www/vhosts/autobuilder.yoctoproject.org/pub/sstate//0c/sstate:ltp:core2-32-poky-linux:20170116:r0:core2-32:3:0cbfc25a900f18f344510cc73f2587d8_package.tgz.pG3pEGVK': No such file or directory
| WARNING: /home/pokybuild/yocto-autobuilder/yocto-worker/nightly-x86-lsb/build/build/tmp/work/core2-32-poky-linux/ltp/20170116-r0/temp/run.sstate_create_package.32435:1 exit 1 from 'chmod 0664 $TFILE'
Comment 5 Joshua Lock 2017-03-02 11:15:52 UTC
*** Bug 8302 has been marked as a duplicate of this bug. ***
Comment 6 Richard Purdie 2017-03-09 22:34:29 UTC
To quote me:

"""
We suffered one of our odd failures:

https://autobuilder.yoctoproject.org/main/builders/nightly-world-lsb/builds/810/steps/BuildImages/logs/stdio

| DEBUG: Executing shell function sstate_create_package
| chmod: cannot access '/srv/www/vhosts/autobuilder.yoctoproject.org/pub/sstate/multilib/3e/sstate:valgrind:i586-poky-linux:3.12.0:r0:i586:3:3e5b62dfa07f8c42024b234b3d19c461_package.tgz.pHNHxSTj': No such file or directory
| WARNING: /home/pokybuild/yocto-autobuilder/yocto-worker/nightly-world-lsb/build/build/tmp/work/i586-poky-linux/valgrind/3.12.0-r0/temp/run.sstate_create_package.11293:1 exit 1 from 'chmod 0664 $TFILE'
| DEBUG: Python function sstate_task_postfunc finished

so the file disappeared whilst we were trying to use it. We've puzzled
over what was causing this. With my recent change to log deletions,
I've a smoking gun:

root@nas01:/# grep 3e5b62 /root/sstate-atime.log 
/main/srv/vhosts/sstate.yoctoproject.org/multilib/3e/sstate:valgrind:i586-poky-linux:3.12.0:r0:i586:3:3e5b62dfa07f8c42024b234b3d19c461_package.tgz.pHNHxSTj

root@nas01:/# grep sstate /etc/cron.daily/*
/etc/cron.daily/cleanup:/usr/bin/find /main/srv/vhosts/sstate.yoctoproject.org -ctime +20 -type f -print -delete >> $HOME/sstate-ctime.log
/etc/cron.daily/cleanup:/usr/bin/find /main/srv/vhosts/sstate.yoctoproject.org -atime +10 -type f -print -delete >> $HOME/sstate-atime.log

So we do have some kind of a race in these commands and it *is* the
cleanup script which is deleting files which it shouldn't. I suspect
we're going to need to write a proper cleanup script to use instead.
"""
Comment 7 Richard Purdie 2017-03-09 23:20:57 UTC
At the very least we can change the command to look for -name *.tgz and -name *.siginfo and hence miss the tmp files.
Comment 8 Michael Halstead 2017-03-09 23:52:14 UTC
I've added the filename restrictions which should fix the problem for now. I'm gathering information about how much we can rely on atime and mtime over nfs now.
Comment 9 Michael Halstead 2017-03-10 02:35:33 UTC
Multiple tests with creating and appending to files on the nfs mount show that access, modify, and change times are generally working as expected on all builders.

At the same time, I see files in sstate that have access times set to the epoch which is odd. Do we clear the atime on purpose somehow?

  File: `/main/srv/vhosts/sstate.yoctoproject.org/00/sstate:xf86dgaproto:i586-poky-linux:2.1:r2:i586:3:00200b482a2cda4850face6bbd3af04c_install.tgz.siginfo'
  Size: 20494     	Blocks: 48         IO Block: 4096   regular file
Device: fc00h/64512d	Inode: 8693222995  Links: 1
Access: (0644/-rw-r--r--)  Uid: ( 1006/pokybuild)   Gid: (  100/   users)
Access: 1970-01-01 00:18:38.000000000 +0000
Modify: 2017-03-09 21:36:20.594788024 +0000
Change: 2017-03-09 21:36:20.594788024 +0000
 Birth: -


  File: `centos7.osl.yoctoproject.org'
  Size: 58        	Blocks: 8          IO Block: 4096   regular file
Device: fc00h/64512d	Inode: 4774403840  Links: 1
Access: (0644/-rw-r--r--)  Uid: ( 1006/pokybuild)   Gid: (  100/   users)
Access: 2017-03-10 02:10:55.098859798 +0000
Modify: 2017-03-10 02:13:37.581570905 +0000
Change: 2017-03-10 02:13:37.581570905 +0000
 Birth: -
  File: `debian8'
  Size: 16        	Blocks: 8          IO Block: 4096   regular file
Device: fc00h/64512d	Inode: 4774403843  Links: 1
Access: (0644/-rw-r--r--)  Uid: ( 1006/pokybuild)   Gid: (  100/   users)
Access: 2017-03-10 02:10:55.102859964 +0000
Modify: 2017-03-10 02:13:37.581570905 +0000
Change: 2017-03-10 02:13:37.581570905 +0000
 Birth: -
  File: `fedora24.osl.yoctoproject.org'
  Size: 60        	Blocks: 8          IO Block: 4096   regular file
Device: fc00h/64512d	Inode: 4774403842  Links: 1
Access: (0644/-rw-r--r--)  Uid: ( 1006/pokybuild)   Gid: (  100/   users)
Access: 2017-03-10 02:10:55.102859964 +0000
Modify: 2017-03-10 02:13:37.581570905 +0000
Change: 2017-03-10 02:13:37.581570905 +0000
 Birth: -
  File: `fedora25.osl.yoctoproject.org'
  Size: 60        	Blocks: 8          IO Block: 4096   regular file
Device: fc00h/64512d	Inode: 4774403845  Links: 1
Access: (0644/-rw-r--r--)  Uid: ( 1006/pokybuild)   Gid: (  100/   users)
Access: 2017-03-10 02:10:55.102859964 +0000
Modify: 2017-03-10 02:13:37.581570905 +0000
Change: 2017-03-10 02:13:37.581570905 +0000
 Birth: -
  File: `opensuse132'
  Size: 24        	Blocks: 8          IO Block: 4096   regular file
Device: fc00h/64512d	Inode: 4774403841  Links: 1
Access: (0644/-rw-r--r--)  Uid: ( 1006/pokybuild)   Gid: (  100/   users)
Access: 2017-03-10 02:10:55.098859798 +0000
Modify: 2017-03-10 02:13:37.581570905 +0000
Change: 2017-03-10 02:13:37.581570905 +0000
 Birth: -
  File: `ubuntu1604'
  Size: 22        	Blocks: 8          IO Block: 4096   regular file
Device: fc00h/64512d	Inode: 4774403844  Links: 1
Access: (0644/-rw-r--r--)  Uid: ( 1006/pokybuild)   Gid: (  100/   users)
Access: 2017-03-10 02:10:55.102859964 +0000
Modify: 2017-03-10 02:13:37.581570905 +0000
Change: 2017-03-10 02:13:37.581570905 +0000
 Birth: -
Comment 10 Michael Halstead 2017-04-12 23:43:40 UTC
The simple fix from comments 7 & 8 is working. 

Also, no new files have appeared with unset mtime and atime.

I think we can safely go without fully resolving the cause of this issue since the workaround can stay in place indefinitely.