openvpn/error.c

/*
 *  OpenVPN -- An application to securely tunnel IP networks
 *             over a single TCP/UDP port, with support for SSL/TLS-based
 *             session authentication and key exchange,
 *             packet encryption, packet authentication, and
 *             packet compression.
 *
 *  Copyright (C) 2002-2008 OpenVPN Technologies, Inc. <sales@openvpn.net>
 *
 *  This program is free software; you can redistribute it and/or modify
 *  it under the terms of the GNU General Public License version 2
 *  as published by the Free Software Foundation.
 *
 *  This program is distributed in the hope that it will be useful,
 *  but WITHOUT ANY WARRANTY; without even the implied warranty of
 *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 *  GNU General Public License for more details.
 *
 *  You should have received a copy of the GNU General Public License
 *  along with this program (see the file COPYING included with this
 *  distribution); if not, write to the Free Software Foundation, Inc.,
 *  59 Temple Place, Suite 330, Boston, MA  02111-1307  USA
 */

#include "syshead.h"

#include "error.h"
#include "buffer.h"
#include "thread.h"
#include "misc.h"
#include "win32.h"
#include "socket.h"
#include "tun.h"
#include "otime.h"
#include "perf.h"
#include "status.h"
#include "integer.h"
#include "ps.h"

#ifdef USE_CRYPTO
#include <openssl/err.h>
#endif

#include "memdbg.h"

#if SYSLOG_CAPABILITY
#ifndef LOG_OPENVPN
#define LOG_OPENVPN LOG_DAEMON
#endif
#endif

/* Globals */
unsigned int x_debug_level; /* GLOBAL */

/* Mute state */
static int mute_cutoff;     /* GLOBAL */
static int mute_count;      /* GLOBAL */
static int mute_category;   /* GLOBAL */

/*
 * Output mode priorities are as follows:
 *
 *  (1) --log-x overrides everything
 *  (2) syslog is used if --daemon or --inetd is defined and not --log-x
 *  (3) if OPENVPN_DEBUG_COMMAND_LINE is defined, output
 *      to constant logfile name.
 *  (4) Output to stdout.
 */

/* If true, indicates that stdin/stdout/stderr
   have been redirected due to --log */
static bool std_redir;      /* GLOBAL */

/* Should messages be written to the syslog? */
static bool use_syslog;     /* GLOBAL */

/* Should timestamps be included on messages to stdout/stderr? */
static bool suppress_timestamps; /* GLOBAL */

/* The program name passed to syslog */
#if SYSLOG_CAPABILITY
static char *pgmname_syslog;  /* GLOBAL */
#endif

/* If non-null, messages should be written here (used for debugging only) */
static FILE *msgfp;         /* GLOBAL */

/* If true, we forked from main OpenVPN process */
static bool forked;         /* GLOBAL */

void
msg_forked (void)
{
  forked = true;
}

bool
set_debug_level (const int level, const unsigned int flags)
{
  const int ceiling = 15;

  if (level >= 0 && level <= ceiling)
    {
      x_debug_level = level;
      return true;
    }
  else if (flags & SDL_CONSTRAIN)
    {
      x_debug_level = constrain_int (level, 0, ceiling);
      return true;
    }
  return false;
}

bool
set_mute_cutoff (const int cutoff)
{
  if (cutoff >= 0)
    {
      mute_cutoff = cutoff;
      return true;
    }
  else
    return false;
}

int
get_debug_level (void)
{
  return x_debug_level;
}

int
get_mute_cutoff (void)
{
  return mute_cutoff;
}

void
set_suppress_timestamps (bool suppressed)
{
  suppress_timestamps = suppressed;
}

void
error_reset ()
{
  use_syslog = std_redir = false;
  suppress_timestamps = false;
  x_debug_level = 1;
  mute_cutoff = 0;
  mute_count = 0;
  mute_category = 0;

#ifdef OPENVPN_DEBUG_COMMAND_LINE
  msgfp = fopen (OPENVPN_DEBUG_FILE, "w");
  if (!msgfp)
    openvpn_exit (OPENVPN_EXIT_STATUS_CANNOT_OPEN_DEBUG_FILE); /* exit point */
#else
  msgfp = NULL;
#endif
}

/*
 * Return a file to print messages to before syslog is opened.
 */
