OpenVPN stopped working - willing to pay for support

rkagerer

I've had OpenVPN set up between our main office and several remote sites (all running DD-WRT routers) and it's worked like a charm for over two years. Recently it stopped working and I'm having trouble isolating the cause.

It seems the client can connect to the server, but after an hour or two loses connection, at which point both the server and client need to be rebooted.

I'm seeing "Connection refused (code=146)" and "Authenticate/Decrypt packet error: bad packet ID (may be a replay): [ #342 ]" errors on the server.

I didn't see any error messages on the client.

I'll follow this post up with log files from both the server and client, which cover a period when one of these disconnect events occurred. I''' also include the startup scripts from both routers.

I'm running in UDP mode. If switching to TCP mode might help the issue I can investigate it, but I'm concerned it might break some of the legacy equipment (e.g. IP phones) which we have attached to the routers.

Help would be GREATLY appreciated as this stuff is a little over my head.

rkagerer

Here are the configuration scripts I promised in the previous post. I've tried to redact sensitive information.

SERVER STARTUP SCRIPT:

cd /tmp
openvpn --mktun --dev tap0
brctl addif br0 tap0
ifconfig tap0 0.0.0.0 promisc up

echo "
# Tunnel options
mode server       # Set OpenVPN major mode
proto udp         # Setup the protocol (server)
port 1194         # TCP/UDP port number
dev tap0          # TUN/TAP virtual network device
keepalive 15 60   # Simplify the expression of --ping 
daemon            # Become a daemon after all initialization
verb 3            # Set output verbosity to n 
comp-lzo          # Use fast LZO compression 

# OpenVPN server mode options
client-to-client  # tells OpenVPN to internally route client-to-client traffic 
duplicate-cn      # Allow multiple clients with the same common name
status /tmp/vpn.status # Output a short status file every minute
log /tmp/openvpn.log  # For debugging

# TLS Mode Options
tls-server        # Enable TLS and assume server role during TLS handshake 
ca ca.crt         # Certificate authority (CA) file
dh dh1024.pem     # File containing Diffie Hellman parameters 
cert server.crt   # Local peer's signed certificate
key server.key    # Local peer's private key 
crl-verify /tmp/crl.pem   # Revoke list (contains jeffoulahen.crt)
" > openvpn.conf

echo "
-----BEGIN CERTIFICATE-----
MIIDSzCCPqCgAwIBAgIJAII278FpJS7kMA0GCSqGSIb3DQEBBAUAMHExCzAJBgNV
...redacted...
tPOauDtpR+TweLA=
-----END CERTIFICATE-----
" > ca.crt
echo "
-----BEGIN RSA PRIVATE KEY-----
MIICXEIDAAKBgQCjfgQ4nsxUIuE0a0bXtv2RFH/jjfnTBaUTE3usFrtu7cX5PLhh
...redacted...
sBaOPJS0QJ/pHB9Xk3tg6LXTuPiHnwWqICLJ9h/YbZTA
-----END RSA PRIVATE KEY-----
" > server.key
chmod 600 server.key
echo "
-----BEGIN CERTIFICATE-----
MIIDYzCWAgygAwIBAgIBATANBgkqhkiG9w0BAQQFADBxMQswCQYDVQQGEwJDQTEL
...redacted...
9g7qIu6G0g==
-----END CERTIFICATE-----
" > server.crt
echo "
-----BEGIN DH PARAMETERS-----
MIGHKoGBAwlHo...redacted...2uQBkhbAgEC
-----END DH PARAMETERS-----
" > dh1024.pem
echo "
-----BEGIN X509 CRL-----
MIIBODCBsjAN...redacted...fuFrRYqsFUUhHKc8GBazz7w2EFU5PLb6skGjZ+CdFgP+W6jBDjgnFJAQMgtz7u21
-----END X509 CRL-----
" > crl.pem

sleep 5
ln -s /usr/sbin/openvpn /tmp/myvpn
/tmp/myvpn --config openvpn.conf

# Expose public IP for WebVM and forward ports
ifconfig vlan2:1 209.###.###.42 netmask 255.255.255.248 broadcast 209.###.###.47
iptables -t nat -I PREROUTING -p all -d 209.###.###.42 -j DNAT --to-destination 192.168.0.8
iptables -t nat -I POSTROUTING -p all -s 192.168.0.8 -j SNAT --to-source 209.###.###.42
iptables -I FORWARD -p tcp -d 192.168.0.8 --dport 80 -j ACCEPT
iptables -I FORWARD -p tcp -d 192.168.0.8 --dport 3389 -j ACCEPT
iptables -I FORWARD -p tcp -d 192.168.0.8 --dport 21 -j ACCEPT

# The above chunk to expose public IP sometimes stops working.  The chunks below
# are to re-run the commands periodically to keep the website working.

# Set up shell script that will be run every 20 mins
echo "
ifconfig vlan2:1 209.###.###.42 netmask 255.255.255.248 broadcast 209.###.###.47
iptables -t nat -I PREROUTING -p all -d 209.###.###.42 -j DNAT --to-destination 192.168.0.8
iptables -t nat -I POSTROUTING -p all -s 192.168.0.8 -j SNAT --to-source 209.###.###.42
iptables -I FORWARD -p tcp -d 192.168.0.8 --dport 80 -j ACCEPT
iptables -I FORWARD -p tcp -d 192.168.0.8 --dport 3389 -j ACCEPT
iptables -I FORWARD -p tcp -d 192.168.0.8 --dport 21 -j ACCEPT
/bin/date > /tmp/hourly.lastrun
" > /tmp/hourly.sh

# Make the script executable for all users
chmod a+x /tmp/hourly.sh

