1

We're having a weird issue in one of our Bamboo plans, which we can't replicate 'locally' (on the same machine, with the same user)

It's failing to copy a file. Here's a truss log:

error   14-Dec-2018 14:22:44    + truss cp -f TestEnvironment.zip /mnt/builds/SEN/Touchstone/Maintenance/10.1/solaris10sparc/gcc4_9/ 
error   14-Dec-2018 14:22:44    execve("/usr/bin/cp", 0xFFBFBB8C, 0xFFBFBBA0)  argc = 4
error   14-Dec-2018 14:22:44    sysinfo(SI_MACHINE, "sun4v", 257)       = 6
error   14-Dec-2018 14:22:44    mmap(0x00000000, 32, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFF3F0000
error   14-Dec-2018 14:22:44    mmap(0x00000000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFF3A0000
error   14-Dec-2018 14:22:44    mmap(0x00000000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFF390000
error   14-Dec-2018 14:22:44    memcntl(0xFF3B0000, 17560, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
error   14-Dec-2018 14:22:44    mmap(0x00000000, 8192, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFF380000
error   14-Dec-2018 14:22:44    memcntl(0x00010000, 4792, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
error   14-Dec-2018 14:22:44    resolvepath("/usr/lib/ld.so.1", "/lib/ld.so.1", 1023) = 12
error   14-Dec-2018 14:22:44    resolvepath("/usr/bin/cp", "/usr/bin/cp", 1023) = 11
error   14-Dec-2018 14:22:44    stat64("/usr/bin/cp", 0xFFBFB658)       = 0
error   14-Dec-2018 14:22:44    open("/var/ld/ld.config", O_RDONLY)     Err#2 ENOENT
error   14-Dec-2018 14:22:44    stat64("/lib/libc.so.1", 0xFFBFADB8)        = 0
error   14-Dec-2018 14:22:44    resolvepath("/lib/libc.so.1", "/lib/libc.so.1", 1023) = 14
error   14-Dec-2018 14:22:44    open("/lib/libc.so.1", O_RDONLY)        = 3
error   14-Dec-2018 14:22:44    mmap(0x00010000, 32768, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_ALIGN, 3, 0) = 0xFF370000
error   14-Dec-2018 14:22:44    mmap(0x00010000, 1294336, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xFF200000
error   14-Dec-2018 14:22:44    mmap(0xFF200000, 1244845, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_TEXT, 3, 0) = 0xFF200000
error   14-Dec-2018 14:22:44    mmap(0xFF330000, 36029, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_INITDATA, 3, 1245184) = 0xFF330000
error   14-Dec-2018 14:22:44    mmap(0xFF33A000, 1680, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANON, -1, 0) = 0xFF33A000
error   14-Dec-2018 14:22:44    munmap(0xFF370000, 32768)           = 0
error   14-Dec-2018 14:22:44    close(3)                    = 0
error   14-Dec-2018 14:22:44    memcntl(0xFF200000, 145936, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
error   14-Dec-2018 14:22:44    mmap(0x00010000, 24576, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xFF370000
error   14-Dec-2018 14:22:44    getcontext(0xFFBFB4C8)
error   14-Dec-2018 14:22:44    getrlimit(RLIMIT_STACK, 0xFFBFB4A8)     = 0
error   14-Dec-2018 14:22:44    getpid()                    = 29644 [29643]
error   14-Dec-2018 14:22:44    setustack(0xFF372A88)
error   14-Dec-2018 14:22:44    issetugid()                 = 0
error   14-Dec-2018 14:22:44    brk(0x000288B0)                 = 0
error   14-Dec-2018 14:22:44    brk(0x0002A8B0)                 = 0
error   14-Dec-2018 14:22:44    stat64("/platform/sun4v/lib/libc_psr.so.1", 0xFFBFA958) = 0
error   14-Dec-2018 14:22:44    resolvepath("/platform/sun4v/lib/libc_psr.so.1", "/platform/sun4v/lib/libc_psr.so.1", 1023) = 33
error   14-Dec-2018 14:22:44    open("/platform/sun4v/lib/libc_psr.so.1", O_RDONLY) = 3
error   14-Dec-2018 14:22:44    mmap(0x00010000, 9244, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_ALIGN, 3, 0) = 0xFF360000
error   14-Dec-2018 14:22:44    munmap(0xFF362000, 1052)            = 0
error   14-Dec-2018 14:22:44    close(3)                    = 0
error   14-Dec-2018 14:22:44    stat64("TestEnvironment.zip", 0x000286C8)   = 0
error   14-Dec-2018 14:22:44    stat64("/lib/libsec.so.1", 0xFFBFA188)      = 0
error   14-Dec-2018 14:22:44    resolvepath("/lib/libsec.so.1", "/lib/libsec.so.1", 1023) = 16
error   14-Dec-2018 14:22:44    open("/lib/libsec.so.1", O_RDONLY)      = 3
error   14-Dec-2018 14:22:44    mmap(0x00010000, 32768, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_ALIGN, 3, 0) = 0xFF350000
error   14-Dec-2018 14:22:44    mmap(0x00010000, 90112, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xFF1E0000
error   14-Dec-2018 14:22:44    mmap(0xFF1E0000, 57581, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_TEXT, 3, 0) = 0xFF1E0000
error   14-Dec-2018 14:22:44    mmap(0xFF1F0000, 13281, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_INITDATA, 3, 65536) = 0xFF1F0000
error   14-Dec-2018 14:22:44    mmap(0xFF1F4000, 5560, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANON, -1, 0) = 0xFF1F4000
error   14-Dec-2018 14:22:44    munmap(0xFF350000, 32768)           = 0
error   14-Dec-2018 14:22:44    close(3)                    = 0
error   14-Dec-2018 14:22:44    memcntl(0xFF1E0000, 14232, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
error   14-Dec-2018 14:22:44    stat64("/lib/libavl.so.1", 0xFFBFA0A8)      = 0
error   14-Dec-2018 14:22:44    resolvepath("/lib/libavl.so.1", "/lib/libavl.so.1", 1023) = 16
error   14-Dec-2018 14:22:44    open("/lib/libavl.so.1", O_RDONLY)      = 3
error   14-Dec-2018 14:22:44    mmap(0x00010000, 14208, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_ALIGN, 3, 0) = 0xFF350000
error   14-Dec-2018 14:22:44    mmap(0x00010000, 81920, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xFF1C0000
error   14-Dec-2018 14:22:44    mmap(0xFF1C0000, 3276, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_TEXT, 3, 0) = 0xFF1C0000
error   14-Dec-2018 14:22:44    mmap(0xFF1D2000, 296, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_INITDATA, 3, 8192) = 0xFF1D2000
error   14-Dec-2018 14:22:44    munmap(0xFF1C2000, 65536)           = 0
error   14-Dec-2018 14:22:44    munmap(0xFF350000, 14208)           = 0
error   14-Dec-2018 14:22:44    close(3)                    = 0
error   14-Dec-2018 14:22:44    memcntl(0xFF1C0000, 1096, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
error   14-Dec-2018 14:22:44    pathconf("TestEnvironment.zip", _PC_ACL_ENABLED) = 2
error   14-Dec-2018 14:22:44    acl("TestEnvironment.zip", ACE_GETACLCNT, 0, 0x00000000) = 3
error   14-Dec-2018 14:22:44    stat64("TestEnvironment.zip", 0xFFBFABC8)   = 0
error   14-Dec-2018 14:22:44    acl("TestEnvironment.zip", ACE_GETACL, 3, 0x000296C8) = 3
error   14-Dec-2018 14:22:44    stat64("/mnt/builds/SEN/Touchstone/Maintenance/10.1/solaris10sparc/gcc4_9/", 0x00028630) = 0
error   14-Dec-2018 14:22:44    stat64("/mnt/builds/SEN/Touchstone/Maintenance/10.1/solaris10sparc/gcc4_9//TestEnvironment.zip", 0x00028630) Err#2 ENOENT
error   14-Dec-2018 14:22:44    open64("TestEnvironment.zip", O_RDONLY)     = 3
error   14-Dec-2018 14:22:44    creat64("/mnt/builds/SEN/Touchstone/Maintenance/10.1/solaris10sparc/gcc4_9//TestEnvironment.zip", 0777) = 4
error   14-Dec-2018 14:22:44    stat64("/mnt/builds/SEN/Touchstone/Maintenance/10.1/solaris10sparc/gcc4_9//TestEnvironment.zip", 0x00028630) = 0
error   14-Dec-2018 14:22:44    fstat64(3, 0x000286C8)              = 0
error   14-Dec-2018 14:22:44    mmap64(0x00000000, 8388608, PROT_READ, MAP_SHARED, 3, 0) = 0xFE800000
error   14-Dec-2018 14:22:44    write(4, " P K030414\0\b\b\b\0 \ q".., 8388608) = 8388608
error   14-Dec-2018 14:22:44    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 8388608) = 0xFE800000
error   14-Dec-2018 14:22:44    write(4, "DB ZB8FF [E2F7 kF1FB9BC0".., 8388608) = 8388608
error   14-Dec-2018 14:22:44    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 0x01000000) = 0xFE800000
error   14-Dec-2018 14:22:44    write(4, " W U \CC gF3 )94 ( R 08C".., 8388608) = 8388608
error   14-Dec-2018 14:22:44    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 0x01800000) = 0xFE800000
error   14-Dec-2018 14:22:44    write(4, " $EF K v1796 % _A8 X zCD".., 8388608) = 8388608
error   14-Dec-2018 14:22:44    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 0x02000000) = 0xFE800000
error   14-Dec-2018 14:22:45    write(4, "01 j9482 3E791 )02B9DBAD".., 8388608) = 8388608
error   14-Dec-2018 14:22:45    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 0x02800000) = 0xFE800000
error   14-Dec-2018 14:22:45    write(4, "FC w &CE02B2E3 ,1DF9 }8E".., 8388608) = 8388608
error   14-Dec-2018 14:22:45    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 0x03000000) = 0xFE800000
error   14-Dec-2018 14:22:45    write(4, "01FE zAFD60FF9B7B0 * kAA".., 8388608) = 8388608
error   14-Dec-2018 14:22:45    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 0x03800000) = 0xFE800000
error   14-Dec-2018 14:22:45    write(4, "B712 Z8D81E4C6F515C3D0F1".., 8388608) = 8388608
error   14-Dec-2018 14:22:45    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 0x04000000) = 0xFE800000
error   14-Dec-2018 14:22:46    write(4, "9A j97AB `0FC0C8 ]E1 )C5".., 8388608) = 8388608
error   14-Dec-2018 14:22:46    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 0x04800000) = 0xFE800000
error   14-Dec-2018 14:22:46    write(4, "1283 z1282DE 60498DB FEF".., 8388608) = 8388608
error   14-Dec-2018 14:22:46    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 0x05000000) = 0xFE800000
error   14-Dec-2018 14:22:46    write(4, "FC8CDBDCEC (CD93 j9A 61A".., 8388608) = 8388608
error   14-Dec-2018 14:22:46    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 0x05800000) = 0xFE800000
error   14-Dec-2018 14:22:46    write(4, "8ECC 6BB U93 ~E5B4A2CF g".., 8388608) = 8388608
error   14-Dec-2018 14:22:46    mmap64(0xFE800000, 8388608, PROT_READ, MAP_SHARED|MAP_FIXED, 3, 0x06000000) = 0xFE800000
error   14-Dec-2018 14:22:46    write(4, "AD 7BFE9E7F0EFE51686F2 9".., 8388608) Err#13 EACCES
error   14-Dec-2018 14:22:46    brk(0x0002A8B0)                 = 0
error   14-Dec-2018 14:22:46    brk(0x0002C8B0)                 = 0
error   14-Dec-2018 14:22:46    open("/usr/dt/lib/nls/msg/C/SUNW_OST_OSLIB.cat", O_RDONLY) Err#2 ENOENT
error   14-Dec-2018 14:22:46    open("/usr/lib/locale/C/LC_MESSAGES/SUNW_OST_OSLIB.mo", O_RDONLY) Err#2 ENOENT
error   14-Dec-2018 14:22:46    cp: TestEnvironment.zipwrite(2, " c p :   T e s t E n v i".., 23)   = 23
error   14-Dec-2018 14:22:46    : write(2, " :  ", 2)               = 2
error   14-Dec-2018 14:22:46    Permission deniedwrite(2, " P e r m i s s i o n   d".., 17) = 17
error   14-Dec-2018 14:22:46    
error   14-Dec-2018 14:22:46    write(2, "\n", 1)               = 1
error   14-Dec-2018 14:22:46    close(3)                    = 0
error   14-Dec-2018 14:22:47    close(4)                    = 0
error   14-Dec-2018 14:22:47    munmap(0xFE800000, 8388608)         = 0
error   14-Dec-2018 14:22:47    unlink("/mnt/builds/SEN/Touchstone/Maintenance/10.1/solaris10sparc/gcc4_9//TestEnvironment.zip") = 0
error   14-Dec-2018 14:22:47    _exit(2)

The previous command cp -f TestEnvironment.zip /mnt/builds/SEN/Touchstone/Maintenance/10.1/Solaris_sparc_gcc/ succeeds as well.

-bash-3.2$ uname -a
SunOS b2s-sol10spr-4 5.10 Generic_147440-01 sun4v sparc sun4v

So, I went to https://docs.oracle.com/cd/E26502_01/html/E29032/write-2.html, and it doesn't mention EACCES...

What's going on?

  • Is the destination directory on NFS? Any unusual permission bits or ACLs on /mnt/builds/SEN/Touchstone/Maintenance/10.1/solaris10sparc/gcc4_9 ? – Mark Plotnick Dec 15 '18 at 2:38
  • That directory has 777 permissions (dunno much about acl's. – Bwmat Dec 15 '18 at 3:10
  • And that directory is on nfs – Bwmat Dec 15 '18 at 3:10
  • Does cat TestEnvironment.zip > /mnt/builds/SEN/Touchstone/Maintenance/10.1/solaris10sparc/gcc4_9/TestEnvironment.zip succeed? – Mark Plotnick Dec 15 '18 at 6:27
  • File locking? I'd try capturing the NFS traffic and seeing what's going on on the NFS server. After 12 successful 8 MB writes to file descriptor 4, you get an EACCESS error from that same file descriptor. That's really strange, as the only way to get that from the local kernel via from the Solaris source posted to the internet is the write() syscall checking for a file lock via the internal nbl_conflict() function. – Andrew Henle Dec 16 '18 at 22:12
-1

You did not send your sourcecode, but it seems that you call mmap() to get the data you like to write.

I guess that you mapped a region of a file that grants no read access to you.

In order to verify that the problem is not caused by a side effect with mmap() you should call

dd if=filename of=/dev/null

to check whether the problem exists when you definitely only read from the source file.

  • I don't have the source, I'm just using the cp that's installed on the system. – Bwmat Dec 17 '18 at 18:32
  • Sorry, I did not see that, but cp mmap()s larger parts of the input file before it calls write(). Is there anything with the input file? – schily Dec 17 '18 at 18:43
  • I'm not sure, that file is one that was just created by the bamboo plan, I don't know of anything 'unusual' about it. – Bwmat Dec 17 '18 at 18:45
  • Then you could have a look at the OpenSolaris sources and look for related EACCESS returns. ACLs are e.g. such a case where a file access could cause EACCESS. – schily Dec 18 '18 at 10:47
  • ACLs are e.g. such a case where a file access could cause EACCESS. I'm pretty sure the only way ACLs can cause an EACCESS return is on open() or openat(), although I haven't examined the kernel source. There's no way I can see for ACLs to cause a write() to return EACCESS, especially after a series of successful write() calls on that same file descriptor. Barring something on the NFS server (quite possible, and that's still a complete unknown...), the only way I see in the OpenSolaris source for write() to fail on EACCESS is for it to run into a file lock. – Andrew Henle Dec 19 '18 at 10:27

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.