[stunnel-users] Plz help the n00b (syslog-ng & stunnel)

Fri May 25 19:33:31 CEST 2007

I should add a little design information.  Multiple machines send standard 
syslog udp/514 to this server, which accepts it via syslog-ng, and then 
forwards it to stunnel localhost:5140/tcp, which is supposed to connect 
to "THE" syslog server on 5140/tcp.

On Friday 25 May 2007, F.M. Taylor formed electrons in this pattern:
> Greetings all.  Seemed simple enough, but I can seem to get it to work.  I
> have obviously missed something simple. Here is the info you will need (and
> probably some you won't).  I have tried every combination of options I can
> think of, and I have searched the archives and the web.  It looks like it
> is almost working, but the server I am trying to connect to never sees the
> data (however "they" have it working on "their" systems, so it must be me).
>  "They" say it connects, talks a little, no real data xfer, closes, then
> more data (followed by the obligatory TCP_RSTs for dead connects).
>
> [insert begging]
>
> [root at bofh stunnel-4.20]# stunnel /etc/stunnel/stunnel.conf
> 2007.05.25 10:43:00 LOG7[20728:182894198944]: Snagged 64 random bytes from
> /root/.rnd 2007.05.25 10:43:00 LOG7[20728:182894198944]: Wrote 1024 new
> random bytes to /root/.rnd 2007.05.25 10:43:00 LOG7[20728:182894198944]:
> RAND_status claims sufficient entropy for the PRNG 2007.05.25 10:43:00
> LOG7[20728:182894198944]: PRNG seeded successfully 2007.05.25 10:43:00
> LOG7[20728:182894198944]: Configuration SSL options: 0x00000FFF 2007.05.25
> 10:43:00 LOG7[20728:182894198944]: SSL options set: 0x00000FFF 2007.05.25
> 10:43:00 LOG7[20728:182894198944]: SSL context initialized for service 5140
> [root at bofh stunnel-4.20]# tail -f /var/log/stunnel4/stunnel.log
> 2007.05.25 10:43:00 LOG5[20728:182894198944]: Threading:PTHREAD SSL:ENGINE
> Sockets:POLL,IPv4 Auth:LIBWRAP 2007.05.25 10:43:00
> LOG6[20728:182894198944]: file ulimit = 1024 (can be changed with 'ulimit
> -n') 2007.05.25 10:43:00 LOG6[20728:182894198944]: poll() used - no
> FD_SETSIZE limit for file descriptors 2007.05.25 10:43:00
> LOG5[20728:182894198944]: 500 clients allowed
> 2007.05.25 10:43:00 LOG7[20728:182894198944]: FD 4 in non-blocking mode
> 2007.05.25 10:43:00 LOG7[20728:182894198944]: FD 5 in non-blocking mode
> 2007.05.25 10:43:00 LOG7[20728:182894198944]: FD 6 in non-blocking mode
> 2007.05.25 10:43:00 LOG7[20728:182894198944]: SO_REUSEADDR option set on
> accept socket 2007.05.25 10:43:00 LOG7[20728:182894198944]: 5140 bound to
> 127.0.0.1:5140 2007.05.25 10:43:00 LOG7[20729:182894198944]: Created pid
> file /var/run/stunnel4/stunnel.pid 2007.05.25 10:43:29
> LOG7[20729:182894198944]: 5140 accepted FD=7 from 127.0.0.1:64820
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: 5140 started
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: FD 7 in non-blocking mode
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: TCP_NODELAY option set on local
> socket 2007.05.25 10:43:29 LOG7[20729:1073809760]: FD 8 in non-blocking
> mode 2007.05.25 10:43:29 LOG7[20729:1073809760]: FD 9 in non-blocking mode
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: Connection from 127.0.0.1:64820
> permitted by libwrap 2007.05.25 10:43:29 LOG7[20729:182894198944]: Cleaning
> up the signal pipe 2007.05.25 10:43:29 LOG5[20729:1073809760]: 5140
> accepted connection from 127.0.0.1:64820 2007.05.25 10:43:29
> LOG6[20729:182894198944]: Child process 20748 finished with code 0
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: FD 8 in non-blocking mode
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: 5140 connecting
> xxx.xxx.xxx.xxx:5140 2007.05.25 10:43:29 LOG7[20729:1073809760]:
> connect_wait: waiting 10 seconds 2007.05.25 10:43:29
> LOG7[20729:1073809760]: connect_wait: connected 2007.05.25 10:43:29
> LOG5[20729:1073809760]: 5140 connected remote server from
> 192.168.2.23:64821 2007.05.25 10:43:29 LOG7[20729:1073809760]: Remote FD=8
> initialized 2007.05.25 10:43:29 LOG7[20729:1073809760]: TCP_NODELAY option
> set on remote socket 2007.05.25 10:43:29 LOG7[20729:1073809760]: SSL state
> (connect): before/connect initialization 2007.05.25 10:43:29
> LOG7[20729:1073809760]: SSL state (connect): SSLv3 write client hello A
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: SSL state (connect): SSLv3 read
> server hello A 2007.05.25 10:43:29 LOG7[20729:1073809760]: SSL state
> (connect): SSLv3 read server certificate A 2007.05.25 10:43:29
> LOG7[20729:1073809760]: SSL state (connect): SSLv3 read server done A
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: SSL state (connect): SSLv3
> write client key exchange A 2007.05.25 10:43:29 LOG7[20729:1073809760]: SSL
> state (connect): SSLv3 write change cipher spec A 2007.05.25 10:43:29
> LOG7[20729:1073809760]: SSL state (connect): SSLv3 write finished A
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: SSL state (connect): SSLv3
> flush data 2007.05.25 10:43:29 LOG7[20729:1073809760]: SSL state (connect):
> SSLv3 read finished A 2007.05.25 10:43:29 LOG7[20729:1073809760]:    1
> items in the session cache 2007.05.25 10:43:29 LOG7[20729:1073809760]:    1
> client connects (SSL_connect()) 2007.05.25 10:43:29 LOG7[20729:1073809760]:
>    1 client connects that finished 2007.05.25 10:43:29
> LOG7[20729:1073809760]:    0 client renegotiations requested 2007.05.25
> 10:43:29 LOG7[20729:1073809760]:    0 server connects (SSL_accept())
> 2007.05.25 10:43:29 LOG7[20729:1073809760]:    0 server connects that
> finished 2007.05.25 10:43:29 LOG7[20729:1073809760]:    0 server
> renegotiations requested 2007.05.25 10:43:29 LOG7[20729:1073809760]:    0
> session cache hits 2007.05.25 10:43:29 LOG7[20729:1073809760]:    0 session
> cache misses 2007.05.25 10:43:29 LOG7[20729:1073809760]:    0 session cache
> timeouts 2007.05.25 10:43:29 LOG6[20729:1073809760]: SSL connected: new
> session negotiated 2007.05.25 10:43:29 LOG6[20729:1073809760]: Negotiated
> ciphers: AES256-SHA SSLv3 Kx=RSA Au=RSA Enc=AES(256) Mac=SHA1 2007.05.25
> 10:43:29 LOG7[20729:1073809760]: SSL alert (read): warning: close notify
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: SSL closed on SSL_read
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: Socket write shutdown
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: SSL write shutdown
> 2007.05.25 10:43:29 LOG7[20729:1073809760]: SSL alert (write): warning:
> close notify 2007.05.25 10:43:29 LOG6[20729:1073809760]: SSL_shutdown
> successfully sent close_notify 2007.05.25 10:43:29 LOG5[20729:1073809760]:
> Connection closed: 303 bytes sent to SSL, 0 bytes sent to socket 2007.05.25
> 10:43:29 LOG7[20729:1073809760]: 5140 finished (0 left)
>
>
> /etc/stunnel/stunnel.conf
>
> setuid = stunnel4
> setgid = stunnel4
> pid = /var/run/stunnel4/stunnel.pid
> socket = l:TCP_NODELAY=1
> socket = r:TCP_NODELAY=1
> debug = 7
> output = /var/log/stunnel4/stunnel.log
> [5140]
> client = yes
> options = ALL
> accept = 127.0.0.1:5140
> connect = xxx.xxx.xxx.xxx:5140
>
>
> [root at bofh stunnel-4.20]# tail /var/log/syslog
> May 25 10:57:35 bofh syslog-ng[1926]: EOF occurred while idle; fd='11'
> May 25 10:57:35 bofh syslog-ng[1926]: Connection broken; time_reopen='60'
> May 25 10:58:37 bofh syslog-ng[1926]: EOF occurred while idle; fd='11'
> May 25 10:58:37 bofh syslog-ng[1926]: Connection broken; time_reopen='60'
> May 25 10:59:38 bofh syslog-ng[1926]: EOF occurred while idle; fd='11'
> May 25 10:59:38 bofh syslog-ng[1926]: Connection broken; time_reopen='60'

-- 
......\\|//........^^^^^........)))((........%%%%%........,,,,,......
......(- -)........(o o)........(- o)........(0-0)........(* *)......     
+--ooO-(_)-Ooo--oo0-(_)-0oo--ooO-(_)-Ooo--oo0-(_)-0oo--ooO-(_)-Ooo--+
| F.M. (Mike) Taylor........'Recedite, plebes! Gero rem imperialem!'|
| 'Ecce potestas casei'..............GIAC GSEC & GCFW Certified.....|
| Desk: 4-1872...........................C: 812-841-1876............|
+-------------------------------------------------------------------+