one step further - i would say, that fork() is the culprit. i added some s_log in the librwap.c code and it appears, that "case 0" never is being executed.
i found http://cygwin.com/faq.html#faq.using.fixing-fork-failures , so there probably needs to be done some special handling for that. (disable pthread on cygwin?) regards rolnd 2014.02.27 15:55:12 LOG7[16476:25769803872]: ECDH initialized with curve prime256v1 2014.02.27 15:55:12 LOG7[16476:25769803872]: SSL options set: 0x00000004 2014.02.27 15:55:12 LOG5[16476:25769803872]: Configuration successful 2014.02.27 15:55:12 LOG7[16476:25769803872]: child spawned 2014.02.27 15:55:12 LOG7[16476:25769803872]: default - close ipc_socket 2014.02.27 15:55:12 LOG7[16476:25769803872]: child spawned 2014.02.27 15:55:12 LOG7[16476:25769803872]: default - close ipc_socket 2014.02.27 15:55:12 LOG7[16476:25769803872]: child spawned 2014.02.27 15:55:12 LOG7[16476:25769803872]: default - close ipc_socket 2014.02.27 15:55:12 LOG7[16476:25769803872]: child spawned 2014.02.27 15:55:12 LOG7[16476:25769803872]: default - close ipc_socket 2014.02.27 15:55:12 LOG7[16476:25769803872]: child spawned 2014.02.27 15:55:12 LOG7[16476:25769803872]: default - close ipc_socket 2014.02.27 15:55:12 LOG7[16476:25769803872]: Service [rsync] (FD=11) bound to 0.0.0.0:1873 2014.02.27 15:55:12 LOG7[16476:25769803872]: Created pid file /var/run/stunnel.pid 2014.02.27 15:55:20 LOG7[16476:25769803872]: Service [rsync] accepted (FD=3) from 192.168.0.116:60302 2014.02.27 15:55:20 LOG7[16476:25770120192]: Service [rsync] started 2014.02.27 15:55:20 LOG7[16476:25770120192]: Waiting for a libwrap process 2014.02.27 15:55:20 LOG7[16476:25770120192]: Acquired libwrap process #0 2014.02.27 15:55:20 LOG7[16476:25770120192]: Releasing libwrap process #0 2014.02.27 15:55:20 LOG7[16476:25770120192]: Released libwrap process #0 2014.02.27 15:55:20 LOG4[16476:25770120192]: Service [rsync] REFUSED by libwrap from 192.168.0.116:60302 2014.02.27 15:55:20 LOG7[16476:25770120192]: See hosts_access(5) manual for details 2014.02.27 15:55:20 LOG5[16476:25770120192]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket 2014.02.27 15:55:20 LOG7[16476:25770120192]: Local socket (FD=3) closed 2014.02.27 15:55:20 LOG7[16476:25770120192]: Service [rsync] finished (0 left) libwrap.c for(i=0; i<num_processes; ++i) { /* spawn a child */ s_log(LOG_DEBUG, "child spawned"); if(s_socketpair(AF_UNIX, SOCK_STREAM, 0, ipc_socket+2*i, 0, "libwrap_init")) { s_log(LOG_DEBUG, "libwrap_init\n"); return 1; } fflush(NULL); switch(fork()) { case -1: /* error */ s_log(LOG_DEBUG, "ioerror fork"); ioerror("fork"); return 1; case 0: /* child */ s_log(LOG_DEBUG, "case 0"); drop_privileges(0); /* libwrap processes are not chrooted */ close(0); /* stdin */ close(1); /* stdout */ if(!global_options.option.foreground) /* for logging in read_fd */ close(2); /* stderr */ for(j=0; j<=i; ++j) /* close parent-side sockets created so far */ s_log(LOG_DEBUG, "close ipc socket\n"); close(ipc_socket[2*j]); while(1) { /* main libwrap child loop */ s_log(LOG_DEBUG, "in ptrheads - main child loop - servname: %s \n",servname); if(read_fd(ipc_socket[2*i+1], servname, SERVNAME_LEN, &rfd)<=0) _exit(0); s_log(LOG_DEBUG, "in ptrheads - servname: %s \n",servname); result=check(servname, rfd); write(ipc_socket[2*i+1], (u8 *)&result, sizeof result); if(rfd>=0) close(rfd); } default: /* parent */ s_log(LOG_DEBUG, "default - close ipc_socket"); close(ipc_socket[2*i+1]); /* child-side socket */ ------ after a lot of digging into it, i found it must be a problem related to pthreads. when i compile stunnel with --with-threads=fork , it works. 2014.02.27 14:19:21 LOG5[5500:0]: stunnel 4.56 on x86_64-unknown-cygwin platform 2014.02.27 14:19:21 LOG5[5500:0]: Compiled/running with OpenSSL 1.0.1e 11 Feb 2013 2014.02.27 14:19:21 LOG5[5500:0]: Threading:FORK Sockets:POLL,IPv6 SSL:ENGINE,OCSP Auth:LIBWRAP 2014.02.27 14:19:21 LOG5[5500:0]: Reading configuration from file /etc/stunnel/stunnel.conf 2014.02.27 14:19:21 LOG7[5500:0]: Compression not enabled 2014.02.27 14:19:21 LOG7[5500:0]: PRNG seeded successfully 2014.02.27 14:19:21 LOG6[5500:0]: Initializing service [rsync] 2014.02.27 14:19:21 LOG4[5500:0]: Insecure file permissions on /etc/stunnel/stunnel.pem 2014.02.27 14:19:21 LOG7[5500:0]: Certificate: /etc/stunnel/stunnel.pem 2014.02.27 14:19:21 LOG7[5500:0]: Certificate loaded 2014.02.27 14:19:21 LOG7[5500:0]: Key file: /etc/stunnel/stunnel.pem 2014.02.27 14:19:21 LOG7[5500:0]: Private key loaded 2014.02.27 14:19:21 LOG7[5500:0]: Using DH parameters from /etc/stunnel/stunnel.pem 2014.02.27 14:19:21 LOG7[5500:0]: DH initialized with 1024-bit key 2014.02.27 14:19:21 LOG7[5500:0]: ECDH initialized with curve prime256v1 2014.02.27 14:19:21 LOG7[5500:0]: SSL options set: 0x00000004 2014.02.27 14:19:21 LOG5[5500:0]: Configuration successful 2014.02.27 14:19:21 LOG7[5500:0]: Service [rsync] (FD=6) bound to 0.0.0.0:1873 2014.02.27 14:19:21 LOG7[5500:0]: Created pid file /var/run/stunnel.pid 2014.02.27 14:19:36 LOG7[5500:0]: Service [rsync] accepted (FD=3) from 192.168.0.116:60289 2014.02.27 14:19:36 LOG7[14636:0]: Service [rsync] started 2014.02.27 14:19:36 LOG7[14636:0]: Service [rsync] permitted by libwrap from 192.168.0.116:60289 2014.02.27 14:19:36 LOG5[14636:0]: Service [rsync] accepted connection from 192.168.0.116:60289 2014.02.27 14:19:36 LOG7[14636:0]: SSL state (accept): before/accept initialization 2014.02.27 14:19:36 LOG7[14636:0]: SNI: no virtual services defined --snip-- > > Hi, > i have a strange problem with tcp_wrappers in conjunction with stunnel cygwin > port. (cc`ing stunnel cygwin maintainer because of that). > > I`m trying to secure an rsync which is started in daemon-mode in an > inetd-style via stunnel. I`m on Win8 64Bit with a recent 64bit Cygwin > installation. > > When i put rsync: ALL in "/etc/hosts.allow" all is fine, but when i try to > restrict connection to a single IP-Adress it doesn`t work. I spent some time > on this but i don`t get this working. > > See the log snippets below this mail. > > successful connection looks like this: > 2014.02.23 12:36:22 LOG7[16424:25770120176]: Released libwrap process #0 > 2014.02.23 12:36:22 LOG7[16424:25770120176]: Service [rsync] permitted by > libwrap from 192.168.0.116:60222 > 2014.02.23 12:36:22 LOG5[16424:25770120176]: Service [rsync] accepted > connection from 192.168.0.116:60222 > > unsuccessful connection looks like this: > 2014.02.23 12:34:34 LOG7[17800:25770120176]: Released libwrap process #0 > 2014.02.23 12:34:34 LOG4[17800:25770120176]: Service [rsync] REFUSED by > libwrap from 192.168.0.116:60221 > 2014.02.23 12:34:34 LOG7[17800:25770120176]: See hosts_access(5) manual for > details > > Afaik, tcpwrappers only checks for IP-address , not source port - correct ? > > I`m curious about IP:PORT in the logs. > > I`m no programmer, but if i get this right, the "accepted_address" is being > passed to libwrap to be checked for authentication and libwrap tells if > connection is permitted or not. So, i`m curious why "accepted_address" seems > to contain IP:PORT where it should possibly only contain "IP". > > from the stunnel sources: > > client.c > ---snipp--- > /* authenticate based on retrieved IP address of the client */ > accepted_address=s_ntop(&c->peer_addr, c->peer_addr_len); > #ifdef USE_LIBWRAP > libwrap_auth(c, accepted_address); > #endif /* USE_LIBWRAP */ > auth_user(c, accepted_address); > s_log(LOG_NOTICE, "Service [%s] accepted connection from %s", > c->opt->servname, accepted_address); > str_free(accepted_address); > } > > ---snipp--- > > libwrap.c > ---snipp--- > #endif /* USE_PTHREAD */ > { /* use original, synchronous libwrap calls */ > enter_critical_section(CRIT_LIBWRAP); > result=check(c->opt->servname, c->local_rfd.fd); > leave_critical_section(CRIT_LIBWRAP); > } > if(!result) { > s_log(LOG_WARNING, "Service [%s] REFUSED by libwrap from %s", > c->opt->servname, accepted_address); > s_log(LOG_DEBUG, "See hosts_access(5) manual for details"); > longjmp(c->err, 1); > } > s_log(LOG_DEBUG, "Service [%s] permitted by libwrap from %s", > c->opt->servname, accepted_address); > } > > ---snipp--- > > Bug ? > > I`m out of ideas otherwise... > > regards > Roland > > > > > stunnel.exe info: > > 2014.02.23 12:36:16 LOG7[16424:25769803872]: Clients allowed=125 > 2014.02.23 12:36:16 LOG5[16424:25769803872]: stunnel 4.56 on > x86_64-unknown-cygwin platform > 2014.02.23 12:36:16 LOG5[16424:25769803872]: Compiled/running with OpenSSL > 1.0.1e 11 Feb 2013 > 2014.02.23 12:36:16 LOG5[16424:25769803872]: Threading:PTHREAD > Sockets:POLL,IPv6 SSL:ENGINE,OCSP Auth:LIBWRAP > 2014.02.23 12:36:16 LOG5[16424:25769803872]: Reading configuration from file > /etc/stunnel/stunnel.conf > > > This one works: > > $ cat /etc/hosts.allow > rsync: ALL > > stunnel log: > 2014.02.23 12:36:22 LOG7[16424:25770120176]: Acquired libwrap process #0 > 2014.02.23 12:36:22 LOG7[16424:25770120176]: Releasing libwrap process #0 > 2014.02.23 12:36:22 LOG7[16424:25770120176]: Released libwrap process #0 > 2014.02.23 12:36:22 LOG7[16424:25770120176]: Service [rsync] permitted by > libwrap from 192.168.0.116:60222 > 2014.02.23 12:36:22 LOG5[16424:25770120176]: Service [rsync] accepted > connection from 192.168.0.116:60222 > 2014.02.23 12:36:22 LOG7[16424:25770120176]: SSL state (accept): > before/accept initialization > 2014.02.23 12:36:22 LOG7[16424:25770120176]: SNI: no virtual services defined > 2014.02.23 12:36:22 LOG7[16424:25770120176]: SSL state (accept): SSLv3 read > client hello A > 2014.02.23 12:36:22 LOG7[16424:25770120176]: SSL state (accept): SSLv3 write > server hello A > 2014.02.23 12:36:22 LOG7[16424:25770120176]: SSL state (accept): SSLv3 write > certificate A > 2014.02.23 12:36:22 LOG7[16424:25770120176]: SSL state (accept): SSLv3 write > key exchange A > 2014.02.23 12:36:22 LOG7[16424:25770120176]: SSL state (accept): SSLv3 write > certificate request A > > > All of the following ones do NOT work > > $ cat /etc/hosts.allow > rsync: 192.168.0.116 > > 2014.02.23 11:48:01 LOG5[17800:25769803872]: Configuration successful > 2014.02.23 11:48:01 LOG7[17800:25769803872]: Service [rsync] (FD=11) bound to > 0.0.0.0:1873 > 2014.02.23 11:48:01 LOG7[17800:25769803872]: Created pid file > /var/run/stunnel.pid > 2014.02.23 12:34:34 LOG7[17800:25769803872]: Service [rsync] accepted (FD=3) > from 192.168.0.116:60221 > 2014.02.23 12:34:34 LOG7[17800:25770120176]: Service [rsync] started > 2014.02.23 12:34:34 LOG7[17800:25770120176]: Waiting for a libwrap process > 2014.02.23 12:34:34 LOG7[17800:25770120176]: Acquired libwrap process #0 > 2014.02.23 12:34:34 LOG7[17800:25770120176]: Releasing libwrap process #0 > 2014.02.23 12:34:34 LOG7[17800:25770120176]: Released libwrap process #0 > 2014.02.23 12:34:34 LOG4[17800:25770120176]: Service [rsync] REFUSED by > libwrap from 192.168.0.116:60221 > 2014.02.23 12:34:34 LOG7[17800:25770120176]: See hosts_access(5) manual for > details > 2014.02.23 12:34:34 LOG5[17800:25770120176]: Connection reset: 0 byte(s) sent > to SSL, 0 byte(s) sent to socket > 2014.02.23 12:34:34 LOG7[17800:25770120176]: Local socket (FD=3) closed > 2014.02.23 12:34:34 LOG7[17800:25770120176]: Service [rsync] finished (0 left) > 2014.02.23 12:34:34 LOG7[17800:25770120176]: str_stats: 1 block(s), 32 data > byte(s), 58 control byte(s) > 2014.02.23 12:36:15 LOG7[17800:25769803872]: Dispatching signals from the > signal pipe > > > $ cat /etc/hosts.allow > rsync: 192.168.0.116 : allow > > 2014.02.23 12:44:36 LOG7[5248:25770120176]: Waiting for a libwrap process > 2014.02.23 12:44:36 LOG7[5248:25770120176]: Acquired libwrap process #0 > 2014.02.23 12:44:36 LOG7[5248:25770120176]: Releasing libwrap process #0 > 2014.02.23 12:44:36 LOG7[5248:25770120176]: Released libwrap process #0 > 2014.02.23 12:44:36 LOG4[5248:25770120176]: Service [rsync] REFUSED by > libwrap from 192.168.0.116:60223 > 2014.02.23 12:44:36 LOG7[5248:25770120176]: See hosts_access(5) manual for > details > 2014.02.23 12:44:36 LOG5[5248:25770120176]: Connection reset: 0 byte(s) sent > to SSL, 0 byte(s) sent to socket > 2014.02.23 12:44:36 LOG7[5248:25770120176]: Local socket (FD=3) closed > 2014.02.23 12:44:36 LOG7[5248:25770120176]: Service [rsync] finished (0 left) > 2014.02.23 12:44:36 LOG7[5248:25770120176]: str_stats: 1 block(s), 32 data > byte(s), 58 control byte(s) > > $ cat /etc/hosts.allow > rsync: 192.168.0.116/32 : allow > > 2014.02.23 12:46:02 LOG7[10392:25770120176]: Service [rsync] started > 2014.02.23 12:46:02 LOG7[10392:25770120176]: Waiting for a libwrap process > 2014.02.23 12:46:02 LOG7[10392:25770120176]: Acquired libwrap process #0 > 2014.02.23 12:46:02 LOG7[10392:25770120176]: Releasing libwrap process #0 > 2014.02.23 12:46:02 LOG7[10392:25770120176]: Released libwrap process #0 > 2014.02.23 12:46:02 LOG4[10392:25770120176]: Service [rsync] REFUSED by > libwrap from 192.168.0.116:60224 > 2014.02.23 12:46:02 LOG7[10392:25770120176]: See hosts_access(5) manual for > details > 2014.02.23 12:46:02 LOG5[10392:25770120176]: Connection reset: 0 byte(s) sent > to SSL, 0 byte(s) sent to socket > 2014.02.23 12:46:02 LOG7[10392:25770120176]: Local socket (FD=3) closed > 2014.02.23 12:46:02 LOG7[10392:25770120176]: Service [rsync] finished (0 left) > 2014.02.23 12:46:02 LOG7[10392:25770120176]: str_stats: 1 block(s), 32 data > byte(s), 58 control byte(s) > > > > > $ cat /etc/stunnel/stunnel.conf > client = no > foreground = yes > > #setuid = root > #setgid = root > # > pid = /var/run/stunnel.pid > > debug = 7 > output = /var/log/stunnel.log > > socket = l:TCP_NODELAY=1 > socket = r:TCP_NODELAY=1 > > socket = l:SO_LINGER=1:60 > > > [rsync] > accept = 1873 > cert = /etc/stunnel/stunnel.pem > client = no > verify = 0 > libwrap = yes > exec = /usr/bin/rsync > execargs = rsync --daemon --config /etc/rsync-ssl/rsync-ssl.conf -- Problem reports: http://cygwin.com/problems.html FAQ: http://cygwin.com/faq/ Documentation: http://cygwin.com/docs.html Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple
