Race condition when custom .ctors entries call ip2unix symbols

[aszlig]

This was reported via email and it happens whenever an application places entries via eg. __attribute__((constructor)) into the .ctors section. If the constructor then calls functions that we wrap, we might end up accessing uninitialised memory because at that time static data on our side might not be initialised.

The reporter also included a traceback:

#0  0x00007f1d834b56ed in std::__detail::_Mod_range_hashing::operator() (this=0x7f1d8371f740 <all_fds>, __num=3, __den=0) at /usr/include/c++/8/bits/hashtable_policy.h:434
#1  0x00007f1d834f36fe in std::__detail::_Hash_code_base<int, int, std::__detail::_Identity, std::hash<int>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, false>::_M_bucket_index (
    this=0x7f1d8371f740 <all_fds>, __c=3, __n=0) at /usr/include/c++/8/bits/hashtable_policy.h:1307
#2  0x00007f1d834f225c in std::_Hashtable<int, int, std::allocator<int>, std::__detail::_Identity, std::equal_to<int>, std::hash<int>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash,
+std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<false, true, true> >::_M_bucket_index (this=0x7f1d8371f740 <all_fds>, __k=@0x7ffc611d911c: 3, __c=3) at /usr/include/c++/8/bits/hashtable.h:638
#3  0x00007f1d834f092e in std::_Hashtable<int, int, std::allocator<int>, std::__detail::_Identity, std::equal_to<int>, std::hash<int>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash,
+std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<false, true, true> >::find (this=0x7f1d8371f740 <all_fds>, __k=@0x7ffc611d911c: 3) at /usr/include/c++/8/bits/hashtable.h:1435
#4  0x00007f1d834ef7bf in std::unordered_set<int, std::hash<int>, std::equal_to<int>, std::allocator<int> >::find (this=0x7f1d8371f740 <all_fds>, __x=@0x7ffc611d911c: 3) at /usr/include/c++/8/bits/unordered_set.h:650
#5  0x00007f1d834ee46c in Systemd::has_fd (fd=3) at ../src/systemd.cc:328
#6  0x00007f1d834bd504 in close (fd=3) at ../src/preload.cc:544
#7  0x00007f1d82dab0c9 in init_fips_mode () at crypto/o_init.c:36
#8  OPENSSL_init_library () at crypto/o_init.c:70
#9  0x00007f1d8372f8ba in call_init (l=<optimized out>, argc=argc@entry=3, argv=argv@entry=0x7ffc611d9598, env=env@entry=0x7ffc611d95b8) at dl-init.c:72
#10 0x00007f1d8372f9ba in call_init (env=0x7ffc611d95b8, argv=0x7ffc611d9598, argc=3, l=<optimized out>) at dl-init.c:30
#11 _dl_init (main_map=0x7f1d8394e1d0, argc=3, argv=0x7ffc611d9598, env=0x7ffc611d95b8) at dl-init.c:119
#12 0x00007f1d83720fda in _dl_start_user () from /lib64/ld-linux-x86-64.so.2
#13 0x0000000000000003 in ?? ()
#14 0x00007ffc611da602 in ?? ()
#15 0x00007ffc611da605 in ?? ()
#16 0x00007ffc611da608 in ?? ()
#17 0x0000000000000000 in ?? ()

So we should be able to trivially reproduce it with something like this:

void __attribute__ ((constructor)) foobar(void) {
    close(1);
}

[tiboratAS]

I recompiled without systemd support and ran the ran the same test that was run with systemd support. It still crashes with a FP exception. It occurs in an unsorted set used in the socket.cc code.

#0  0x00007ffff7b7644d in std::__detail::_Mod_range_hashing::operator() (this=0x7ffff7dcf5c0 <Socket::registry>, __num=3, __den=0)
    at /usr/include/c++/8/bits/hashtable_policy.h:434
#1  0x00007ffff7b95378 in std::__detail::_Hash_code_base<int, std::pair<int const, std::shared_ptr<Socket> >, std::__detail::_Select1st, std::hash<int>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, false>::_M_bucket_index (this=0x7ffff7dcf5c0 <Socket::registry>, __c=3, __n=0)
    at /usr/include/c++/8/bits/hashtable_policy.h:1307