FILE *
msg_fp()
{
  FILE *fp = msgfp;
  if (!fp)
    fp = OPENVPN_MSG_FP;
  if (!fp)
    openvpn_exit (OPENVPN_EXIT_STATUS_CANNOT_OPEN_DEBUG_FILE); /* exit point */
  return fp;
}

#define SWAP { tmp = m1; m1 = m2; m2 = tmp; }

int x_msg_line_num; /* GLOBAL */

void x_msg (const unsigned int flags, const char *format, ...)
{
  struct gc_arena gc;
  va_list arglist;
#if SYSLOG_CAPABILITY
  int level;
#endif
  char *m1;
  char *m2;
  char *tmp;
  int e;
  const char *prefix;
  const char *prefix_sep;

  void usage_small (void);

#ifndef HAVE_VARARG_MACROS
  /* the macro has checked this otherwise */
  if (!MSG_TEST (flags))
    return;
#endif

  if (flags & M_ERRNO_SOCK)
    e = openvpn_errno_socket ();
  else
    e = openvpn_errno ();

  /*
   * Apply muting filter.
   */
#ifndef HAVE_VARARG_MACROS
  /* the macro has checked this otherwise */
  if (!dont_mute (flags))
    return;
#endif

  gc_init (&gc);

  mutex_lock_static (L_MSG);

  m1 = (char *) gc_malloc (ERR_BUF_SIZE, false, &gc);
  m2 = (char *) gc_malloc (ERR_BUF_SIZE, false, &gc);

  va_start (arglist, format);
  vsnprintf (m1, ERR_BUF_SIZE, format, arglist);
  va_end (arglist);
  m1[ERR_BUF_SIZE - 1] = 0; /* windows vsnprintf needs this */

  if ((flags & (M_ERRNO|M_ERRNO_SOCK)) && e)
    {
      openvpn_snprintf (m2, ERR_BUF_SIZE, "%s: %s (errno=%d)",
			m1, strerror_ts (e, &gc), e);
      SWAP;
    }

#ifdef USE_CRYPTO
  if (flags & M_SSL)
    {
      int nerrs = 0;
      int err;
      while ((err = ERR_get_error ()))
	{
	  openvpn_snprintf (m2, ERR_BUF_SIZE, "%s: %s",
			    m1, ERR_error_string (err, NULL));
	  SWAP;
	  ++nerrs;
	}
      if (!nerrs)
	{
	  openvpn_snprintf (m2, ERR_BUF_SIZE, "%s (OpenSSL)", m1);
	  SWAP;
	}
    }
#endif

  if (flags & M_OPTERR)
    {
      openvpn_snprintf (m2, ERR_BUF_SIZE, "Options error: %s", m1);
      SWAP;
    }

#if SYSLOG_CAPABILITY
  if (flags & (M_FATAL|M_NONFATAL|M_USAGE_SMALL))
    level = LOG_ERR;
  else if (flags & M_WARN)
    level = LOG_WARNING;
  else
    level = LOG_NOTICE;
#endif

  /* set up client prefix */
  if (flags & M_NOIPREFIX)
    prefix = NULL;
  else
    prefix = msg_get_prefix ();
  prefix_sep = " ";
  if (!prefix)
    prefix_sep = prefix = "";

  /* virtual output capability used to copy output to management subsystem */
  if (!forked)
    {
      const struct virtual_output *vo = msg_get_virtual_output ();
      if (vo)
	{
	  openvpn_snprintf (m2, ERR_BUF_SIZE, "%s%s%s",
			    prefix,
			    prefix_sep,
			    m1);
	  virtual_output_print (vo, flags, m2);
	}
    }

  if (!(flags & M_MSG_VIRT_OUT))
    {
      if (use_syslog && !std_redir && !forked)
	{
#if SYSLOG_CAPABILITY
	  syslog (level, "%s%s%s",
		  prefix,
		  prefix_sep,
		  m1);
#endif
	}
      else
	{
	  FILE *fp = msg_fp();
	  const bool show_usec = check_debug_level (DEBUG_LEVEL_USEC_TIME);

	  if ((flags & M_NOPREFIX) || suppress_timestamps)
	    {
	      fprintf (fp, "%s%s%s%s",
		       prefix,
		       prefix_sep,
		       m1,
		       (flags&M_NOLF) ? "" : "\n");
	    }
	  else
	    {
#ifdef USE_PTHREAD
	      fprintf (fp, "%s [%d] %s%s%s%s",
		       time_string (0, 0, show_usec, &gc),
		       (int) openvpn_thread_self (),
		       prefix,
		       prefix_sep,
		       m1,
		       (flags&M_NOLF) ? "" : "\n");
#else
	      fprintf (fp, "%s %s%s%s%s",
		       time_string (0, 0, show_usec, &gc),
		       prefix,
		       prefix_sep,
		       m1,
		       (flags&M_NOLF) ? "" : "\n");
#endif
	    }
	  fflush(fp);
	  ++x_msg_line_num;
	}
    }

  if (flags & M_FATAL)
    msg (M_INFO, "Exiting");

  mutex_unlock_static (L_MSG);
  
  if (flags & M_FATAL)
    openvpn_exit (OPENVPN_EXIT_STATUS_ERROR); /* exit point */

  if (flags & M_USAGE_SMALL)
    usage_small ();

  gc_free (&gc);
}