# Set up crontab file
/bin/sh -c 'echo "# minute (0-59)," >> /tmp/crontab'
/bin/sh -c 'echo "# |      hour (0-23)," >> /tmp/crontab'
/bin/sh -c 'echo "# |      |       day of the month (1-31)," >> /tmp/crontab'
/bin/sh -c 'echo "# |      |       |       month of the year (1-12)," >> /tmp/crontab'
/bin/sh -c 'echo "# |      |       |       |       day of the week (0-6 with 0=Sunday)." >> /tmp/crontab'
/bin/sh -c 'echo "# |      |       |       |       |       commands" >> /tmp/crontab'

# Set up cron job to run above shell script every 20 minutes
echo '  */20   *       *       *       *       root /tmp/hourly.sh' >> /tmp/crontab

SERVER FIREWALL SCRIPT:

cd /usr/sbin
iptables -I INPUT -p udp --dport 1194 -j ACCEPT

# Expose public IP for WebVM and forward ports
ifconfig vlan2:1 209.###.###.42 netmask 255.255.255.248 broadcast 209.###.###.47
iptables -t nat -I PREROUTING -p all -d 209.###.###.42 -j DNAT --to-destination 192.168.0.8
iptables -t nat -I POSTROUTING -p all -s 192.168.0.8 -j SNAT --to-source 209.###.###.42
iptables -I FORWARD -p tcp -d 192.168.0.8 --dport 80 -j ACCEPT
iptables -I FORWARD -p tcp -d 192.168.0.8 --dport 3389 -j ACCEPT
iptables -I FORWARD -p tcp -d 192.168.0.8 --dport 21 -j ACCEPT

CLIENT STARTUP SCRIPT:

#RICHARDHOME
cd /tmp
mkdir openvpn
ln -s /usr/sbin/openvpn /tmp/myvpn
./myvpn --mktun --dev tap1
brctl addif br0 tap1
ifconfig tap1 0.0.0.0 promisc up
sleep 5
echo "
tls-client
dev tap1
proto udp
remote office.redacted.com 1194
resolv-retry infinite
nobind
persist-key
persist-tun
ca /tmp/openvpn/myca.crt
cert /tmp/openvpn/myclient.crt
key /tmp/openvpn/myclient.key
ns-cert-type server
comp-lzo
verb 3
daemon
log /tmp/openvpn/openvpn.log #for testing only
status /tmp/vpn.status
# management localhost 1195 #doesn't work
" > /tmp/openvpn/myvpn.conf
echo "
-----BEGIN CERTIFICATE-----
MIIDNzCCAqCgAwIBAgIJAII278FpJS7kMA0GCSqGSIb3DQEBBAUAMHExCzAJBgNV
...redacted...
ChJC/f4qVmcDSz+T20ktopYYl8XekS6XAkCTaqF3CyDdjItStTWMQ49g1r3rRzFZ
tPOauDtpR+TweLA=
-----END CERTIFICATE-----
" > /tmp/openvpn/myca.crt
echo "
-----BEGIN CERTIFICATE-----
MIIDWDCCAsGgAwIBAgIBBDANBgkqhkiG9w0BAQQFADBxMQswCQYDVQQGEwJDQTEL
...redacted...
RCGA2L7XkHn/Si0xMtuFXSmhFJKw4/oxw/Gh+ncHoEbLb7z8o2OiJPfRLLY=
-----END CERTIFICATE-----
" > /tmp/openvpn/myclient.crt 
echo "
-----BEGIN RSA PRIVATE KEY-----
MIICXAIBAAKBgQCvHEFL4OLJwC+Bx3P0dQ2DNt8BDSVKkiLGA7tY+kCZZPVeXRrx
...redacted...
aAELGUW7ykCYmJwwEM3sF2RDz1ORNMEmMjyMEONLxJU=
-----END RSA PRIVATE KEY-----
" > /tmp/openvpn/myclient.key
chmod 600 /tmp/openvpn/myclient.key
./myvpn --config /tmp/openvpn/myvpn.conf

rkagerer

SERVER LOG:

Here's a log file from the server. I had to truncate it to fit in the maximum 60,000 characters.