#2  0x00007ffff7b93c7c in std::_Hashtable<int, std::pair<int const, std::shared_ptr<Socket> >, std::allocator<std::pair<int const, std::shared_ptr<Socket> > >, std::__detail::_Select1st, std::equal_to<int>, std::hash<int>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<false, false, true> >::_M_bucket_index (this=0x7ffff7dcf5c0 <Socket::registry>, __k=@0x7fffffffe074: 3, __c=3) at /usr/include/c++/8/bits/hashtable.h:638
#3  0x00007ffff7b928ce in std::_Hashtable<int, std::pair<int const, std::shared_ptr<Socket> >, std::allocator<std::pair<int const, std::shared_ptr<Socket> > >, std::__detail::_Select1st, std::equal_to<int>, std::hash<int>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<false, false, true> >::find (this=0x7ffff7dcf5c0 <Socket::registry>, __k=@0x7fffffffe074: 3) at /usr/include/c++/8/bits/hashtable.h:1435
#4  0x00007ffff7b90dbb in std::unordered_map<int, std::shared_ptr<Socket>, std::hash<int>, std::equal_to<int>, std::allocator<std::pair<int const, std::shared_ptr<Socket> > > >::find (this=0x7ffff7dcf5c0 <Socket::registry>, __x=@0x7fffffffe074: 3) at /usr/include/c++/8/bits/unordered_map.h:921
#5  0x00007ffff7b8c8ef in Socket::find (fd=3) at ../src/socket.cc:14
#6  0x00007ffff7b85b6c in Socket::when<int>(int, std::function<int (std::shared_ptr<Socket>)>, std::function<int ()>) (fd=3, f=..., d=...) at ../src/socket.hh:32
#7  0x00007ffff7b7ddc6 in close (fd=3) at ../src/preload.cc:559
#8  0x00007ffff746c0c9 in init_fips_mode () at crypto/o_init.c:36
#9  OPENSSL_init_library () at crypto/o_init.c:70
#10 0x00007ffff7ddf8ba in call_init (l=<optimized out>, argc=argc@entry=4, argv=argv@entry=0x7fffffffe3e8, env=env@entry=0x7fffffffe410) at dl-init.c:72
#11 0x00007ffff7ddf9ba in call_init (env=0x7fffffffe410, argv=0x7fffffffe3e8, argc=4, l=<optimized out>) at dl-init.c:30
#12 _dl_init (main_map=0x7ffff7ffe1d0, argc=4, argv=0x7fffffffe3e8, env=0x7fffffffe410) at dl-init.c:119
#13 0x00007ffff7dd0fda in _dl_start_user () from /lib64/ld-linux-x86-64.so.2
#14 0x0000000000000004 in ?? ()
#15 0x00007fffffffe65a in ?? ()
#16 0x00007fffffffe65d in ?? ()
#17 0x00007fffffffe660 in ?? ()
#18 0x00007fffffffe663 in ?? ()
#19 0x0000000000000000 in ?? ()

[aszlig]

Just tried to write a small regression test but couldn't reproduce this error.

Regression test

# Regression test for https://github.com/nixcloud/ip2unix/issues/29
{ pkgs, ip2unix, ... }:

pkgs.runCommand "test-custom-ctor" {
  nativeBuildInputs = [
    ip2unix pkgs.netcat-openbsd pkgs.systemd
    (pkgs.writeCBin "testprog" ''
      #include <stddef.h>
      #include <stdio.h>
      #include <stdlib.h>
      #include <string.h>
      #include <unistd.h>
      #include <netinet/ip.h>

      void __attribute__ ((constructor)) foobar(void) {
        close(3);
        fputs("testprog: Closed file descriptor 3.\n", stderr);
      }

      int main(void) {
        int fd, conn;
        char buf[7];
        struct sockaddr_in sa;

        if ((fd = socket(AF_INET, SOCK_STREAM, 0)) == -1) {
          perror("socket");
          return EXIT_FAILURE;
        }

        sa.sin_family = AF_INET;
        sa.sin_addr.s_addr = htonl(INADDR_ANY);
        sa.sin_port = htons(666);

        if (bind(fd, (struct sockaddr *)&sa, sizeof sa) == -1) {
          close(fd);
          perror("bind");
          return EXIT_FAILURE;
        }

        if (listen(fd, 10) == -1) {
          close(fd);
          perror("listen");
          return EXIT_FAILURE;
        }

        if ((conn = accept(fd, NULL, 0)) == -1) {
          close(fd);
          perror("accept");
          return EXIT_FAILURE;
        }

        if (recv(conn, buf, sizeof(buf) - 1, MSG_WAITALL) == -1) {
          close(conn);
          close(fd);
          perror("recv");
          return EXIT_FAILURE;
        }

        buf[sizeof(buf) - 1] == '\0';
        close(conn);
        close(fd);

        if (strncmp(buf, "foobar", sizeof(buf)) != 0) {
          fprintf(stderr, "Message \"%s\" didn't match \"foobar\".\n", buf);
          return EXIT_FAILURE;
        }

        fputs("Got \"foobar\" from socket.\n", stderr);
        return EXIT_SUCCESS;
      }
    '')
  ];
} ''
  systemd-socket-activate -l "$PWD/test.socket" \
    ip2unix -vvvvv -r systemd testprog &
  while [ ! -e test.socket ]; do sleep 1; done

  echo -n foobar | nc -U test.socket
  wait -n
  touch "$out"