/*
 * Apply muting filter.
 */
bool
dont_mute (unsigned int flags)
{
  bool ret = true;
  if (mute_cutoff > 0 && !(flags & M_NOMUTE))
    {
      const int mute_level = DECODE_MUTE_LEVEL (flags);
      if (mute_level > 0 && mute_level == mute_category)
	{
	  if (mute_count == mute_cutoff)
	    msg (M_INFO | M_NOMUTE, "NOTE: --mute triggered...");
	  if (++mute_count > mute_cutoff)
	    ret = false;
	}
      else
	{
	  const int suppressed = mute_count - mute_cutoff;
	  if (suppressed > 0)
	    msg (M_INFO | M_NOMUTE,
		 "%d variation(s) on previous %d message(s) suppressed by --mute",
		 suppressed,
		 mute_cutoff);
	  mute_count = 1;
	  mute_category = mute_level;
	}
    }
  return ret;
}

void
assert_failed (const char *filename, int line)
{
  msg (M_FATAL, "Assertion failed at %s:%d", filename, line);
}

/*
 * Fail memory allocation.  Don't use msg() because it tries
 * to allocate memory as part of its operation.
 */
void
out_of_memory (void)
{
  fprintf (stderr, PACKAGE_NAME ": Out of Memory\n");
  exit (1);
}

void
open_syslog (const char *pgmname, bool stdio_to_null)
{
#if SYSLOG_CAPABILITY
  if (!msgfp && !std_redir)
    {
      if (!use_syslog)
	{
	  pgmname_syslog = string_alloc (pgmname ? pgmname : PACKAGE, NULL);
	  openlog (pgmname_syslog, LOG_PID, LOG_OPENVPN);
	  use_syslog = true;

	  /* Better idea: somehow pipe stdout/stderr output to msg() */
	  if (stdio_to_null)
	    set_std_files_to_null (false);
	}
    }
#else
  msg (M_WARN, "Warning on use of --daemon/--inetd: this operating system lacks daemon logging features, therefore when I become a daemon, I won't be able to log status or error messages");
#endif
}

void
close_syslog ()
{
#if SYSLOG_CAPABILITY
  if (use_syslog)
    {
      closelog();
      use_syslog = false;
      if (pgmname_syslog)
	{
	  free (pgmname_syslog);
	  pgmname_syslog = NULL;
	}
    }
#endif
}

#ifdef WIN32

static HANDLE orig_stderr;

HANDLE
get_orig_stderr (void)
{
  if (orig_stderr)
    return orig_stderr;
  else
    return GetStdHandle (STD_ERROR_HANDLE);
}

#endif