Tue Jul  5 18:26:36 2011 OpenVPN 2.1_rc20 mipsel-unknown-linux-gnu [SSL] [LZO2] [EPOLL] built on Nov 23 2009
Tue Jul  5 18:26:36 2011 Diffie-Hellman initialized with 1024 bit key
Tue Jul  5 18:26:36 2011 TLS-Auth MTU parms [ L:1574 D:138 EF:38 EB:0 ET:0 EL:0 ]
Tue Jul  5 18:26:36 2011 TUN/TAP device tap0 opened
Tue Jul  5 18:26:36 2011 TUN/TAP TX queue length set to 100
Tue Jul  5 18:26:36 2011 Data Channel MTU parms [ L:1574 D:1450 EF:42 EB:135 ET:32 EL:0 AF:3/1 ]
Tue Jul  5 18:26:36 2011 Socket Buffers: R=[114688->131072] S=[114688->131072]
Tue Jul  5 18:26:36 2011 UDPv4 link local (bound): [undef]:1194
Tue Jul  5 18:26:36 2011 UDPv4 link remote: [undef]
Tue Jul  5 18:26:36 2011 MULTI: multi_init called, r=256 v=256
Tue Jul  5 18:26:36 2011 Initialization Sequence Completed
Tue Jul  5 18:26:38 2011 MULTI: multi_create_instance called
Tue Jul  5 18:26:38 2011 99.226.###.14:49903 Re-using SSL/TLS context
Tue Jul  5 18:26:38 2011 99.226.###.14:49903 LZO compression initialized
Tue Jul  5 18:26:38 2011 99.226.###.14:49903 Control Channel MTU parms [ L:1574 D:138 EF:38 EB:0 ET:0 EL:0 ]
Tue Jul  5 18:26:38 2011 99.226.###.14:49903 Data Channel MTU parms [ L:1574 D:1450 EF:42 EB:135 ET:32 EL:0 AF:3/1 ]
Tue Jul  5 18:26:38 2011 99.226.###.14:49903 TLS: Initial packet from 99.226.###.14:49903, sid=cda0301d 323fd034
Tue Jul  5 18:26:39 2011 99.226.###.14:49903 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 18:26:39 2011 99.226.###.14:49903 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 18:26:39 2011 99.226.###.14:49903 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 18:26:39 2011 99.226.###.14:49903 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 18:26:39 2011 99.226.###.14:49903 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 18:26:39 2011 99.226.###.14:49903 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 18:26:39 2011 99.226.###.14:49903 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 18:26:39 2011 99.226.###.14:49903 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 18:26:39 2011 99.226.###.14:49903 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 18:26:39 2011 99.226.###.14:49903 [Paul_redacted] Peer Connection Initiated with 99.226.###.14:49903
Tue Jul  5 18:26:39 2011 Paul_redacted/99.226.###.14:49903 MULTI: no dynamic or static remote --ifconfig address is available for Paul_redacted/99.226.###.14:49903
Tue Jul  5 18:26:40 2011 Paul_redacted/99.226.###.14:49903 PUSH: Received control message: 'PUSH_REQUEST'
Tue Jul  5 18:26:40 2011 Paul_redacted/99.226.###.14:49903 SENT CONTROL [Paul_redacted]: 'PUSH_REPLY,ping 15,ping-restart 60' (status=1)
Tue Jul  5 18:27:32 2011 Paul_redacted/99.226.###.14:49903 MULTI: Learn: 00:ff:8f:41:7e:a5 -> Paul_redacted/99.226.###.14:49903
Tue Jul  5 18:35:42 2011 MULTI: multi_create_instance called
Tue Jul  5 18:35:42 2011 99.239.###.203:2050 Re-using SSL/TLS context
Tue Jul  5 18:35:42 2011 99.239.###.203:2050 LZO compression initialized
Tue Jul  5 18:35:42 2011 99.239.###.203:2050 Control Channel MTU parms [ L:1574 D:138 EF:38 EB:0 ET:0 EL:0 ]
Tue Jul  5 18:35:42 2011 99.239.###.203:2050 Data Channel MTU parms [ L:1574 D:1450 EF:42 EB:135 ET:32 EL:0 AF:3/1 ]
Tue Jul  5 18:35:42 2011 99.239.###.203:2050 TLS: Initial packet from 99.239.###.203:2050, sid=3da7569b c0a725ac
Tue Jul  5 18:35:42 2011 99.239.###.203:2050 TLS Error: local/remote TLS keys are out of sync: 99.239.###.203:2050 [1]
Tue Jul  5 18:35:42 2011 99.239.###.203:2050 TLS Error: local/remote TLS keys are out of sync: 99.239.###.203:2050 [1]
Tue Jul  5 18:35:44 2011 99.239.###.203:2050 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 18:35:44 2011 99.239.###.203:2050 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 18:35:44 2011 99.239.###.203:2050 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Cottage_1/emailAddress=jeff@redacted.com
Tue Jul  5 18:35:44 2011 99.239.###.203:2050 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Cottage_1/emailAddress=jeff@redacted.com
Tue Jul  5 18:35:44 2011 99.239.###.203:2050 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 18:35:44 2011 99.239.###.203:2050 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 18:35:44 2011 99.239.###.203:2050 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 18:35:44 2011 99.239.###.203:2050 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 18:35:44 2011 99.239.###.203:2050 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 18:35:44 2011 99.239.###.203:2050 [Cottage_1] Peer Connection Initiated with 99.239.###.203:2050
Tue Jul  5 18:35:44 2011 Cottage_1/99.239.###.203:2050 MULTI: no dynamic or static remote --ifconfig address is available for Cottage_1/99.239.###.203:2050
Tue Jul  5 18:35:44 2011 MULTI: multi_create_instance called
Tue Jul  5 18:35:44 2011 99.226.###.14:2049 Re-using SSL/TLS context
Tue Jul  5 18:35:44 2011 99.226.###.14:2049 LZO compression initialized
Tue Jul  5 18:35:44 2011 99.226.###.14:2049 Control Channel MTU parms [ L:1574 D:138 EF:38 EB:0 ET:0 EL:0 ]
Tue Jul  5 18:35:44 2011 99.226.###.14:2049 Data Channel MTU parms [ L:1574 D:1450 EF:42 EB:135 ET:32 EL:0 AF:3/1 ]
Tue Jul  5 18:35:44 2011 99.226.###.14:2049 TLS: Initial packet from 99.226.###.14:2049, sid=e5b45edb 96ddd7db
Tue Jul  5 18:35:44 2011 Cottage_1/99.239.###.203:2050 MULTI: Learn: 00:ff:f1:08:a9:41 -> Cottage_1/99.239.###.203:2050
Tue Jul  5 18:35:45 2011 99.226.###.14:2049 TLS Error: local/remote TLS keys are out of sync: 99.226.###.14:2049 [1]
Tue Jul  5 18:35:45 2011 99.226.###.14:2049 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 18:35:45 2011 99.226.###.14:2049 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 18:35:45 2011 99.226.###.14:2049 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 18:35:45 2011 99.226.###.14:2049 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 18:35:45 2011 99.226.###.14:2049 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 18:35:45 2011 99.226.###.14:2049 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 18:35:45 2011 99.226.###.14:2049 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 18:35:45 2011 99.226.###.14:2049 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 18:35:45 2011 99.226.###.14:2049 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 18:35:45 2011 99.226.###.14:2049 [Paul_redacted] Peer Connection Initiated with 99.226.###.14:2049
Tue Jul  5 18:35:45 2011 Paul_redacted/99.226.###.14:2049 MULTI: no dynamic or static remote --ifconfig address is available for Paul_redacted/99.226.###.14:2049
Tue Jul  5 18:35:46 2011 Paul_redacted/99.226.###.14:2049 MULTI: Learn: 00:ff:7c:f4:c2:ec -> Paul_redacted/99.226.###.14:2049
Tue Jul  5 18:35:52 2011 Cottage_1/99.239.###.203:2050 MULTI: Learn: 00:09:97:29:3a:e1 -> Cottage_1/99.239.###.203:2050
Tue Jul  5 18:35:53 2011 Cottage_1/99.239.###.203:2050 MULTI: Learn: 00:0a:e4:0b:53:88 -> Cottage_1/99.239.###.203:2050
Tue Jul  5 18:35:58 2011 Cottage_1/99.239.###.203:2050 MULTI: Learn: 00:0a:e4:05:12:e2 -> Cottage_1/99.239.###.203:2050
Tue Jul  5 18:36:10 2011 Cottage_1/99.239.###.203:2050 MULTI: Learn: 00:0a:e4:05:14:3f -> Cottage_1/99.239.###.203:2050
Tue Jul  5 18:36:14 2011 Paul_redacted/99.226.###.14:2049 MULTI: Learn: 00:17:65:fe:16:17 -> Paul_redacted/99.226.###.14:2049
Tue Jul  5 18:36:19 2011 Paul_redacted/99.226.###.14:2049 MULTI: Learn: 00:17:65:fe:15:3b -> Paul_redacted/99.226.###.14:2049
Tue Jul  5 19:26:20 2011 MULTI: multi_create_instance called
Tue Jul  5 19:26:20 2011 24.246.###.56:2049 Re-using SSL/TLS context
Tue Jul  5 19:26:20 2011 24.246.###.56:2049 LZO compression initialized
Tue Jul  5 19:26:20 2011 24.246.###.56:2049 Control Channel MTU parms [ L:1574 D:138 EF:38 EB:0 ET:0 EL:0 ]
Tue Jul  5 19:26:20 2011 24.246.###.56:2049 Data Channel MTU parms [ L:1574 D:1450 EF:42 EB:135 ET:32 EL:0 AF:3/1 ]
Tue Jul  5 19:26:20 2011 24.246.###.56:2049 TLS: Initial packet from 24.246.###.56:2049, sid=f3e41f92 35c93d9d
Tue Jul  5 19:26:21 2011 24.246.###.56:2049 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 19:26:21 2011 24.246.###.56:2049 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 19:26:21 2011 24.246.###.56:2049 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Richard_redacted/emailAddress=richardk@leapbeyond.com
Tue Jul  5 19:26:21 2011 24.246.###.56:2049 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Richard_redacted/emailAddress=richardk@leapbeyond.com
Tue Jul  5 19:26:22 2011 24.246.###.56:2049 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 19:26:22 2011 24.246.###.56:2049 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 19:26:22 2011 24.246.###.56:2049 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 19:26:22 2011 24.246.###.56:2049 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 19:26:22 2011 24.246.###.56:2049 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 19:26:22 2011 24.246.###.56:2049 [Richard_redacted] Peer Connection Initiated with 24.246.###.56:2049
Tue Jul  5 19:26:22 2011 Richard_redacted/24.246.###.56:2049 MULTI: no dynamic or static remote --ifconfig address is available for Richard_redacted/24.246.###.56:2049
Tue Jul  5 19:26:22 2011 Richard_redacted/24.246.###.56:2049 MULTI: Learn: 00:ff:0d:6a:28:0e -> Richard_redacted/24.246.###.56:2049
Tue Jul  5 19:26:39 2011 Paul_redacted/99.226.###.14:49903 TLS: soft reset sec=0 bytes=3253041/0 pkts=27708/0
Tue Jul  5 19:26:39 2011 Paul_redacted/99.226.###.14:49903 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 19:26:39 2011 Paul_redacted/99.226.###.14:49903 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 19:26:39 2011 Paul_redacted/99.226.###.14:49903 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 19:26:39 2011 Paul_redacted/99.226.###.14:49903 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 19:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 19:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 19:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 19:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 19:26:39 2011 Paul_redacted/99.226.###.14:49903 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 19:27:14 2011 Richard_redacted/24.246.###.56:2049 MULTI: Learn: 00:0a:e4:05:14:4a -> Richard_redacted/24.246.###.56:2049
Tue Jul  5 19:35:44 2011 Cottage_1/99.239.###.203:2050 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 19:35:44 2011 Cottage_1/99.239.###.203:2050 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 19:35:44 2011 Cottage_1/99.239.###.203:2050 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Cottage_1/emailAddress=jeff@redacted.com
Tue Jul  5 19:35:44 2011 Cottage_1/99.239.###.203:2050 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Cottage_1/emailAddress=jeff@redacted.com
Tue Jul  5 19:35:44 2011 Cottage_1/99.239.###.203:2050 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 19:35:44 2011 Cottage_1/99.239.###.203:2050 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 19:35:44 2011 Cottage_1/99.239.###.203:2050 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 19:35:44 2011 Cottage_1/99.239.###.203:2050 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 19:35:44 2011 Cottage_1/99.239.###.203:2050 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 19:35:45 2011 Paul_redacted/99.226.###.14:2049 TLS: soft reset sec=0 bytes=3964374/0 pkts=35456/0
Tue Jul  5 19:35:46 2011 Paul_redacted/99.226.###.14:2049 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 19:35:46 2011 Paul_redacted/99.226.###.14:2049 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 19:35:46 2011 Paul_redacted/99.226.###.14:2049 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 19:35:46 2011 Paul_redacted/99.226.###.14:2049 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 19:35:46 2011 Paul_redacted/99.226.###.14:2049 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 19:35:46 2011 Paul_redacted/99.226.###.14:2049 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 19:35:46 2011 Paul_redacted/99.226.###.14:2049 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 19:35:46 2011 Paul_redacted/99.226.###.14:2049 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 19:35:46 2011 Paul_redacted/99.226.###.14:2049 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 19:44:52 2011 Richard_redacted/24.246.###.56:2049 MULTI: Learn: fe:fe:ff:7e:ff:7e -> Richard_redacted/24.246.###.56:2049
Tue Jul  5 19:44:52 2011 Richard_redacted/24.246.###.56:2049 MULTI: Learn: 00:00:80:11:51:2b -> Richard_redacted/24.246.###.56:2049
Tue Jul  5 19:51:07 2011 Richard_redacted/24.246.###.56:2049 Replay-window backtrack occurred [1]
Tue Jul  5 19:56:17 2011 Richard_redacted/24.246.###.56:2049 Replay-window backtrack occurred [5]
Tue Jul  5 19:56:18 2011 Richard_redacted/24.246.###.56:2049 Replay-window backtrack occurred [6]
Tue Jul  5 19:56:19 2011 Richard_redacted/24.246.###.56:2049 Replay-window backtrack occurred [7]
Tue Jul  5 20:23:48 2011 Richard_redacted/24.246.###.56:2049 Replay-window backtrack occurred [17]
Tue Jul  5 20:23:50 2011 Richard_redacted/24.246.###.56:2049 Replay-window backtrack occurred [21]
Tue Jul  5 20:26:22 2011 Richard_redacted/24.246.###.56:2049 TLS: soft reset sec=0 bytes=12631210/0 pkts=64992/0
Tue Jul  5 20:26:23 2011 Richard_redacted/24.246.###.56:2049 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 20:26:23 2011 Richard_redacted/24.246.###.56:2049 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 20:26:23 2011 Richard_redacted/24.246.###.56:2049 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Richard_redacted/emailAddress=richardk@leapbeyond.com
Tue Jul  5 20:26:23 2011 Richard_redacted/24.246.###.56:2049 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Richard_redacted/emailAddress=richardk@leapbeyond.com
Tue Jul  5 20:26:23 2011 Richard_redacted/24.246.###.56:2049 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 20:26:23 2011 Richard_redacted/24.246.###.56:2049 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 20:26:23 2011 Richard_redacted/24.246.###.56:2049 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 20:26:23 2011 Richard_redacted/24.246.###.56:2049 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 20:26:23 2011 Richard_redacted/24.246.###.56:2049 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 20:26:39 2011 Paul_redacted/99.226.###.14:49903 TLS: soft reset sec=0 bytes=3897569/0 pkts=35703/0
Tue Jul  5 20:26:39 2011 Paul_redacted/99.226.###.14:49903 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 20:26:39 2011 Paul_redacted/99.226.###.14:49903 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 20:26:39 2011 Paul_redacted/99.226.###.14:49903 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 20:26:39 2011 Paul_redacted/99.226.###.14:49903 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 20:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 20:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 20:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 20:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 20:26:39 2011 Paul_redacted/99.226.###.14:49903 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 20:35:43 2011 Cottage_1/99.239.###.203:2050 TLS: tls_process: killed expiring key
Tue Jul  5 20:35:44 2011 Cottage_1/99.239.###.203:2050 TLS: soft reset sec=0 bytes=4456712/0 pkts=41538/0
Tue Jul  5 20:35:45 2011 Paul_redacted/99.226.###.14:2049 TLS: tls_process: killed expiring key
Tue Jul  5 20:35:45 2011 Cottage_1/99.239.###.203:2050 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 20:35:45 2011 Cottage_1/99.239.###.203:2050 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 20:35:45 2011 Cottage_1/99.239.###.203:2050 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Cottage_1/emailAddress=jeff@redacted.com
Tue Jul  5 20:35:45 2011 Cottage_1/99.239.###.203:2050 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Cottage_1/emailAddress=jeff@redacted.com
Tue Jul  5 20:35:45 2011 Cottage_1/99.239.###.203:2050 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 20:35:45 2011 Cottage_1/99.239.###.203:2050 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 20:35:45 2011 Cottage_1/99.239.###.203:2050 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 20:35:45 2011 Cottage_1/99.239.###.203:2050 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 20:35:45 2011 Cottage_1/99.239.###.203:2050 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 20:35:46 2011 Paul_redacted/99.226.###.14:2049 TLS: soft reset sec=0 bytes=4227910/0 pkts=39303/0
Tue Jul  5 20:35:47 2011 Paul_redacted/99.226.###.14:2049 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 20:35:47 2011 Paul_redacted/99.226.###.14:2049 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 20:35:47 2011 Paul_redacted/99.226.###.14:2049 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 20:35:47 2011 Paul_redacted/99.226.###.14:2049 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 20:35:47 2011 Paul_redacted/99.226.###.14:2049 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 20:35:47 2011 Paul_redacted/99.226.###.14:2049 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 20:35:47 2011 Paul_redacted/99.226.###.14:2049 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 20:35:47 2011 Paul_redacted/99.226.###.14:2049 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 20:35:47 2011 Paul_redacted/99.226.###.14:2049 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 21:26:22 2011 Richard_redacted/24.246.###.56:2049 TLS: tls_process: killed expiring key
Tue Jul  5 21:26:23 2011 Richard_redacted/24.246.###.56:2049 TLS: soft reset sec=0 bytes=3843348/0 pkts=35615/0
Tue Jul  5 21:26:24 2011 Richard_redacted/24.246.###.56:2049 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 21:26:24 2011 Richard_redacted/24.246.###.56:2049 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 21:26:24 2011 Richard_redacted/24.246.###.56:2049 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Richard_redacted/emailAddress=richardk@leapbeyond.com
Tue Jul  5 21:26:24 2011 Richard_redacted/24.246.###.56:2049 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Richard_redacted/emailAddress=richardk@leapbeyond.com
Tue Jul  5 21:26:24 2011 Richard_redacted/24.246.###.56:2049 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 21:26:24 2011 Richard_redacted/24.246.###.56:2049 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 21:26:24 2011 Richard_redacted/24.246.###.56:2049 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 21:26:24 2011 Richard_redacted/24.246.###.56:2049 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 21:26:24 2011 Richard_redacted/24.246.###.56:2049 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 21:26:39 2011 Paul_redacted/99.226.###.14:49903 TLS: soft reset sec=0 bytes=3691464/0 pkts=33823/0
Tue Jul  5 21:26:39 2011 Paul_redacted/99.226.###.14:49903 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 21:26:39 2011 Paul_redacted/99.226.###.14:49903 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 21:26:39 2011 Paul_redacted/99.226.###.14:49903 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 21:26:39 2011 Paul_redacted/99.226.###.14:49903 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 21:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 21:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 21:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 21:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 21:26:39 2011 Paul_redacted/99.226.###.14:49903 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 21:35:44 2011 Cottage_1/99.239.###.203:2050 TLS: tls_process: killed expiring key
Tue Jul  5 21:35:45 2011 Cottage_1/99.239.###.203:2050 TLS: soft reset sec=0 bytes=4303655/0 pkts=40170/0
Tue Jul  5 21:35:46 2011 Paul_redacted/99.226.###.14:2049 TLS: tls_process: killed expiring key
Tue Jul  5 21:35:46 2011 Cottage_1/99.239.###.203:2050 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 21:35:46 2011 Cottage_1/99.239.###.203:2050 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 21:35:46 2011 Cottage_1/99.239.###.203:2050 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Cottage_1/emailAddress=jeff@redacted.com
Tue Jul  5 21:35:46 2011 Cottage_1/99.239.###.203:2050 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Cottage_1/emailAddress=jeff@redacted.com
Tue Jul  5 21:35:46 2011 Cottage_1/99.239.###.203:2050 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 21:35:46 2011 Cottage_1/99.239.###.203:2050 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 21:35:46 2011 Cottage_1/99.239.###.203:2050 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 21:35:46 2011 Cottage_1/99.239.###.203:2050 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 21:35:46 2011 Cottage_1/99.239.###.203:2050 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 21:35:47 2011 Paul_redacted/99.226.###.14:2049 TLS: soft reset sec=0 bytes=4072998/0 pkts=37903/0
Tue Jul  5 21:35:48 2011 Paul_redacted/99.226.###.14:2049 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 21:35:48 2011 Paul_redacted/99.226.###.14:2049 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 21:35:48 2011 Paul_redacted/99.226.###.14:2049 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 21:35:48 2011 Paul_redacted/99.226.###.14:2049 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 21:35:48 2011 Paul_redacted/99.226.###.14:2049 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 21:35:48 2011 Paul_redacted/99.226.###.14:2049 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 21:35:48 2011 Paul_redacted/99.226.###.14:2049 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 21:35:48 2011 Paul_redacted/99.226.###.14:2049 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 21:35:48 2011 Paul_redacted/99.226.###.14:2049 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 22:16:18 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:19 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:19 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:19 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:19 2011 read UDPv4 [ECONNREFUSED|ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:19 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:21 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:22 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:23 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:24 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:25 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:26 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:27 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:28 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:29 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:30 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:31 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:32 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:33 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:34 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:35 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:36 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:37 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:37 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:39 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:40 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:41 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:42 2011 Richard_redacted/24.246.###.56:2049 write UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:43 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:44 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:45 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:45 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:46 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:48 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:49 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:50 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:50 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:52 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:53 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:53 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:54 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:56 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:57 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:57 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:59 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:16:59 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:01 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:02 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:02 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:04 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:05 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:06 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:06 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:07 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:09 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:10 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:11 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:12 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:12 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:14 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:14 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:16 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:17 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:18 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:19 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:19 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:21 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:22 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:22 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:24 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:25 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:26 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:27 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:28 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:29 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:29 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:30 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:32 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:33 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:33 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:34 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:35 2011 Cottage_1/99.239.###.203:2050 write UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:37 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:38 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:39 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:39 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:41 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:41 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:42 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:43 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:45 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:45 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:46 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:47 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:49 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:50 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:51 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:52 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:53 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:54 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:55 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:56 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:57 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:57 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:59 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:17:59 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:01 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:02 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:03 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:04 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:05 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:06 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:06 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:07 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:09 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:10 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:11 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:12 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:13 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:14 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:15 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:16 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:16 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:18:18 2011 Richard_redacted/24.246.###.56:2049 [Richard_redacted] Inactivity timeout (--ping-restart), restarting
Tue Jul  5 22:18:18 2011 Richard_redacted/24.246.###.56:2049 SIGUSR1[soft,ping-restart] received, client-instance restarting
Tue Jul  5 22:18:18 2011 read UDPv4 [ECONNREFUSED]: Connection refused (code=146)
Tue Jul  5 22:26:39 2011 Paul_redacted/99.226.###.14:49903 TLS: soft reset sec=0 bytes=3684646/0 pkts=33533/0
Tue Jul  5 22:26:39 2011 Paul_redacted/99.226.###.14:49903 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 22:26:39 2011 Paul_redacted/99.226.###.14:49903 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 22:26:39 2011 Paul_redacted/99.226.###.14:49903 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 22:26:39 2011 Paul_redacted/99.226.###.14:49903 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Paul_redacted/emailAddress=paul@redacted.com
Tue Jul  5 22:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 22:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 22:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 22:26:39 2011 Paul_redacted/99.226.###.14:49903 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 22:26:39 2011 Paul_redacted/99.226.###.14:49903 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Tue Jul  5 22:35:45 2011 Cottage_1/99.239.###.203:2050 TLS: tls_process: killed expiring key
Tue Jul  5 22:35:46 2011 Cottage_1/99.239.###.203:2050 TLS: soft reset sec=0 bytes=4292747/0 pkts=39543/0
Tue Jul  5 22:35:47 2011 Paul_redacted/99.226.###.14:2049 TLS: tls_process: killed expiring key
Tue Jul  5 22:35:47 2011 Cottage_1/99.239.###.203:2050 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 22:35:47 2011 Cottage_1/99.239.###.203:2050 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=redacted/CN=redacted/emailAddress=jeff@redacted.com
Tue Jul  5 22:35:47 2011 Cottage_1/99.239.###.203:2050 CRL CHECK OK: /C=CA/ST=ON/O=redacted/CN=Cottage_1/emailAddress=jeff@redacted.com
Tue Jul  5 22:35:47 2011 Cottage_1/99.239.###.203:2050 VERIFY OK: depth=0, /C=CA/ST=ON/O=redacted/CN=Cottage_1/emailAddress=jeff@redacted.com
Tue Jul  5 22:35:47 2011 Cottage_1/99.239.###.203:2050 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 22:35:47 2011 Cottage_1/99.239.###.203:2050 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 22:35:47 2011 Cottage_1/99.239.###.203:2050 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Tue Jul  5 22:35:47 2011 Cottage_1/99.239.###.203:2050 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Tue Jul  5 22:35:47 2011 Cottage_1/99.239.###.203:2050 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA

