borgbackup / borg

Deduplicating archiver with compression and authenticated encryption.
https://www.borgbackup.org/
Other
11.15k stars 742 forks source link

Cannot open self /usr/bin/borg or archive /usr/bin/borg.pkg #2002

Closed ilial closed 7 years ago

ilial commented 7 years ago

Hi, I've installed borg from the binary: https://github.com/borgbackup/borg/releases/download/1.0.9/borg-linux64 renamed it to borg and placed under /usr/bin/ I'm running it from a crontab. It works for some days (different on each server), than i get the following error: Cannot open self /usr/bin/borg or archive /usr/bin/borg.pkg As you can see, the executable became much smaller ls -l /usr/bin/borg -rwxr-xr-x 1 root root 33888 Jan 4 14:11 /usr/bin/borg On a server, where it works (for now) ls -l /usr/bin/borg -rwxr-xr-x 1 root root 11456315 Jan 4 14:23 /usr/bin/borg

RonnyPfannschmidt commented 7 years ago

at first glance this looks like a deployment/autoupdate/autorepair issue with your servers, please provide more information

ilial commented 7 years ago

It was the first thing I thought about. Yesterday, before end of the day, it worked fine. Today morning it just didn't work and i found that the file changed. The system is CentOS 6.6 nothing from: deployment/autoupdate/autorepair was running and not even exists on this machine Nothing unusual in any system logs The machine is a VM on XEN sever. It was being backuped to remote server, like 2 others machines in the POC The command runs from a cron job: borg create -v --stats borg@mybcksrv.com:/home/borgbackup/mytestsrv.com::'{now:%Y-%m-%d_%H:%M:%S}' /home/ilial /opt /home/test &>/var/log/borg.log And this what i saw at the morning: cat /var/log/borg.log Cannot open self /usr/bin/borg or archive /usr/bin/borg.pkg On the mybcksrv.com: the /home/borgbackup/mytestsrv.com didn't changed since last successful backup ...

enkore commented 7 years ago

Can you compare these files? Is the shorter file a truncated version of the correct file or something completely different? Do the time stamps on the file (mtime, ctime) indicate that it was changed?

33k is about the size of the pyinstaller bootloader (which is the tool used to build these binaries). Perhaps we're looking at some subtle PyInstaller bug or a problem in our PyInstaller scripts.

Hmm. The values of variables like TMP/TEMP/TMPDIR/TEMPDIR are not unusual in your system, as in, they don't point to /usr/bin or something like that? Are there perhaps new files or directories in /usr/bin? Like a library.zip or something like that?

ilial commented 7 years ago

No library.zip. I've already read on an older issue about Cannot open self /usr/bin/borg or archive /usr/bin/borg.pkg so it ran with predefined TEMP variable To compare two binaries I did: xxd borg > borg_corrupted and on working one xxd borg > bor_ok

and the corrupted one isn't looks like truncated version.

Just thought, may be you already encountered something like that ...

Anyway, thanks a lot for the fast answer!

ThomasWaldmann commented 7 years ago

Just as a side note: you should never install custom stuff to /usr/bin. To avoid interference and also make clear what is the OS and what are local modifications / custom tools, always use /usr/local/bin (or /usr/local/sbin) for the latter ones.

The single-file borg binary is about 10MB in size and should be root:root mode 755.

ilial commented 7 years ago

Thanks Thomas, you are completely right. But It is not first time i see this problem and it happend in /usr/local/bin too. I've put it in /usr/bin to avoid possible PATH issues.

level323 commented 7 years ago

I hit the "cannot open self" issue a few weeks back, and have been meaning to post an issue about it but I'm on holidays so fun is taking a priority ;-)

The weird thing is that I'm running borg on a bunch of Debian 8 machines, and on MOST of them the standalone binary works fine, and yet on a few of these machines I hit the "cannot open self" error.

At the time I was running borg 1.9rc1 (that was the latest available) across all these machines.

I have yet to figure out the root cause of the issue, but using strace I was able to identify the point where things go awry:

execve("./borg-linux64", ["./borg-linux64"], [/* 23 vars */]) = 0
brk(0)                                  = 0x1373000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb1af406000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=32691, ...}) = 0
mmap(NULL, 32691, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb1af3fe000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320\16\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=14664, ...}) = 0
mmap(NULL, 2109712, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb1aefe4000
mprotect(0x7fb1aefe7000, 2093056, PROT_NONE) = 0
mmap(0x7fb1af1e6000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7fb1af1e6000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libz.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 \"\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=109144, ...}) = 0
mmap(NULL, 2204200, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb1aedc9000
mprotect(0x7fb1aede3000, 2093056, PROT_NONE) = 0
mmap(0x7fb1aefe2000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19000) = 0x7fb1aefe2000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\34\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1738176, ...}) = 0  
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb1af3fd000
mmap(NULL, 3844640, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb1aea1e000
mprotect(0x7fb1aebbf000, 2097152, PROT_NONE) = 0
mmap(0x7fb1aedbf000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a1000) = 0x7fb1aedbf000
mmap(0x7fb1aedc5000, 14880, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fb1aedc5000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb1af3fc000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb1af3fb000
arch_prctl(ARCH_SET_FS, 0x7fb1af3fc700) = 0
mprotect(0x7fb1aedbf000, 16384, PROT_READ) = 0
mprotect(0x7fb1aefe2000, 4096, PROT_READ) = 0
mprotect(0x7fb1af1e6000, 4096, PROT_READ) = 0
mprotect(0x7fb1af408000, 4096, PROT_READ) = 0
munmap(0x7fb1af3fe000, 32691)           = 0
brk(0)                                  = 0x1373000
brk(0x1398000)                          = 0x1398000
readlink("/proc/self/exe", "/usr/local/lib/borgbackup/1.0.9r"..., 4096) = 47
open("/usr/local/lib/borgbackup/1.0.9rc1@", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/local/lib/borgbackup/1.0.9rc1/borg-linux64.pkg", O_RDONLY) = -1 ENOENT (No such file or directory)
write(2, "Cannot open self /usr/local/lib/"..., 128Cannot open self /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64 or archive /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64.pkg
) = 128
exit_group(-1)                          = ?
+++ exited with 255 +++

The self-contained binary is at /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64

Notice the strace line open("/usr/local/lib/borgbackup/1.0.9rc1@", O_RDONLY) = -1 ENOENT (No such file or directory)

Something (presumably the pyinstaller bootloader???) is mangling the path that it tries to open (which should be /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64

The strace line that immediately follows gave me the clue to a workaround. I created a second copy of the binary at /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64.pkg. After doing that, I was able to execute /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64 and it would successfully run (by opening the .pkg copy). In case you were wondering, trying to execute /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64.pkg directly would fail because (strace would show) it mangling the path in a similar manner, and then trying to fall back to searching for /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64.pkg.pkg, which obviously doesn't exist.

Not sure if the OP is hitting this particular issue or not. If not, I can open a separate issue. Also, this may be a pyinstaller bug, but I'm really unsure because the very same self-contained binary runs fine on most of my other Debian 8 boxes. In all cases where I hit cannot open self I apply the workaround successfully.

Note that I tried all the suggestions to the cannot open self I found via google and none of them worked. Also I checked and can confirm that the binaries are not getting corrupted/truncated.

I was also wondering if the affected machines might be missing some subtle tool/lib/dependency. That of course would be a nice clean explanation, but I can't find any clues as to what it/they might be - and as should be clear, the workaround actually works.

Any ideas on the root cause?

I'm happy to run some extra tests on these machines to try and identify the root cause if anyone has any suspicions.

ThomasWaldmann commented 7 years ago

@level323 The self-contained binary is at /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64 <- does that have r-x permissions for user, group and others? Also, do all directories in the path to it have at least x permissions for user, group and others?

level323 commented 7 years ago

@ThomasWaldmann Yes it does have r-x permissions

ThomasWaldmann commented 7 years ago

@level323 ok, thanks. I'll have a look at the pyinstaller bootloader again (I already did some unrelated work there).

ThomasWaldmann commented 7 years ago

Note: use strace -s 4096 next time to avoid it abbreviating strings.

ThomasWaldmann commented 7 years ago

https://github.com/docker/compose/issues/1135#issuecomment-134535455 is it that?

Or rather that: https://github.com/pyinstaller/pyinstaller/issues/1812 seems to be fixed in 3.2 branch, so the solution for borg is to upgrade to pyinstaller 3.2.x.

level323 commented 7 years ago

@ThomasWaldmann

Re the docker-compose issue 1135 - my Debian 8 machines don't have prelink installed so I don't see how this could be the cause in this case.

OK, here's the output of strace -s 4096 ./borg-linux64:

execve("./borg-linux64", ["./borg-linux64"], [/* 22 vars */]) = 0
brk(0)                                  = 0x7c3000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fede91e0000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=32691, ...}) = 0
mmap(NULL, 32691, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fede91d8000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320\16\0\0\0\0\0\0@\0\0\0\0\0\0\0\3101\0\0\0\0\0\0\0\0\0\0@\0008\0\t\0@\0\36\0\35\0\6\0\0\0\5\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0\370\1\0\0\0\0\0\0\370\1\0\0\0\0\0\0\10\0\0\0\0\0\0\0\3\0\0\0\4\0\0\0000\32\0\0\0\0\0\0000\32\0\0\0\0\0\0000\32\0\0\0\0\0\0\34\0\0\0\0\0\0\0\34\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0\1\0\0\0\5\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\10 \0\0\0\0\0\0\10 \0\0\0\0\0\0\0\0 \0\0\0\0\0\1\0\0\0\6\0\0\0`-\0\0\0\0\0\0`- \0\0\0\0\0`- \0\0\0\0\0@\3\0\0\0\0\0\0\260\3\0\0\0\0\0\0\0\0 \0\0\0\0\0\2\0\0\0\6\0\0\0\210-\0\0\0\0\0\0\210- \0\0\0\0\0\210- \0\0\0\0\0\20\2\0\0\0\0\0\0\20\2\0\0\0\0\0\0\10\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0008\2\0\0\0\0\0\0008\2\0\0\0\0\0\0008\2\0\0\0\0\0\0D\0\0\0\0\0\0\0D\0\0\0\0\0\0\0\4\0\0\0\0\0\0\0P\345td\4\0\0\0L\32\0\0\0\0\0\0L\32\0\0\0\0\0\0L\32\0\0\0\0\0\0\274\0\0\0\0\0\0\0\274\0\0\0\0\0\0\0\4\0\0\0\0\0\0\0Q\345td\6\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0R\345td\4\0\0\0`-\0\0\0\0\0\0`- \0\0\0\0\0`- \0\0\0\0\0\240\2\0\0\0\0\0\0\240\2\0\0\0\0\0\0\1\0\0\0\0\0\0\0\4\0\0\0\24\0\0\0\3\0\0\0GNU\0\35\204\20&\377,Z\352%\302\31!\372\311\311x\253FX%\4\0\0\0\20\0\0\0\1\0\0\0GNU\0\0\0\0\0\2\0\0\0\6\0\0\0 \0\0\0\0\0\0\0\33\0\0\0\33\0\0\0\2\0\0\0\7\0\0\0\230\2\21\0\200H\0\4\22\0\0@\203(\10\236\33\0\0\0\0\0\0\0\34\0\0\0\0\0\0\0\0\0\0\0\35\0\0\0\0\0\0\0\36\0\0\0\0\0\0\0\37\0\0\0\0\0\0\0 \0\0\0\0\0\0\0!\0\0\0#\0\0\0$\0\0\0&\0\0\0'\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0(\0\0\0\0\0\0\0\0\0\0\0\353\26\251\30a\257\0\371\301S\200\30\273\25sB\257\304M\17\221!\374\370\6\2\4\371\3733\373\17\371\31sB\372\31sB\225\263_\31\177\236\320\30a\242\222\6", 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=14664, ...}) = 0
mmap(NULL, 2109712, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fede8dbe000
mprotect(0x7fede8dc1000, 2093056, PROT_NONE) = 0
mmap(0x7fede8fc0000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7fede8fc0000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libz.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 \"\0\0\0\0\0\0@\0\0\0\0\0\0\0X\243\1\0\0\0\0\0\0\0\0\0@\0008\0\7\0@\0\34\0\33\0\1\0\0\0\5\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\204\222\1\0\0\0\0\0\204\222\1\0\0\0\0\0\0\0 \0\0\0\0\0\1\0\0\0\6\0\0\0\240\234\1\0\0\0\0\0\240\234!\0\0\0\0\0\240\234!\0\0\0\0\0\200\5\0\0\0\0\0\0\210\5\0\0\0\0\0\0\0\0 \0\0\0\0\0\2\0\0\0\6\0\0\0\320\235\1\0\0\0\0\0\320\235!\0\0\0\0\0\320\235!\0\0\0\0\0\360\1\0\0\0\0\0\0\360\1\0\0\0\0\0\0\10\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\310\1\0\0\0\0\0\0\310\1\0\0\0\0\0\0\310\1\0\0\0\0\0\0$\0\0\0\0\0\0\0$\0\0\0\0\0\0\0\4\0\0\0\0\0\0\0P\345td\4\0\0\0\310w\1\0\0\0\0\0\310w\1\0\0\0\0\0\310w\1\0\0\0\0\0\\\3\0\0\0\0\0\0\\\3\0\0\0\0\0\0\4\0\0\0\0\0\0\0Q\345td\6\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0R\345td\4\0\0\0\240\234\1\0\0\0\0\0\240\234!\0\0\0\0\0\240\234!\0\0\0\0\0`\3\0\0\0\0\0\0`\3\0\0\0\0\0\0\1\0\0\0\0\0\0\0\4\0\0\0\24\0\0\0\3\0\0\0GNU\0\255\314J^'\325\336\217\v\303\306\2\33P\272,5\354\232\216\0\0\0\0C\0\0\0\30\0\0\0\10\0\0\0\t\0\0\0\0\3h\24\f\3$\24\221\2\223A;\0\16\30\234\1\4DQ\f\0\210,\0\303\"\224\27\212\203\0c0\262G\212PC ,\20\35\210\341\200\213A\220\23e$g\304\201V\0.\20\2\200\0\20\30\0\0\0\33\0\0\0\34\0\0\0\36\0\0\0\"\0\0\0#\0\0\0%\0\0\0&\0\0\0\0\0\0\0'\0\0\0(\0\0\0+\0\0\0.\0\0\0/\0\0\0\0\0\0\0001\0\0\0\0\0\0\0002\0\0\0004\0\0\0005\0\0\0007\0\0\0009\0\0\0\0\0\0\0:\0\0\0;\0\0\0<\0\0\0\0\0\0\0=\0\0\0\0\0\0\0?\0\0\0@\0\0\0A\0\0\0B\0\0\0D\0\0\0E\0\0\0G\0\0\0J\0\0\0\0\0\0\0M\0\0\0O\0\0\0P\0\0\0Q\0\0\0U\0\0\0V\0\0\0\0\0\0\0X\0\0\0\0\0\0\0Z\0\0\0\\\0\0\0\0\0\0\0]\0\0\0_\0\0\0\0\0\0\0`\0\0\0d\0\0\0f\0\0\0\0\0\0\0g\0\0\0h\0\0\0i\0\0\0\0\0\0\0\0\0\0\0j\0\0\0k\0\0\0", 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=109144, ...}) = 0
mmap(NULL, 2204200, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fede8ba3000
mprotect(0x7fede8bbd000, 2093056, PROT_NONE) = 0
mmap(0x7fede8dbc000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19000) = 0x7fede8dbc000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\34\2\0\0\0\0\0@\0\0\0\0\0\0\0\300t\32\0\0\0\0\0\0\0\0\0@\0008\0\n\0@\0D\0C\0\6\0\0\0\5\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0000\2\0\0\0\0\0\0000\2\0\0\0\0\0\0\10\0\0\0\0\0\0\0\3\0\0\0\4\0\0\0P\346\26\0\0\0\0\0P\346\26\0\0\0\0\0P\346\26\0\0\0\0\0\34\0\0\0\0\0\0\0\34\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0\1\0\0\0\5\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\334\16\32\0\0\0\0\0\334\16\32\0\0\0\0\0\0\0 \0\0\0\0\0\1\0\0\0\6\0\0\0H\27\32\0\0\0\0\0H\27:\0\0\0\0\0H\27:\0\0\0\0\0\360O\0\0\0\0\0\0\330\222\0\0\0\0\0\0\0\0 \0\0\0\0\0\2\0\0\0\6\0\0\0\240K\32\0\0\0\0\0\240K:\0\0\0\0\0\240K:\0\0\0\0\0\340\1\0\0\0\0\0\0\340\1\0\0\0\0\0\0\10\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0p\2\0\0\0\0\0\0p\2\0\0\0\0\0\0p\2\0\0\0\0\0\0D\0\0\0\0\0\0\0D\0\0\0\0\0\0\0\4\0\0\0\0\0\0\0\7\0\0\0\4\0\0\0H\27\32\0\0\0\0\0H\27:\0\0\0\0\0H\27:\0\0\0\0\0\20\0\0\0\0\0\0\0\200\0\0\0\0\0\0\0\10\0\0\0\0\0\0\0P\345td\4\0\0\0l\346\26\0\0\0\0\0l\346\26\0\0\0\0\0l\346\26\0\0\0\0\0,j\0\0\0\0\0\0,j\0\0\0\0\0\0\4\0\0\0\0\0\0\0Q\345td\6\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\20\0\0\0\0\0\0\0R\345td\4\0\0\0H\27\32\0\0\0\0\0H\27:\0\0\0\0\0H\27:\0\0\0\0\0\2708\0\0\0\0\0\0\2708\0\0\0\0\0\0\1\0\0\0\0\0\0\0\4\0\0\0\24\0\0\0\3\0\0\0GNU\0\255\f\340\246\266\342\1\311\250\31[-U\4:\374\324\365\333\0\4\0\0\0\20\0\0\0\1\0\0\0GNU\0\0\0\0\0\2\0\0\0\6\0\0\0 \0\0\0\0\0\0\0\363\3\0\0\n\0\0\0\0\1\0\0\16\0\0\0\0000\20D\240 \2\1\210\3\346\220\305E\214\0\300\0\10\0\5\200\0`\300\200\0\r\212\f\0\4\20\0\210D2\10.@\210P4, \16\"H&\204\300\214\4\10\0\2\2\16\241\254\32\4f\300\0\3002\0\300\0P\1 \201\10\204\v  ($\0\4 P\0\20X\200\312DB(\0\6\200\20\30B\0 @\200\0\tP\0Q\212@\20\0\0\0\0\10\0\0\21\20", 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1738176, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fede91d7000
mmap(NULL, 3844640, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fede87f8000
mprotect(0x7fede8999000, 2097152, PROT_NONE) = 0
mmap(0x7fede8b99000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a1000) = 0x7fede8b99000
mmap(0x7fede8b9f000, 14880, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fede8b9f000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fede91d6000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fede91d5000
arch_prctl(ARCH_SET_FS, 0x7fede91d6700) = 0
mprotect(0x7fede8b99000, 16384, PROT_READ) = 0
mprotect(0x7fede8dbc000, 4096, PROT_READ) = 0
mprotect(0x7fede8fc0000, 4096, PROT_READ) = 0
mprotect(0x7fede91e2000, 4096, PROT_READ) = 0
munmap(0x7fede91d8000, 32691)           = 0
brk(0)                                  = 0x7c3000
brk(0x7e8000)                           = 0x7e8000
readlink("/proc/self/exe", "/usr/local/lib/borgbackup/1.0.9rc1/borg-linux64", 4096) = 47
open("/usr/local/lib/borgbackup/1.0.9rc1@", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/local/lib/borgbackup/1.0.9rc1/borg-linux64.pkg", O_RDONLY) = -1 ENOENT (No such file or directory)
write(2, "Cannot open self /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64 or archive /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64.pkg\n", 128Cannot open self /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64 or archive /usr/local/lib/borgbackup/1.0.9rc1/borg-linux64.pkg
) = 128
exit_group(-1)                          = ?
+++ exited with 255 +++
ThomasWaldmann commented 7 years ago

Maybe @ilial has that prelink issue already solved in pyinstaller 3.2.x as his binary is getting smaller.

@level323 seems to have a different issue maybe as the executable path somehow gets corrupted inside the bootloader (truncated and @ at the end). I have looked into bootloader source, but could not find such a bug.

level323 commented 7 years ago

I wish to add that I just conducted some further investigations on one of my Debian 8 boxes that is giving the cannot open selferror on the borg 1.0.9rc1 borg linux 64 bit standalone.

I downloaded the borg 1.0.9 (final) and 1.1.0b1 linux 64 bit standalone binaries and can report that these also fail with the cannot open self error.

level323 commented 7 years ago

Further investigations:

I tried moving the borg linux 64 standalone binary file (v 1.0.9) to different locations and executing it via strace to see whether or not the mangling of the path it tries to open changes (and thus may give a clue as to the root cause(s)):

Not sure this info helps much... but here it is anyway.

ThomasWaldmann commented 7 years ago

@level323 btw, is your RAM maybe malfunctioning, can you run memtest86+ on that machine?

enkore commented 7 years ago

Either way, there is some memory corruption going on, programmatic or otherwise.

level323 commented 7 years ago

@ThomasWaldmann The machine in question is a KVM virtual machine.

Memtest86+ reported no errors.

Also, this is not the only machine I've experienced this issue on. On the other machines (also Debian 8) the corruption of the path to the open command is identical. IMO that significantly reduces the chance that memory corruption is the cause.

Just a reminder that only a few of my Debian 8 machines exhibit this issue. Other Debian 8 boxes run the standalone binary just fine without any workarounds.

All these bits of information keep leading me back to thinking that it's most likely either some subtle missing dependency that pyinstaller standalone binaries depend on or perhaps a character encoding issue. But my linux mind melding powers are surely not as great as some so there may be another cause.

ThomasWaldmann commented 7 years ago

Idea (if it can not be solved otherwise):

When doing next release or rc, I could additionally build with pyinstaller 3.2.x - so you could check whether it happens with that also.

htgoebel commented 7 years ago

Reading through the comments, these are two problems, which most presumable are not related to each other.

  1. Truncated borg executable. I have no clue what is going on here. It does not sound like a problem caused by PyInstaller or Borg. Maybe some tool like inotifywatch may allow checking which process is truncating the file.
  2. Errors in the filename. This may be some programming error in the C-code of PyInstaller. @level323: Does this error occur always on your system? Can you please build a version of Borg which uses the PyInstaller debug loader. Build-instructions are here, then in this step you also need to pass --debug the pyinstaller ....
ThomasWaldmann commented 7 years ago

@htgoebel first issue is likely a prelink issue and solved in pyinstaller 3.2.x, see comments above.

ThomasWaldmann commented 7 years ago

https://github.com/pyinstaller/pyinstaller/issues/2357 bug in pyinstaller issue tracker.

ThomasWaldmann commented 7 years ago

I added a binary built with pyinstaller 3.2.1 in debug mode to the 1.1.0b3 release. Everybody having issues with the 1.0.x borg binaries built with pyinstaller 3.1.1 please try this.

Please note that this is a BETA of 1.1, so you maybe don't want to run that against your production repo.

https://github.com/borgbackup/borg/releases/tag/1.1.0b3 -> borg-linux64-pyi321-debug

level323 commented 7 years ago

@ThomasWaldmann I can report that the borg-linux64-pyi321-debug works properly on the machine where previous standalones were mangling the file path. However, the regular borg-linux64 standalone for 1.1.0b3 also works now.

So something has changed since the 1.1.0b1 standalone builds that has resolved the issue of file name mangling in the pyinstaller bootloader.

ThomasWaldmann commented 7 years ago

@level323 hmm, that is strange, I think I have used the same pyinstaller "3.1.1+" for 1.0.9 and 1.1.0b3 (and you said the bug happens on 1.0.9 on your machine).

level323 commented 7 years ago

@ThomasWaldmann If what you say is true then it certainly adds another kink to the strange story.

I just tested some more releases and can tell you that:

I also tested 1.0.8rc1 because it was released after 1.1.0b2 and thought it might be interesting to see what happened. It definitely exhibits the bug.

ThomasWaldmann commented 7 years ago
$ git diff 1.1.0b1 1.1.0b2 Vagrantfile
...
-    git clone https://github.com/pyinstaller/pyinstaller.git
+    git clone https://github.com/thomaswaldmann/pyinstaller.git
     cd pyinstaller
-    # develop branch, with rebuilt bootloaders, with ThomasWaldmann/do-not-overwrite-LD_LP
-    git checkout fd3df7796afa367e511c881dac983cad0697b9a3
+    # develop branch, with fixed / freshly rebuilt bootloaders
+    git checkout fresh-bootloader
$ git diff 1.0.9 1.1.0b3 Vagrantfile
...
-    git clone https://github.com/pyinstaller/pyinstaller.git
+    git clone https://github.com/thomaswaldmann/pyinstaller.git
     cd pyinstaller
-    git checkout v3.1.1
+    # develop branch, with fixed / freshly rebuilt bootloaders
+    git checkout fresh-bootloader

OK, looks like I forgot to update 1.0-maint to the fixed and freshly compiled bootloaders. :-|

ThomasWaldmann commented 7 years ago

Switching to thomaswaldmann/pyinstaller tag fresh-bootloader for now, we use that since quite a while in master branch.

ThomasWaldmann commented 7 years ago

fixed by #2076.