void
redirect_stdout_stderr (const char *file, bool append)
{
#if defined(WIN32)
  if (!std_redir)
    {
      HANDLE log_handle;
      int log_fd;
      struct security_attributes sa;

      init_security_attributes_allow_all (&sa);

      log_handle = CreateFile (file,
			       GENERIC_WRITE,
			       FILE_SHARE_READ,
			       &sa.sa,
			       append ? OPEN_ALWAYS : CREATE_ALWAYS,
			       FILE_ATTRIBUTE_NORMAL,
			       NULL);

      if (log_handle == INVALID_HANDLE_VALUE)
	{
	  msg (M_WARN|M_ERRNO, "Warning: cannot open --log file: %s", file);
	  return;
	}

      /* append to logfile? */
      if (append)
	{
	  if (SetFilePointer (log_handle, 0, NULL, FILE_END) == INVALID_SET_FILE_POINTER)
	    msg (M_ERR, "Error: cannot seek to end of --log file: %s", file);
	}
      
      /* save original stderr for password prompts */
      orig_stderr = GetStdHandle (STD_ERROR_HANDLE);

      /* set up for redirection */
      if (!SetStdHandle (STD_OUTPUT_HANDLE, log_handle)
	  || !SetStdHandle (STD_ERROR_HANDLE, log_handle))
	msg (M_ERR, "Error: cannot redirect stdout/stderr to --log file: %s", file);

      /* direct stdout/stderr to point to log_handle */
      log_fd = _open_osfhandle ((intptr_t)log_handle, _O_TEXT);
      if (log_fd == -1)
	msg (M_ERR, "Error: --log redirect failed due to _open_osfhandle failure");
      
      /* open log_handle as FILE stream */
      ASSERT (msgfp == NULL);
      msgfp = _fdopen (log_fd, "w");
      if (msgfp == NULL)
	msg (M_ERR, "Error: --log redirect failed due to _fdopen");

      std_redir = true;
    }
#elif defined(HAVE_DUP2)
  if (!std_redir)
    {
      int out = open (file,
		      O_CREAT | O_WRONLY | (append ? O_APPEND : O_TRUNC),
		      S_IRUSR | S_IWUSR);

      if (out < 0)
	{
	  msg (M_WARN|M_ERRNO, "Warning: Error redirecting stdout/stderr to --log file: %s", file);
	  return;
	}

      if (dup2 (out, 1) == -1)
	msg (M_ERR, "--log file redirection error on stdout");
      if (dup2 (out, 2) == -1)
	msg (M_ERR, "--log file redirection error on stderr");

      if (out > 2)
	close (out);

      std_redir = true;
    }

#else
  msg (M_WARN, "WARNING: The --log option is not supported on this OS because it lacks the dup2 function");
#endif
}

/*
 * Functions used to check return status
 * of I/O operations.
 */

unsigned int x_cs_info_level;    /* GLOBAL */
unsigned int x_cs_verbose_level; /* GLOBAL */
unsigned int x_cs_err_delay_ms;  /* GLOBAL */

void
reset_check_status ()
{
  x_cs_info_level = 0;
  x_cs_verbose_level = 0;
}

void
set_check_status (unsigned int info_level, unsigned int verbose_level)
{
  x_cs_info_level = info_level;
  x_cs_verbose_level = verbose_level;
}

/*
 * Called after most socket or tun/tap operations, via the inline
 * function check_status().
 *
 * Decide if we should print an error message, and see if we can
 * extract any useful info from the error, such as a Path MTU hint
 * from the OS.
 */
void
x_check_status (int status,
		const char *description,
		struct link_socket *sock,
		struct tuntap *tt)
{
  const int my_errno = (sock ? openvpn_errno_socket () : openvpn_errno ());
  const char *extended_msg = NULL;

  msg (x_cs_verbose_level, "%s %s returned %d",
       sock ? proto2ascii (sock->info.proto, true) : "",
       description,
       status);

  if (status < 0)
    {
      struct gc_arena gc = gc_new ();
#if EXTENDED_SOCKET_ERROR_CAPABILITY
      /* get extended socket error message and possible PMTU hint from OS */
      if (sock)
	{
	  int mtu;
	  extended_msg = format_extended_socket_error (sock->sd, &mtu, &gc);
	  if (mtu > 0 && sock->mtu != mtu)
	    {
	      sock->mtu = mtu;
	      sock->info.mtu_changed = true;
	    }
	}
#elif defined(WIN32)
      /* get possible driver error from TAP-Win32 driver */
      extended_msg = tap_win32_getinfo (tt, &gc);
#endif
      if (!ignore_sys_error (my_errno))
	{
	  if (extended_msg)
	    msg (x_cs_info_level, "%s %s [%s]: %s (code=%d)",
		 description,
		 sock ? proto2ascii (sock->info.proto, true) : "",
		 extended_msg,
		 strerror_ts (my_errno, &gc),
		 my_errno);
	  else
	    msg (x_cs_info_level, "%s %s: %s (code=%d)",
		 description,
		 sock ? proto2ascii (sock->info.proto, true) : "",
		 strerror_ts (my_errno, &gc),
		 my_errno);

	  if (x_cs_err_delay_ms)
	    sleep_milliseconds (x_cs_err_delay_ms);
	}
      gc_free (&gc);
    }
}