rkagerer

CLIENT LOG:

A log file sample from the client. Note the time on the client and server are out of sync (sorry).

Wed Jul  6 07:44:54 2011 OpenVPN 2.0.7 mipsel-unknown-linux [SSL] [LZO] [EPOLL] built on Sep 15 2006
Wed Jul  6 07:44:54 2011 IMPORTANT: OpenVPN's default port number is now 1194, based on an official port number assignment by IANA.  OpenVPN 2.0-beta16 and earlier used 5000 as the default port.
Wed Jul  6 07:44:54 2011 LZO compression initialized
Wed Jul  6 07:44:54 2011 Control Channel MTU parms [ L:1574 D:138 EF:38 EB:0 ET:0 EL:0 ]
Wed Jul  6 07:44:54 2011 TUN/TAP device tap1 opened
Wed Jul  6 07:44:54 2011 Data Channel MTU parms [ L:1574 D:1450 EF:42 EB:135 ET:32 EL:0 AF:3/1 ]
Wed Jul  6 07:44:54 2011 UDPv4 link local: [undef]
Wed Jul  6 07:44:54 2011 UDPv4 link remote: 209.###.###.41:1194
Wed Jul  6 07:44:54 2011 TLS: Initial packet from 209.###.###.41:1194, sid=f06f791d f64a6170
Wed Jul  6 07:44:56 2011 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=Oulahen/CN=Oulahen/emailAddress=jeff@oulahen.com
Wed Jul  6 07:44:56 2011 VERIFY OK: nsCertType=SERVER
Wed Jul  6 07:44:56 2011 VERIFY OK: depth=0, /C=CA/ST=ON/O=Oulahen/CN=server/emailAddress=jeff@oulahen.com
Wed Jul  6 07:45:01 2011 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Wed Jul  6 07:45:01 2011 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed Jul  6 07:45:01 2011 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Wed Jul  6 07:45:01 2011 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Wed Jul  6 07:45:01 2011 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
Wed Jul  6 07:45:01 2011 [server] Peer Connection Initiated with 209.###.###.41:1194
Wed Jul  6 07:45:02 2011 Initialization Sequence Completed

