search

borgbackup / borg

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

ncurses version mismatch in release 1.1.4 #3732

Closed vphantom closed 6 years ago

vphantom commented 6 years ago

I never worked with Vagrantfiles before so I don't see an obvious solution. I downloaded borg-linux64 from the 1.1.4 release and it seems to work, but if I try to create an already-existing name, in addition to failing as expected I get a dynamic linker error:

$ borg create --stats -x -C lz4 /tmp/testborg::iodocker1 io-docker
Enter passphrase for key /tmp/testborg: 
/bin/sh: symbol lookup error: /lib/x86_64-linux-gnu/libncurses.so.5: undefined symbol: _nc_putchar
Archive iodocker1 already exists

Considering that the binary does not in fact link with my system's ncurses:

$ ldd bin/borg
    linux-vdso.so.1 (0x00007ffcad78a000)
    libdl.so.2 => /lib/x86_64-linux-gnu/libdl.so.2 (0x00007f65f6ec1000)
    libz.so.1 => /lib/x86_64-linux-gnu/libz.so.1 (0x00007f65f6ca6000)
    libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f65f68fa000)
    /lib64/ld-linux-x86-64.so.2 (0x000055f8a1b34000)

…I can reasonably conclude that the problem lies inside the virtual environment created with Vagrant. Something, maybe /bin/sh, needs another version of ncurses than what's bundled. :(

ThomasWaldmann commented 6 years ago