/*
 * In multiclient mode, put a client-specific prefix
 * before each message.
 */
const char *x_msg_prefix; /* GLOBAL */

#ifdef USE_PTHREAD
pthread_key_t x_msg_prefix_key; /* GLOBAL */
#endif

/*
 * Allow MSG to be redirected through a virtual_output object
 */

const struct virtual_output *x_msg_virtual_output; /* GLOBAL */

/*
 * Init thread-local variables
 */

void
msg_thread_init (void)
{
#ifdef USE_PTHREAD
  ASSERT (!pthread_key_create (&x_msg_prefix_key, NULL));
#endif
}

void
msg_thread_uninit (void)
{
#ifdef USE_PTHREAD
  pthread_key_delete (x_msg_prefix_key);
#endif
}

/*
 * Exiting.
 */

void
openvpn_exit (const int status)
{
#ifdef ENABLE_PLUGIN
  void plugin_abort (void);
#endif

#ifdef WIN32
  uninit_win32 ();
#endif

  close_syslog ();

#ifdef ENABLE_PLUGIN
  plugin_abort ();
#endif

#if PORT_SHARE
  if (port_share)
    port_share_abort (port_share);
#endif

#ifdef ABORT_ON_ERROR
  if (status == OPENVPN_EXIT_STATUS_ERROR)
    abort ();
#endif

  if (status == OPENVPN_EXIT_STATUS_GOOD)
    perf_output_results ();

  exit (status);
}

/*
 * Translate msg flags into a string
 */
const char *
msg_flags_string (const unsigned int flags, struct gc_arena *gc)
{
  struct buffer out = alloc_buf_gc (16, gc);
  if (flags == M_INFO)
    buf_printf (&out, "I");
  if (flags & M_FATAL)
    buf_printf (&out, "F");
  if (flags & M_NONFATAL)
    buf_printf (&out, "N");
  if (flags & M_WARN)
    buf_printf (&out, "W");
  if (flags & M_DEBUG)
    buf_printf (&out, "D");
  return BSTR (&out);
}

#ifdef ENABLE_DEBUG
void
crash (void)
{
  char *null = NULL;
  *null = 0;
}
#endif

#ifdef WIN32