rkagerer

Finally, a snapshot of the vpn.status log on the server:

OpenVPN CLIENT LIST
Updated,Wed Jul  6 08:39:36 2011
Common Name,Real Address,Bytes Received,Bytes Sent,Connected Since
Paul_redacted,99.226.###.14:49903,3041127,39937312,Tue Jul  5 18:26:38 2011
Cottage_1,99.239.###.203:2050,11223200,40095256,Tue Jul  5 18:35:42 2011
Richard_redacted,24.246.###.56:2049,300427,468400,Wed Jul  6 08:34:18 2011
ROUTING TABLE
Virtual Address,Common Name,Real Address,Last Ref
00:0a:e4:05:14:4a,Richard_redacted,24.246.###.56:2049,Wed Jul  6 08:39:32 2011
00:0a:e4:0b:53:88,Cottage_1,99.239.###.203:2050,Wed Jul  6 08:39:33 2011
00:ff:f1:08:a9:41,Cottage_1,99.239.###.203:2050,Tue Jul  5 18:35:44 2011
00:0a:e4:05:12:e2,Cottage_1,99.239.###.203:2050,Wed Jul  6 08:39:32 2011
00:09:97:29:3a:e1,Cottage_1,99.239.###.203:2050,Tue Jul  5 18:35:52 2011
00:ff:8f:41:7e:a5,Paul_redacted,99.226.###.14:49903,Wed Jul  6 08:39:23 2011
00:ff:af:7e:d9:ca,Richard_redacted,24.246.###.56:2049,Wed Jul  6 08:34:25 2011
00:0e:7b:6a:db:f1,Richard_redacted,24.246.###.56:2049,Wed Jul  6 08:36:36 2011
00:0c:41:f2:cc:56,Richard_redacted,24.246.###.56:2049,Wed Jul  6 08:36:00 2011
00:0a:e4:05:14:3f,Cottage_1,99.239.###.203:2050,Wed Jul  6 08:39:32 2011
GLOBAL STATS
Max bcast/mcast queue length,4
END