''

Output:

Listening on /build/test.socket as 3.
Communication attempt on fd 3.
Execing ip2unix (ip2unix -vvvvv -r systemd testprog)
ip2unix[5] preload.cc:562:ip2unix_wrap_close TRACE: close(3)
ip2unix[5] systemd.cc:196:init INFO: Number of systemd file descriptors found in LISTEN_FDS: 1
ip2unix[5] systemd.cc:246:init DEBUG: Adding unnamed systemd unix file descriptor 3 to pool.
ip2unix[5] systemd.cc:101:update_env DEBUG: Setting __IP2UNIX_SYSTEMD_FDS to '3&f'.
ip2unix[5] systemd.cc:112:update_env DEBUG: Setting __IP2UNIX_SYSTEMD_FDMAP to ''.
ip2unix[5] systemd.cc:269:init DEBUG: Finished getting systemd file descriptors.
ip2unix[5] preload.cc:569:ip2unix_wrap_close DEBUG: Prevented socket fd 3 from being closed, because it's a file descriptor passed by systemd.
testprog: Closed file descriptor 3.
ip2unix[5] preload.cc:91:ip2unix_wrap_socket TRACE: socket(2, 1, 0)
ip2unix[5] socket.cc:40:create INFO: Registered socket with fd 4, domain 2, type 1 and protocol 0.
ip2unix[5] preload.cc:288:ip2unix_wrap_bind TRACE: bind(4, 0x7fffffffe710, 16)
ip2unix[5] systemd.cc:278:remove_fd INFO: Disassociating systemd file descriptor 3.
ip2unix[5] systemd.cc:101:update_env DEBUG: Setting __IP2UNIX_SYSTEMD_FDS to ''.
ip2unix[5] systemd.cc:112:update_env DEBUG: Setting __IP2UNIX_SYSTEMD_FDMAP to ''.
ip2unix[5] systemd.cc:296:remove_fd DEBUG: Setting new flags 1 on fd 3, previos flags were 0.
ip2unix[5] socket.cc:225:make_unix INFO: Re-using socket with fd 3.
ip2unix[5] socket.cc:255:make_unix INFO: Replaced socket fd 4 by socket with fd 3.
ip2unix[5] socket.cc:308:activate INFO: Socket fd 4 marked for systemd socket activation.
ip2unix[5] preload.cc:156:ip2unix_wrap_listen TRACE: listen(4, 10)
ip2unix[5] preload.cc:321:ip2unix_wrap_accept TRACE: accept(4, 0, 0)
ip2unix[5] socket.cc:492:accept INFO: Accepted socket fd 3 registered as a children of socket fd 4.
ip2unix[5] preload.cc:562:ip2unix_wrap_close TRACE: close(3)
ip2unix[5] socket.cc:649:close INFO: Closing socket fd 3.
ip2unix[5] socket.cc:666:close INFO: Socket fd 3 unregistered.
ip2unix[5] preload.cc:562:ip2unix_wrap_close TRACE: close(4)
ip2unix[5] socket.cc:645:close INFO: Not closing socket fd 4 because it's a systemd socket.
ip2unix[5] socket.cc:666:close INFO: Socket fd 4 unregistered.
Got "foobar" from socket.

@tiboratAS: Is the program you're using publicly available, so I can directly use the program you're using as a regression test?