Works for me (don't get the symbol lookup error for an existing archive). The binary is built on Debian Wheezy, I just tested it on Ubuntu 18.04. Does your OS have an older libncurses.so.5 than Debian "Wheezy" 7?

Running ldd on the binary doesn't say much, you will only see what the "bootloader" of pyinstaller needs, not what's needed later. I'll check whether libncurses is / can be included into the binary...

vphantom commented 6 years ago

Thank you for looking into this! I'm on Debian 8 (Jessie, more recent than Wheezy). If the build relies on the host's libncurses, I suppose the safest fix would be to bundle the version you need instead, if that's feasible.

ThomasWaldmann commented 6 years ago

Strange that d8 does not have a symbol that d7 had?

ThomasWaldmann commented 6 years ago

Looks like libreadline -> libtinfo -> libncurses. And libncurses isn't included in the binary.

I'll add libncurses and libncursesw via the .spec file.

ThomasWaldmann commented 6 years ago

Hmm, i tried to reproduce on Debian "Jessie" 8, but i do not get that warning (using a current build of the binary, with and without libncurses[w] in the binary).

I also tried the 1.1.4 binary and also do not get the warning there.

@vphantom Is there something strange with your libncurses?

Mine:

$ ls -l /lib/x86_64-linux-gnu/libnc*
lrwxrwxrwx 1 root root     17 Dec  3 21:19 /lib/x86_64-linux-gnu/libncurses.so.5 -> libncurses.so.5.9
-rw-r--r-- 1 root root 151120 Dec  3 21:19 /lib/x86_64-linux-gnu/libncurses.so.5.9
lrwxrwxrwx 1 root root     18 Dec  3 21:19 /lib/x86_64-linux-gnu/libncursesw.so.5 -> libncursesw.so.5.9
-rw-r--r-- 1 root root 221112 Dec  3 21:19 /lib/x86_64-linux-gnu/libncursesw.so.5.9

$ apt-cache show libncurses5:amd64
Package: libncurses5
Source: ncurses
Version: 5.9+20140913-1+deb8u2
Installed-Size: 270
Maintainer: Craig Small <csmall@debian.org>
Architecture: amd64
Depends: libtinfo5 (= 5.9+20140913-1+deb8u2), libc6 (>= 2.15)
Pre-Depends: multiarch-support, libtinfo5 (>= 5.9-3)
Recommends: libgpm2
Description: shared libraries for terminal handling
Description-md5: 599cbbcff16d09b3b4643d84f37643fd
Multi-Arch: same
Homepage: http://invisible-island.net/ncurses/
Tag: implemented-in::ada, implemented-in::c, implemented-in::c++,
 role::shared-lib
Section: libs
Priority: required
Filename: pool/main/n/ncurses/libncurses5_5.9+20140913-1+deb8u2_amd64.deb
Size: 96638
MD5sum: 021d1cc2f7d4d9ba9bcdf60758e9167b
SHA1: 6a5809c6ec49c6fc808772962cf120c460a52dec
SHA256: a49c5090c9f61b174beaaf948a92b5b1f6a4e93f0647e1f91118ef45e10f04e9
vphantom commented 6 years ago

By the way here's an easier way to reproduce ithere: just list a non-existent archive. Not all errors yield this, but this one does.

$ borg list /tmp/testborg::io1
Enter passphrase for key /tmp/testborg: 
/bin/sh: symbol lookup error: /lib/x86_64-linux-gnu/libncurses.so.5: undefined symbol: _nc_putchar
Archive io1 does not exist

I have the very same libncurses:

$ ls -l /lib/x86_64-linux-gnu/libnc*
lrwxrwxrwx 1 root root     17 Dec  3 16:19 /lib/x86_64-linux-gnu/libncurses.so.5 -> libncurses.so.5.9
-rw-r--r-- 1 root root 151120 Dec  3 16:19 /lib/x86_64-linux-gnu/libncurses.so.5.9
lrwxrwxrwx 1 root root     18 Dec  3 16:19 /lib/x86_64-linux-gnu/libncursesw.so.5 -> libncursesw.so.5.9
-rw-r--r-- 1 root root 221112 Dec  3 16:19 /lib/x86_64-linux-gnu/libncursesw.so.5.9

Apt-cache also yields the exact same output as yours, 5.9+20140913-1+deb8u2 etc.

As a precaution, I just ran debsums --silent and all my checksums are still good, and of course gpg --verify borg-linux64.asc says "Good signature", so the difference between our setups is elsewhere. Another library or tool used outside of the bundle, perhaps. Maybe Bash itself.

While the prudent action is probably to bundle it, I'd be really curious to figure out the root cause. Would dpkg --list (to Pastebin of course) or something similar help?

ThomasWaldmann commented 6 years ago

borg usually does not open shells. not sure about whether pyinstaller binaries internally do.

Do you use BORG_PASSCOMMAND and does it call a shell?

vphantom commented 6 years ago

I didn't set any environment variables. I just downloaded Borg (today is my first attempt to use it), played with borg init, borg create and borg list to get a feel for it and noticed the linking error displayed when using some commands and not others.

vphantom commented 6 years ago

Addendum: I tried to run the same sequence of commands in debian:wheezy-slim and in debian:jessie-slim Docker containers and I cannot reproduce the error there. The bundle seems to be sensitive to my computer's specific environment but not to stock Debian. (I wouldn't know what's so special about mine…)

htgoebel commented 6 years ago

@ThomasWaldmann You need to check the libs bundles within the (frozen) borg application.Use pyi-archive_viewer to extract the libs. This is what I've found in https://github.com/borgbackup/borg/releases/download/1.1.4/borg-linux64

[tmp]$ ldd libreadline.so.6 
        linux-vdso.so.1 (0x00007ffcb0ff7000)
        libtinfo.so.5 => /lib64/libtinfo.so.5 (0x00007f0745ddd000)
        libc.so.6 => /lib64/libc.so.6 (0x00007f0745a2a000)
        /lib64/ld-linux-x86-64.so.2 (0x00007f074624e000)
[tmp]$ ldd libtinfo.so.5 
        linux-vdso.so.1 (0x00007ffe6dcc1000)
        libc.so.6 => /lib64/libc.so.6 (0x00007f7cb5b78000)
        /lib64/ld-linux-x86-64.so.2 (0x00007f7cb6154000)

None of these libs is linked to libncurses. (The paths are pointing to /usr/lib, since this is in the normal shell, not in PyInstaller and LD_LIBRARAY_PATH is not set.)

@vphantom I suggest running strace -e trace=file -o /tmp/trace.txt -f borg-linux and search the /tmp/trace.txt for any hints.

ThomasWaldmann commented 6 years ago

I found some (libn)curses string in libtinfo, so I assumed it does something with it.

vphantom commented 6 years ago

Okay, did the strace. 21626 is/loads /bin/sh or uname -p which loaded ncurses, even though neither /bin/sh nor /bin/uname on my system link to ncurses. The juicy bits:

21621 execve("/home/lis/bin/borg", ["borg", "info", "testborg::test"], [/* 48 vars */]) = 0
[...]
21621 stat("/tmp/_MEInVVZwX/lib2to3/tests/data/README", 0x7ffca7ce6e30) = -1 ENOENT (No such file or directory)
21621 open("/tmp/_MEInVVZwX/lib2to3/tests/data/README", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
21622 execve("/home/lis/bin/borg", ["borg", "info", "testborg::test"], [/* 50 vars */]) = 0
[...]
21623 execve("/sbin/ldconfig", ["/sbin/ldconfig", "-p"], [/* 2 vars */]) = 0
[...]
21623 +++ exited with 0 +++
[...]
21624 execve("/sbin/ldconfig", ["/sbin/ldconfig", "-p"], [/* 2 vars */]) = 0
[...]
21624 +++ exited with 0 +++
[...]
21622 open("/tmp/testborg/config", O_RDONLY|O_CLOEXEC) = 4
[...]
21622 rmdir("/tmp/testborg/lock.exclusive") = 0
21622 stat("borg/archiver.py", 0x7fff71fd3cd0) = -1 ENOENT (No such file or directory)
[5 times]
21622 stat("borg/archive.py", 0x7fff71fd3cd0) = -1 ENOENT (No such file or directory)
21626 open("/proc/self/fd", O_RDONLY|O_CLOEXEC) = 4
21626 execve("/bin/sh", ["/bin/sh", "-c", "uname -p 2> /dev/null"], [/* 49 vars */]) = 0
21626 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
21626 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
21626 open("/tmp/_MEInVVZwX/tls/x86_64/libncurses.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
21626 stat("/tmp/_MEInVVZwX/tls/x86_64", 0x7ffd9c9b4d70) = -1 ENOENT (No such file or directory)
21626 open("/tmp/_MEInVVZwX/tls/libncurses.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
21626 stat("/tmp/_MEInVVZwX/tls", 0x7ffd9c9b4d70) = -1 ENOENT (No such file or directory)
21626 open("/tmp/_MEInVVZwX/x86_64/libncurses.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
21626 stat("/tmp/_MEInVVZwX/x86_64", 0x7ffd9c9b4d70) = -1 ENOENT (No such file or directory)
21626 open("/tmp/_MEInVVZwX/libncurses.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
21626 stat("/tmp/_MEInVVZwX", {st_mode=S_IFDIR|0700, st_size=1460, ...}) = 0
21626 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
21626 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
21626 open("/lib/x86_64-linux-gnu/libncurses.so.5", O_RDONLY|O_CLOEXEC) = 3
21626 open("/tmp/_MEInVVZwX/libtinfo.so.5", O_RDONLY|O_CLOEXEC) = 3
21626 open("/tmp/_MEInVVZwX/libdl.so.2", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
21626 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
21626 open("/lib/x86_64-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
21626 open("/tmp/_MEInVVZwX/libc.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
21626 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
21626 open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
21626 +++ exited with 127 +++
21622 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=21626, si_uid=1000, si_status=127, si_utime=0, si_stime=0} ---
21622 openat(AT_FDCWD, "/etc", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 4
21622 open("/etc/debian_version", O_RDONLY|O_CLOEXEC) = 4
21622 getcwd("/tmp", 1024)              = 5
21622 +++ exited with 2 +++
21621 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=21622, si_uid=1000, si_status=2, si_utime=52, si_stime=6} ---
[...]
21621 openat(AT_FDCWD, "/tmp/_MEInVVZwX/lib2to3/tests/data", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 6
21621 stat("/tmp/_MEInVVZwX/lib2to3/tests/data/README", {st_mode=S_IFREG|0700, st_size=404, ...}) = 0
21621 unlink("/tmp/_MEInVVZwX/lib2to3/tests/data/README") = 0
21621 rmdir("/tmp/_MEInVVZwX/lib2to3/tests/data") = 0
21621 rmdir("/tmp/_MEInVVZwX/lib2to3/tests") = 0
21621 stat("/tmp/_MEInVVZwX/lib2to3/PatternGrammar3.5.4.final.0.pickle", {st_mode=S_IFREG|0700, st_size=2093, ...}) = 0
21621 unlink("/tmp/_MEInVVZwX/lib2to3/PatternGrammar3.5.4.final.0.pickle") = 0
[...now we're clearly winding down...]
21621 rmdir("/tmp/_MEInVVZwX/lib/python3.5") = 0
21621 rmdir("/tmp/_MEInVVZwX/lib")      = 0
[...]
21621 rmdir("/tmp/_MEInVVZwX")          = 0
21621 +++ exited with 2 +++

It appears to my untrained eye that Borg had printed its "Archive test does not exist" and finished its useful work and that this error occurs in the winding down phase.

htgoebel commented 6 years ago

The uname shell-command is from platform.uname().

After the "/bin/sh" "-c" "uname -p 2> /dev/null"the very first library loaded it ncurses, what is curious! When I'm running strace -f -e trace=file /bin/sh -c uname -p this first load libtinfo (which is not installed on my system), libdl and libc. Maybe you'd removed too many lines?

Anyway, the question is: Why is /bin/sh (or uname) opening libtinfo and libncurses? Maybe the environment is different? Different TERM settings? OTOH, libtinfo belongs to ncurses. So why is ncurses loaded here?

vphantom commented 6 years ago

Found it! The problem is that my /bin/sh is a symlink to bash instead of Debian's dash on a fresh install. My bash is linked with your libtinfo and my libncurses, with hilarious consequences. Here's the simplest way to reproduce it reliably, if you have access to Docker:

$ docker run --rm -it -v /path/to/borg-linux64:/bin/borg debian:jessie-slim bash

root@887d078bf869:/# borg list /tmp/testborg
Repository /tmp/testborg does not exist.

root@887d078bf869:/# rm /bin/sh ; ln -s /bin/bash /bin/sh

root@887d078bf869:/# borg list /tmp/testborg
/bin/sh: symbol lookup error: /lib/x86_64-linux-gnu/libncurses.so.5: undefined symbol: _nc_putchar
Repository /tmp/testborg does not exist.

Since the purpose of the bundle is to run on the widest variety of systems possible, it seems that including dash (123kb) or the simplest shell necessary could be an option.

ThomasWaldmann commented 6 years ago

I'll have a look whether we can call platform.uname() like we call ssh (with a cleaned up env, so everything will come from the host system and the lib mixup is avoided).

ThomasWaldmann commented 6 years ago

See PR #3739 - not totally sure whether setting os.environ to a new dict works transparently enough.

ThomasWaldmann commented 6 years ago

@vphantom i have a test binary soon, can you test it?

vphantom commented 6 years ago

@ThomasWaldmann Of course. :) Just direct me to the test binary when it'll be ready.

ThomasWaldmann commented 6 years ago

sha256: 25aec1039b38cbdb9839358606e80e2fa59a0ba8f781ce0ea8d0070abda8e9da

https://paste.thinkmo.de/J7U7huLz#borg-linux64-pre1.1.5

there it is! ^^^

https://github.com/borgbackup/borg/blob/1.1-maint/docs/changes.rst#version-115-not-released-yet

vphantom commented 6 years ago

I can still reproduce the issue:

lis@titan:~$ docker run --rm -it -v /home/lis/bin/borg:/bin/borg-1.1.4 -v /tmp/borg-linux64-pre1.1.5:/bin/borg-pre1.1.5 debian:jessie-slim bash
root@baf6b9b977d4:/# borg-1.1.4 --version
borg-1.1.4 1.1.4
root@baf6b9b977d4:/# borg-pre1.1.5 --version
borg-pre1.1.5 1.1.5.dev98+gad7b687
root@baf6b9b977d4:/# borg-1.1.4 list /tmp/nonexistent
Repository /tmp/nonexistent does not exist.
root@baf6b9b977d4:/# borg-pre1.1.5 list /tmp/nonexistent
Repository /tmp/nonexistent does not exist.
root@baf6b9b977d4:/# rm /bin/sh ; ln -s /bin/bash /bin/sh  
root@baf6b9b977d4:/# borg-1.1.4 list /tmp/nonexistent
/bin/sh: symbol lookup error: /lib/x86_64-linux-gnu/libncurses.so.5: undefined symbol: _nc_putchar
Repository /tmp/nonexistent does not exist.
root@baf6b9b977d4:/# borg-pre1.1.5 list /tmp/nonexistent
/bin/sh: symbol lookup error: /lib/x86_64-linux-gnu/libncurses.so.5: undefined symbol: _nc_putchar
Repository /tmp/nonexistent does not exist.
ThomasWaldmann commented 6 years ago

Crap. Hmm, guess what I did in the code was pointless as it uses clone to clone the current process (with the dirty env) rather than creating a new (sub)process (with the cleaned env).

So, can we do anything about it? @htgoebel @enkore

htgoebel commented 6 years ago

Is prepare_subprocess_env setting LD_LIBRARY_PATH back to LD_LIBARAY_PATH_ORIG?

ThomasWaldmann commented 6 years ago

@htgoebel it depends, see comments there: https://github.com/borgbackup/borg/blob/1.1-maint/src/borg/helpers.py#L2388

ThomasWaldmann commented 6 years ago

I'll try to fix by replacing the platform.uname() (which does a shell call internally just to get processor info) by os.uname().

ThomasWaldmann commented 6 years ago

1296e12b2be2e1fc2d83c02c9cc644af1edeb0ce84e8713678bf8b0b7a92e389

next try: https://paste.thinkmo.de/HyNyfZj7#borg-linux64-pre1.1.5-2

vphantom commented 6 years ago

Success!

$ docker run --rm -it -v /home/lis/bin/borg:/bin/borg-1.1.4 -v /tmp/borg-linux64-pre1.1.5-2:/bin/borg-pre1.1.5-2 debian:jessie-slim bash
root@5b7f2eb78199:/# borg-1.1.4 --version
borg-1.1.4 1.1.4
root@5b7f2eb78199:/# borg-pre1.1.5-2 --version
borg-pre1.1.5-2 1.1.5.dev100+g9b2417e
root@5b7f2eb78199:/# borg-1.1.4 list /tmp/nonexistent
Repository /tmp/nonexistent does not exist.
root@5b7f2eb78199:/# borg-pre1.1.5-2 list /tmp/nonexistent
Repository /tmp/nonexistent does not exist.
root@5b7f2eb78199:/# rm /bin/sh ; ln -s /bin/bash /bin/sh
root@5b7f2eb78199:/# borg-1.1.4 list /tmp/nonexistent
/bin/sh: symbol lookup error: /lib/x86_64-linux-gnu/libncurses.so.5: undefined symbol: _nc_putchar
Repository /tmp/nonexistent does not exist.
root@5b7f2eb78199:/# borg-pre1.1.5-2 list /tmp/nonexistent
Repository /tmp/nonexistent does not exist.
ThomasWaldmann commented 6 years ago

\o/

Thanks for testing!