I realize these are a lot of log files. If anyone see's something obvious to try here I'd appreciate the help!

Mimiko

You didn't mention, does this happen only with one client, or all client?

rkagerer

All clients are having connection problems.

I'm not sure if it's the same problem everywhere, but I assume so.

Also, most or all of the clients are using the same ISP. (Mine is using a different ISP but it operates over the same network).

Mimiko

rkagerer wroteAlso, most or all of the clients are using the same ISP. (Mine is using a different ISP but it operates over the same network).

That might be problem. Check internet connection stability on the server. On the problem occurs, check what's downloading or uploading from server. Use speedtest or something at that moment.

Also check for viruses your server. It seems that something is interfering and loads up internet traffic and/or cpu.

Bebop

rkagerer wrote I'm seeing "Connection refused (code=146)" and "Authenticate/Decrypt packet error: bad packet ID (may be a replay): [ #342 ]"

Because its only happening after 2 hours, this is a tricky one for trial and error testing methods.

Have you ruled out MTU issues as a possible cause?

--fragment max and --mssfix max may be worth looking into, although I don't see this as being a good long term solution.

Maybe update the server OpenVPN to a newer release, since yours is a releases cycle edition.

Lastly, I googled your "maybe a replay" issue, and have found this from the archives:

may not be the case for you but i'm pretty sure i've seen this when the
clocks on the two machines are substantially out of sync. i remember
having a similar problem when i first started using openvpn and i recall
discovering that one of my machine's clocks was way off. it's been awhile
but it seems that that's all i had to do.

