Disconnect reason within client-disconnect scope?

[jfroumis]

I've done quite a bit of hunting in the OpenVPN 2.1 documentation and Google (which indexes this forum) to find out how to get access to the disconnect reason within the "client-disconnect" event scope and haven't really found anything that helps. The "signal" environment variable used to convey this information only gets populated on a "down" event but I need access to this at the time of the client-disconnect. This information appears to be available somewhere when the client disconnects because with the verbosity set to level six, I see this in the OpenVPN log at the time of a client disconnect:

Fri Oct 8 16:33:13 2011 us=657594 <user>@<domain>/<client_ip>:<client_port> SIGUSR1[soft, connection-reset] received, client-instance restarting

Dumping all environment variables from within the client-disconnect shell script as well as programmatically from within the code for the Radius plugin for OpenVPN indicates that the signal variable is not available and neither is anything else that would indicate the cause of the disconnect shown in the log.

So how do I get access to this information at the time of the client-disconnect? Did I completely miss something in the documentation?

I'm using the following version of OpenVPN in case it matters: OpenVPN 2.1_rc11 x86_64-pc-linux-gnu [SSL] [LZ02] [EPOLL] [PKCS11]

Thanks!

[janjust]

hi,

the "client-disconnect" script is called ONLY when the client is considered fully disconnected; this can be achieved by adding

Code: Select all

explicit-exit-notify

to the client config , or it will happen some <timeout> seconds after the last traffic is seen from the client.

The message you are seeing is a client RESTART which does not trigger any scripts in itself. when the client connects again the 'client-connect' and 'learn-address' scripts should/will be called again.

[jfroumis]

Jan,

Thank you for the quick response, I appreciate it!

I think I may not have explained what I need and what I was doing very well.

First, what I need:
On the server side, I need to be able to determine the reason a connection was closed. Specifically, I need to know whether the connection timed out or the user explicitly closed it. This is important because we need to know whether most of our users' connections are being properly shut down or whether there is some other system or network problem that is causing the disconnect. What I REALLY need is for the Radius plugin to OpenVPN to put this into a Radius Stop record as the Acct-Terminate-Cause field, but it appears as if this is not possible without modifying the plugin code as there is no plumbing for this field in the current code. I obviously can't modify the code to set this field, however, if I can't retrieve the disconnect cause at the time of the client-disconnect (which is when the Stop record is created).

What I was doing:
I am using a Linux OpenVPN virtual machine as a client talking to another Linux OpenVPN virtual machine acting as the server. There are two instances of OpenVPN running on the server: one for UDP and one for TCP and both are using the Radius plugin. I have turned the OpenVPN logging verbosity up to 6 on the server. I realize that I need to use the explicit-exit-notify option with the UDP protocol (and I push it to the client from the server for that configuration), but I have noticed that it was not necessary for TCP. Based on your response, I added it anyway and it didn't seem to make a difference. When I disconnect the client by properly shutting down OpenVPN on the client, I see the relevant disconnect cause in the server log immediately before the client-disconnect logic is run in the Radius plugin and the client-disconnect shell script is run in OpenVPN. Presumably these happen simultaneously or very close to one another.

When the connection times out (e.g. the network cable is pulled), the server's OpenVPN log shows:

Code: Select all

 Tue Oct 11 12:12:06 2011 us=600539 <user>@<domain>/<client_ip>:<client_port> SIGUSR1[soft,ping-restart] received, client-instance restarting 

When the connection stops by gracefully shutting down the OpenVPN client, the server's OpenVPN log shows:

Code: Select all

 Mon Oct 10 16:55:45 2011 us=122944 <user>@<domain>/<client_ip>:<client_port> SIGUSR1[soft,connection-reset] received, client-instance restarting 

So my question is still: How do I get access to these different disconnect causes (ping-restart vs. connection-reset) in the client-disconnect scope? Based on the logging, they appear to be available shortly before the client-disconnect scope, so I hope I can get at them without having to modify code to do so.

Thanks!

[Mimiko]

If you will don't whant to update the OpenVPN sources for your needs and add required feature for you, and the compile into binaries, then you can redirect openvpn log with verb6 to a script that will analyze those lines of discconect and create a stistics file, or do what you whant.

[janjust]

just out of curiosity: when you set

Code: Select all

verb 7

and then pull the cable, do you see any lines like

MULTI: multi_close_instance called

in the server logs? if so, then that suggests that the client_disconnect should/could be called at some point, but I have to verify whether this is true....

[jfroumis]

Thanks for the suggestion Mimiko.

I'm not opposed to modifying the code and giving something back to the community, but I guess I am a little surprised that nobody else has needed this before. I don't think I understand the structure of the OpenVPN code well enough yet to know whether this is something that truly requires a code change and that is why I am consulting the experts here first.

I did briefly think about parsing the log file for the necessary information, but with a substantial user base and some of the other things I have been seeing in the logs (such as 60+ IPv6 errors from Windows 7 clients upon each new connection), it would get prohibitively slow to keep parsing a quickly and constantly growing log file. Plus I suspect that with that level of verbosity, the log file(s) would fill up the host storage volume...

[jfroumis]

Jan- Yes, when I set the verbosity to 7 I see DO see the following line in the log file:

Code: Select all

MULTI: multi_close_instance called 

Please let me know how this helps. Thanks for your continued assistance.

[Mimiko]

such as 60+ IPv6 errors from Windows 7 clients

This errors are removed, removing ipv6 protocol from tun adapter.

Plus I suspect that with that level of verbosity, the log file(s) would fill up the host storage volume

The OpenVPN will not write to log, it will pipe the logs to your script, your script will regexp analize thos outputs and discard unnecesarry lines, writting to file only thouse you need.

[janjust]

aha, just tried to replicate it :

I'm using a very simple 'client-disconnect' script:

Code: Select all

#!/bin/bash
env

which DOES get called when the client connection hits a 'ping-restart':

openvpnclient2/172.30.0.128:1028 [openvpnclient2] Inactivity timeout (--ping-restart), restarting
...
script_type=client-disconnect
...
config=tun-udp-server.conf
...
X509_0_CN=openvpnclient2

so the 'signal' env var does not seem to be set, but the script *IS* called... perhaps you can use this to your advantage.

[jfroumis]

Adding the following two lines to the block of code in the function multi_client_disconnect_script (in multi.c) where the script_type is set to "client-disconnect" seems to have done the trick:

Code: Select all

const char* signal_string = signal_description (mi->context.sig->signal_received, mi->context.sig->signal_text);
setenv_str (mi->context.c2.es, "signal", signal_string);

[Mimiko]

So you pathced the code.