const char *
strerror_win32 (DWORD errnum, struct gc_arena *gc)
{
  /*
   * This code can be omitted, though often the Windows
   * WSA error messages are less informative than the
   * Posix equivalents.
   */
#if 1
  switch (errnum) {
    /*
     * When the TAP-Win32 driver returns STATUS_UNSUCCESSFUL, this code
     * gets returned to user space.
     */
  case ERROR_GEN_FAILURE:
    return "General failure (ERROR_GEN_FAILURE)";
  case ERROR_IO_PENDING:
    return "I/O Operation in progress (ERROR_IO_PENDING)";
  case WSA_IO_INCOMPLETE:
    return "I/O Operation in progress (WSA_IO_INCOMPLETE)";
  case WSAEINTR:
    return "Interrupted system call (WSAEINTR)";
  case WSAEBADF:
    return "Bad file number (WSAEBADF)";
  case WSAEACCES:
    return "Permission denied (WSAEACCES)";
  case WSAEFAULT:
    return "Bad address (WSAEFAULT)";
  case WSAEINVAL:
    return "Invalid argument (WSAEINVAL)";
  case WSAEMFILE:
    return "Too many open files (WSAEMFILE)";
  case WSAEWOULDBLOCK:
    return "Operation would block (WSAEWOULDBLOCK)";
  case WSAEINPROGRESS:
    return "Operation now in progress (WSAEINPROGRESS)";
  case WSAEALREADY:
    return "Operation already in progress (WSAEALREADY)";
  case WSAEDESTADDRREQ:
    return "Destination address required (WSAEDESTADDRREQ)";
  case WSAEMSGSIZE:
    return "Message too long (WSAEMSGSIZE)";
  case WSAEPROTOTYPE:
    return "Protocol wrong type for socket (WSAEPROTOTYPE)";
  case WSAENOPROTOOPT:
    return "Bad protocol option (WSAENOPROTOOPT)";
  case WSAEPROTONOSUPPORT:
    return "Protocol not supported (WSAEPROTONOSUPPORT)";
  case WSAESOCKTNOSUPPORT:
    return "Socket type not supported (WSAESOCKTNOSUPPORT)";
  case WSAEOPNOTSUPP:
    return "Operation not supported on socket (WSAEOPNOTSUPP)";
  case WSAEPFNOSUPPORT:
    return "Protocol family not supported (WSAEPFNOSUPPORT)";
  case WSAEAFNOSUPPORT:
    return "Address family not supported by protocol family (WSAEAFNOSUPPORT)";
  case WSAEADDRINUSE:
    return "Address already in use (WSAEADDRINUSE)";
  case WSAENETDOWN:
    return "Network is down (WSAENETDOWN)";
  case WSAENETUNREACH:
    return "Network is unreachable (WSAENETUNREACH)";
  case WSAENETRESET:
    return "Net dropped connection or reset (WSAENETRESET)";
  case WSAECONNABORTED:
    return "Software caused connection abort (WSAECONNABORTED)";
  case WSAECONNRESET:
    return "Connection reset by peer (WSAECONNRESET)";
  case WSAENOBUFS:
    return "No buffer space available (WSAENOBUFS)";
  case WSAEISCONN:
    return "Socket is already connected (WSAEISCONN)";
  case WSAENOTCONN:
    return "Socket is not connected (WSAENOTCONN)";
  case WSAETIMEDOUT:
    return "Connection timed out (WSAETIMEDOUT)";
  case WSAECONNREFUSED:
    return "Connection refused (WSAECONNREFUSED)";
  case WSAELOOP:
    return "Too many levels of symbolic links (WSAELOOP)";
  case WSAENAMETOOLONG:
    return "File name too long (WSAENAMETOOLONG)";
  case WSAEHOSTDOWN:
    return "Host is down (WSAEHOSTDOWN)";
  case WSAEHOSTUNREACH:
    return "No Route to Host (WSAEHOSTUNREACH)";
  case WSAENOTEMPTY:
    return "Directory not empty (WSAENOTEMPTY)";
  case WSAEPROCLIM:
    return "Too many processes (WSAEPROCLIM)";
  case WSAEUSERS:
    return "Too many users (WSAEUSERS)";
  case WSAEDQUOT:
    return "Disc Quota Exceeded (WSAEDQUOT)";
  case WSAESTALE:
    return "Stale NFS file handle (WSAESTALE)";
  case WSASYSNOTREADY:
    return "Network SubSystem is unavailable (WSASYSNOTREADY)";
  case WSAVERNOTSUPPORTED:
    return "WINSOCK DLL Version out of range (WSAVERNOTSUPPORTED)";
  case WSANOTINITIALISED:
    return "Successful WSASTARTUP not yet performed (WSANOTINITIALISED)";
  case WSAEREMOTE:
    return "Too many levels of remote in path (WSAEREMOTE)";
  case WSAHOST_NOT_FOUND:
    return "Host not found (WSAHOST_NOT_FOUND)";
  default:
    break;
  }
#endif

  /* format a windows error message */
  {
    char message[256];
    struct buffer out = alloc_buf_gc (256, gc);
    const int status =  FormatMessage (
				       FORMAT_MESSAGE_IGNORE_INSERTS
				       | FORMAT_MESSAGE_FROM_SYSTEM
				       | FORMAT_MESSAGE_ARGUMENT_ARRAY,
				       NULL,
				       errnum,
				       0,
				       message,
				       sizeof (message),
				       NULL);
    if (!status)
      {
	buf_printf (&out, "[Unknown Win32 Error]");
      }
    else
      {
	char *cp;
	for (cp = message; *cp != '\0'; ++cp)
	  {
	    if (*cp == '\n' || *cp == '\r')
	      *cp = ' ';
	  }
	
	buf_printf(&out, "%s", message);
      }
    
    return BSTR (&out);
  }
}

#endif