So that is somewhat a consideration for you too, since you said that "The time on the client and server are out of sync".

And you are getting a lot of TLS Error: local/remote TLS keys are out of sync that may be worth looking into.

Actually, scrap what I said about the clocks being out of sync....

getting closer to the point is: Can you be sure that the clock on your server is not jumping back ever?

See this from the archive: http://openvpn.net/archive/openvpn-users/2005-03/msg00513.html

As a result, switching off replay protection may be a viable solution.

rkagerer

Thanks for those good suggestions.. will follow them up and let you know what happens.

Interestingly, yesterday we replaced the router that was acting as the OpenVPN server, and also disconnected one of the client sites, and it looks like things have been stable overnight. So it might even be a hardware issue. But even if it's working I'll monitor the log files to see if the replay / "keys out of sync" errors are still occurring.

rkagerer

I have some more information. I've confirmed there is one OpenVPN client site that is taking down the server. Let me explain...

We took the router in our main office and "duplicated" it. i.e. Got another router of the exact same hardware model, and set up the same version of DD-WRT with all the exact same settings. OpenVPN was similarly set up with the exact same settings and scripts.

We then put that router on a completely different internet connection (i.e. different ISP). So now we have a second OpenVPN server, on a different IP, set up exactly the same as the original one.

We left all remote sites pointed to the original router, except one suspect site which we changed to point to the public IP of the clone instead.

Now the original router works just fine. However the clone (more specifically, the OpenVPN server on the clone) goes down after a few hours or a day. By "goes down", I mean it stops accepting connections from the client site, stops logging to the log file, etc. It's out cold. We have to restart the OpenVPN service on the server for clients to be able to connect again.

The last thing logged by the service is:

Sat Aug 27 13:46:10 2011 Cottage_1/173.xxx.xxx.193:2048 TLS: tls_process: killed expiring key
Sat Aug 27 13:46:11 2011 Cottage_1/173.xxx.xxx.193:2048 TLS: soft reset sec=0 bytes=102338381/0 pkts=139033/0
Sat Aug 27 13:46:12 2011 Cottage_1/173.xxx.xxx.193:2048 CRL CHECK OK: /C=CA/ST=ON/L=Toronto/O=xxxxxxx/CN=xxxxxxx/emailAddress=jeff@xxxxxxx.com
Sat Aug 27 13:46:12 2011 Cottage_1/173.xxx.xxx.193:2048 VERIFY OK: depth=1, /C=CA/ST=ON/L=Toronto/O=xxxxxxx/CN=xxxxxxx/emailAddress=jeff@xxxxxxx.com
Sat Aug 27 13:46:12 2011 Cottage_1/173.xxx.xxx.193:2048 CRL CHECK OK: /C=CA/ST=ON/O=xxxxxxx/CN=Cottage_1/emailAddress=jeff@xxxxxxx.com
Sat Aug 27 13:46:12 2011 Cottage_1/173.xxx.xxx.193:2048 VERIFY OK: depth=0, /C=CA/ST=ON/O=xxxxxxx/CN=Cottage_1/emailAddress=jeff@oulahen.com
Sat Aug 27 13:46:12 2011 Cottage_1/173.xxx.xxx.193:2048 Data Channel Encrypt: Cipher 'BF-CBC' initialized with 128 bit key
Sat Aug 27 13:46:12 2011 Cottage_1/173.xxx.xxx.193:2048 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Sat Aug 27 13:46:12 2011 Cottage_1/173.xxx.xxx.193:2048 Data Channel Decrypt: Cipher 'BF-CBC' initialized with 128 bit key
Sat Aug 27 13:46:12 2011 Cottage_1/173.xxx.xxx.193:2048 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
Sat Aug 27 13:46:12 2011 Cottage_1/173.xxx.xxx.193:2048 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA

Any ideas?

Mimiko

When this occurs. Try to stop the problem client, and see if OpenVPN is getting to normal.

Increase verbose level of logging.