src/login-common/client-common.c

	client-common.c revision 04eb0abcf8f8b0c014499b5c5bae89484553613f
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen/* Copyright (c) 2002-2016 Dovecot authors, see the included COPYING file */
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "login-common.h"
345648b341f228bd7f0b89f8aa3ecb9c470d817eTimo Sirainen#include "array.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "hostpid.h"
d1414c09cf0d58ac983054e2f4e1a1f329272dcfTimo Sirainen#include "llist.h"
5a2cb3d097a2d9a9e930af997e7bf3400a8d840dTimo Sirainen#include "istream.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "ostream.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "iostream-rawlog.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "process-title.h"
97c339398f1aba6f315b55a9b6ee6b020e33bea4Timo Sirainen#include "buffer.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "str.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "base64.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "str-sanitize.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "safe-memset.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "var-expand.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "master-interface.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "master-service.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "master-service-ssl-settings.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "master-auth.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "auth-client.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "dsasl-client.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "login-proxy.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "ssl-proxy.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen#include "client-common.h"
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainenstruct client *clients = NULL;
d1414c09cf0d58ac983054e2f4e1a1f329272dcfTimo Sirainenstatic struct client *last_client = NULL;
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainenstatic unsigned int clients_count = 0;
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainenstatic void empty_login_client_allocated_hook(struct client *client ATTR_UNUSED)
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen{
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen}
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainenstatic login_client_allocated_func_t *hook_client_allocated =
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen    empty_login_client_allocated_hook;
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen
73bfdbe28c2ce6d143eadf0bab8ccfbe4cab0faeTimo Sirainenlogin_client_allocated_func_t *
d1414c09cf0d58ac983054e2f4e1a1f329272dcfTimo Sirainenlogin_client_allocated_hook_set(login_client_allocated_func_t *new_hook)
d1414c09cf0d58ac983054e2f4e1a1f329272dcfTimo Sirainen{
d1414c09cf0d58ac983054e2f4e1a1f329272dcfTimo Sirainen    login_client_allocated_func_t *old_hook = hook_client_allocated;
d1414c09cf0d58ac983054e2f4e1a1f329272dcfTimo Sirainen
c57776c06ec99ba9b0dafdbf9475ea72ea8ca134Timo Sirainen    hook_client_allocated = new_hook;
d1414c09cf0d58ac983054e2f4e1a1f329272dcfTimo Sirainen    return old_hook;
d1414c09cf0d58ac983054e2f4e1a1f329272dcfTimo Sirainen}
d1414c09cf0d58ac983054e2f4e1a1f329272dcfTimo Sirainen
d1414c09cf0d58ac983054e2f4e1a1f329272dcfTimo Sirainenstatic void client_idle_disconnect_timeout(struct client *client)
d1414c09cf0d58ac983054e2f4e1a1f329272dcfTimo Sirainen{
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen    const char *user_reason, *destroy_reason;
33c6d5807b449463e9b81db5ec99fe027cc1b984Timo Sirainen    unsigned int secs;
8eea67470c1bd8562a62e7445d930bb2079b1a43Timo Sirainen
94a78eb438622fa53abef1e1726714dacad4b61cTimo Sirainen    if (client->master_tag != 0) {
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen        secs = ioloop_time - client->auth_finished;
c7480644202e5451fbed448508ea29a25cffc99cTimo Sirainen        user_reason = "Timeout while finishing login.";
a4ac325c2802693c6b761e5a8fda961e5d7490eaTimo Sirainen        destroy_reason = t_strdup_printf(
b7c2065b3f10f9ae27787a9db5aaefbfc70d4502Timo Sirainen            "Timeout while finishing login (waited %u secs)", secs);
0469ed17dafcc56589ce00960a23f4f06817dfb5Timo Sirainen        client_log_err(client, destroy_reason);
0469ed17dafcc56589ce00960a23f4f06817dfb5Timo Sirainen    } else if (client->auth_request != NULL) {
0469ed17dafcc56589ce00960a23f4f06817dfb5Timo Sirainen        user_reason =
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen            "Disconnected for inactivity during authentication.";
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen        destroy_reason =
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen            "Disconnected: Inactivity during authentication";
97c339398f1aba6f315b55a9b6ee6b020e33bea4Timo Sirainen    } else if (client->login_proxy != NULL) {
97c339398f1aba6f315b55a9b6ee6b020e33bea4Timo Sirainen        secs = ioloop_time - client->created;
97c339398f1aba6f315b55a9b6ee6b020e33bea4Timo Sirainen        user_reason = "Timeout while finishing login.";
97c339398f1aba6f315b55a9b6ee6b020e33bea4Timo Sirainen        destroy_reason = t_strdup_printf(
97c339398f1aba6f315b55a9b6ee6b020e33bea4Timo Sirainen            "proxy: Logging in to %s:%u timed out "
97c339398f1aba6f315b55a9b6ee6b020e33bea4Timo Sirainen            "(state=%u, duration=%us)",
97c339398f1aba6f315b55a9b6ee6b020e33bea4Timo Sirainen            login_proxy_get_host(client->login_proxy),
97c339398f1aba6f315b55a9b6ee6b020e33bea4Timo Sirainen            login_proxy_get_port(client->login_proxy),
0469ed17dafcc56589ce00960a23f4f06817dfb5Timo Sirainen            client->proxy_state, secs);
0469ed17dafcc56589ce00960a23f4f06817dfb5Timo Sirainen        client_log_err(client, destroy_reason);
0469ed17dafcc56589ce00960a23f4f06817dfb5Timo Sirainen    } else {
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen        user_reason = "Disconnected for inactivity.";
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen        destroy_reason = "Disconnected: Inactivity";
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen    }
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen    client_notify_disconnect(client, CLIENT_DISCONNECT_TIMEOUT, user_reason);
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen    client_destroy(client, destroy_reason);
33c6d5807b449463e9b81db5ec99fe027cc1b984Timo Sirainen}
8eea67470c1bd8562a62e7445d930bb2079b1a43Timo Sirainen
94a78eb438622fa53abef1e1726714dacad4b61cTimo Sirainenstatic void client_open_streams(struct client *client)
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen{
c7480644202e5451fbed448508ea29a25cffc99cTimo Sirainen    client->input = i_stream_create_fd(client->fd, LOGIN_MAX_INBUF_SIZE);
a4ac325c2802693c6b761e5a8fda961e5d7490eaTimo Sirainen    client->output = o_stream_create_fd(client->fd, LOGIN_MAX_OUTBUF_SIZE);
b7c2065b3f10f9ae27787a9db5aaefbfc70d4502Timo Sirainen    o_stream_set_no_error_handling(client->output, TRUE);
0469ed17dafcc56589ce00960a23f4f06817dfb5Timo Sirainen
0469ed17dafcc56589ce00960a23f4f06817dfb5Timo Sirainen    if (login_rawlog_dir != NULL) {
0469ed17dafcc56589ce00960a23f4f06817dfb5Timo Sirainen        if (iostream_rawlog_create(login_rawlog_dir, &client->input,
25757faf029c369a8318349dafe952e2358df1d8Timo Sirainen                       &client->output) < 0)
            login_rawlog_dir = NULL;
    }
}

static bool client_is_trusted(struct client *client)
{
    const char *const *net;
    struct ip_addr net_ip;
    unsigned int bits;

    if (client->set->login_trusted_networks == NULL)
        return FALSE;

    net = t_strsplit_spaces(client->set->login_trusted_networks, ", ");
    for (; *net != NULL; net++) {
        if (net_parse_range(*net, &net_ip, &bits) < 0) {
            i_error("login_trusted_networks: "
                "Invalid network '%s'", *net);
            break;
        }

        if (net_is_in_network(&client->ip, &net_ip, bits))
            return TRUE;
    }
    return FALSE;
}

struct client *
client_create(int fd, bool ssl, pool_t pool,
          const struct master_service_connection *conn,
          const struct login_settings *set,
          const struct master_service_ssl_settings *ssl_set,
          void **other_sets)
{
    struct client *client;

    i_assert(fd != -1);

    client = login_binary->client_vfuncs->alloc(pool);
    client->v = *login_binary->client_vfuncs;
    if (client->v.auth_send_challenge == NULL)
        client->v.auth_send_challenge = client_auth_send_challenge;
    if (client->v.auth_parse_response == NULL)
        client->v.auth_parse_response = client_auth_parse_response;

    client->created = ioloop_time;
    client->refcount = 1;

    client->pool = pool;
    client->set = set;
    client->ssl_set = ssl_set;
    p_array_init(&client->module_contexts, client->pool, 5);

    client->fd = fd;
    client->tls = ssl;

    client->local_ip = conn->local_ip;
    client->local_port = conn->local_port;
    client->ip = conn->remote_ip;
    client->remote_port = conn->remote_port;
    client->real_local_ip = conn->real_local_ip;
    client->real_local_port = conn->real_local_port;
    client->real_remote_ip = conn->real_remote_ip;
    client->real_remote_port = conn->real_remote_port;
    client->listener_name = p_strdup(client->pool, conn->name);

    client->trusted = client_is_trusted(client);
    client->secured = ssl || client->trusted ||
        net_ip_compare(&conn->real_remote_ip, &conn->real_local_ip);
    client->proxy_ttl = LOGIN_PROXY_TTL;

    if (last_client == NULL)
        last_client = client;
    DLLIST_PREPEND(&clients, client);
    clients_count++;

    client->to_disconnect =
        timeout_add(CLIENT_LOGIN_TIMEOUT_MSECS,
                client_idle_disconnect_timeout, client);
    client_open_streams(client);

    hook_client_allocated(client);
    client->v.create(client, other_sets);

    if (auth_client_is_connected(auth_client))
        client_notify_auth_ready(client);
    else
        client_set_auth_waiting(client);

    login_refresh_proctitle();
    return client;
}

void client_destroy(struct client *client, const char *reason)
{
    if (client->destroyed)
        return;
    client->destroyed = TRUE;

    if (!client->login_success && reason != NULL) {
        reason = t_strconcat(reason, " ",
            client_get_extra_disconnect_reason(client), NULL);
    }
    if (reason != NULL)
        client_log(client, reason);

    if (last_client == client)
        last_client = client->prev;
    DLLIST_REMOVE(&clients, client);

    if (client->output != NULL)
        o_stream_uncork(client->output);
    if (!client->login_success && client->ssl_proxy != NULL)
        ssl_proxy_destroy(client->ssl_proxy);
    if (client->input != NULL)
        i_stream_close(client->input);
    if (client->output != NULL)
        o_stream_close(client->output);

    if (client->master_tag != 0) {
        i_assert(client->auth_request == NULL);
        i_assert(client->authenticating);
        i_assert(client->refcount > 1);
        client->authenticating = FALSE;
        master_auth_request_abort(master_auth, client->master_tag);
        client->refcount--;
    } else if (client->auth_request != NULL) {
        i_assert(client->authenticating);
        sasl_server_auth_abort(client);
    } else {
        i_assert(!client->authenticating);
    }

    if (client->io != NULL)
        io_remove(&client->io);
    if (client->to_disconnect != NULL)
        timeout_remove(&client->to_disconnect);
    if (client->to_auth_waiting != NULL)
        timeout_remove(&client->to_auth_waiting);
    if (client->auth_response != NULL)
        str_free(&client->auth_response);

    if (client->fd != -1) {
        net_disconnect(client->fd);
        client->fd = -1;
    }

    if (client->proxy_password != NULL) {
        safe_memset(client->proxy_password, 0,
                strlen(client->proxy_password));
        i_free_and_null(client->proxy_password);
    }

    if (client->proxy_sasl_client != NULL)
        dsasl_client_free(&client->proxy_sasl_client);
    if (client->login_proxy != NULL)
        login_proxy_free(&client->login_proxy);
    if (client->v.destroy != NULL)
        client->v.destroy(client);
    if (client_unref(&client) && initial_service_count == 1) {
        /* as soon as this connection is done with proxying
           (or whatever), the process will die. there's no need for
           authentication anymore, so close the connection.
           do this only with initial service_count=1, in case there
           are other clients with pending authentications */
        auth_client_disconnect(auth_client, "unnecessary connection");
    }
    login_client_destroyed();
    login_refresh_proctitle();
}

void client_destroy_success(struct client *client, const char *reason)
{
    client->login_success = TRUE;
    client_destroy(client, reason);
}

void client_destroy_internal_failure(struct client *client)
{
    client_notify_disconnect(client, CLIENT_DISCONNECT_INTERNAL_ERROR,
        "Internal login failure. "
        "Refer to server log for more information.");
    client_destroy(client, t_strdup_printf(
        "Internal login failure (pid=%s id=%u)",
        my_pid, client->master_auth_id));
}

void client_ref(struct client *client)
{
    client->refcount++;
}

bool client_unref(struct client **_client)
{
    struct client *client = *_client;

    i_assert(client->refcount > 0);
    if (--client->refcount > 0)
        return TRUE;

    *_client = NULL;

    i_assert(client->destroyed);
    i_assert(client->login_proxy == NULL);

    if (client->ssl_proxy != NULL)
        ssl_proxy_free(&client->ssl_proxy);
    if (client->input != NULL)
        i_stream_unref(&client->input);
    if (client->output != NULL)
        o_stream_unref(&client->output);

    i_free(client->proxy_user);
    i_free(client->proxy_master_user);
    i_free(client->virtual_user);
    i_free(client->virtual_user_orig);
    i_free(client->virtual_auth_user);
    i_free(client->auth_mech_name);
    i_free(client->master_data_prefix);
    pool_unref(&client->pool);

    i_assert(clients_count > 0);
    clients_count--;

    master_service_client_connection_destroyed(master_service);
    login_refresh_proctitle();
    return FALSE;
}

void client_destroy_oldest(void)
{
    struct client *client;

    if (last_client == NULL) {
        /* we have no clients */
        return;
    }

    /* destroy the last client that hasn't successfully authenticated yet.
       this is usually the last client, but don't kill it if it's just
       waiting for master to finish its job. */
    for (client = last_client; client != NULL; client = client->prev) {
        if (client->master_tag == 0)
            break;
    }
    if (client == NULL)
        client = last_client;

    client_notify_disconnect(client, CLIENT_DISCONNECT_RESOURCE_CONSTRAINT,
                 "Connection queue full");
    client_destroy(client, "Disconnected: Connection queue full");
}

void clients_destroy_all_reason(const char *reason)
{
    struct client *client, *next;

    for (client = clients; client != NULL; client = next) {
        next = client->next;
        client_notify_disconnect(client,
            CLIENT_DISCONNECT_SYSTEM_SHUTDOWN, reason);
        client_destroy(client, reason);
    }
}

void clients_destroy_all(void)
{
    clients_destroy_all_reason("Disconnected: Shutting down");
}

static void client_start_tls(struct client *client)
{
    int fd_ssl;

    client_ref(client);
    if (!client_unref(&client) || client->destroyed)
        return;

    fd_ssl = ssl_proxy_alloc(client->fd, &client->ip, client->pool,
                 client->set, client->ssl_set,
                 &client->ssl_proxy);
    if (fd_ssl == -1) {
        client_notify_disconnect(client,
            CLIENT_DISCONNECT_INTERNAL_ERROR,
            "TLS initialization failed.");
        client_destroy(client,
            "Disconnected: TLS initialization failed.");
        return;
    }
    ssl_proxy_set_client(client->ssl_proxy, client);
    ssl_proxy_start(client->ssl_proxy);

    client->starttls = TRUE;
    client->tls = TRUE;
    client->secured = TRUE;
    login_refresh_proctitle();

    client->fd = fd_ssl;
    client->io = io_add(client->fd, IO_READ, client_input, client);
    i_stream_unref(&client->input);
    o_stream_unref(&client->output);
    client_open_streams(client);

    client->v.starttls(client);
}

static int client_output_starttls(struct client *client)
{
    int ret;

    if ((ret = o_stream_flush(client->output)) < 0) {
        client_destroy(client, "Disconnected");
        return 1;
    }

    if (ret > 0) {
        o_stream_unset_flush_callback(client->output);
        client_start_tls(client);
    }
    return 1;
}

void client_cmd_starttls(struct client *client)
{
    if (client->tls) {
        client->v.notify_starttls(client, FALSE, "TLS is already active.");
        return;
    }

    if (!client_is_tls_enabled(client)) {
        client->v.notify_starttls(client, FALSE, "TLS support isn't enabled.");
        return;
    }

    /* remove input handler, SSL proxy gives us a new fd. we also have to
       remove it in case we have to wait for buffer to be flushed */
    if (client->io != NULL)
        io_remove(&client->io);

    client->v.notify_starttls(client, TRUE, "Begin TLS negotiation now.");

    /* uncork the old fd */
    o_stream_uncork(client->output);

    if (o_stream_flush(client->output) <= 0) {
        /* the buffer has to be flushed */
        o_stream_set_flush_pending(client->output, TRUE);
        o_stream_set_flush_callback(client->output,
                        client_output_starttls, client);
    } else {
        client_start_tls(client);
    }
}

unsigned int clients_get_count(void)
{
    return clients_count;
}

const char *client_get_session_id(struct client *client)
{
    buffer_t *buf, *base64_buf;
    struct timeval tv;
    uint64_t timestamp;
    unsigned int i;

    if (client->session_id != NULL)
        return client->session_id;

    buf = buffer_create_dynamic(pool_datastack_create(), 24);
    base64_buf = buffer_create_dynamic(pool_datastack_create(), 24*2);

    if (gettimeofday(&tv, NULL) < 0)
        i_fatal("gettimeofday(): %m");
    timestamp = tv.tv_usec + (long long)tv.tv_sec * 1000ULL*1000ULL;

    /* add lowest 48 bits of the timestamp. this gives us a bit less than
       9 years until it wraps */
    for (i = 0; i < 48; i += 8)
        buffer_append_c(buf, (timestamp >> i) & 0xff);

    buffer_append_c(buf, client->remote_port & 0xff);
    buffer_append_c(buf, (client->remote_port >> 8) & 0xff);
    if (IPADDR_IS_V6(&client->ip))
        buffer_append(buf, &client->ip.u.ip6, sizeof(client->ip.u.ip6));
    else
        buffer_append(buf, &client->ip.u.ip4, sizeof(client->ip.u.ip4));
    base64_encode(buf->data, buf->used, base64_buf);
    client->session_id = p_strdup(client->pool, str_c(base64_buf));
    return client->session_id;
}

static struct var_expand_table login_var_expand_empty_tab[] = {
    { 'u', NULL, "user" },
    { 'n', NULL, "username" },
    { 'd', NULL, "domain" },

    { 's', NULL, "service" },
    { 'h', NULL, "home" },
    { 'l', NULL, "lip" },
    { 'r', NULL, "rip" },
    { 'p', NULL, "pid" },
    { 'm', NULL, "mech" },
    { 'a', NULL, "lport" },
    { 'b', NULL, "rport" },
    { 'c', NULL, "secured" },
    { 'k', NULL, "ssl_security" },
    { 'e', NULL, "mail_pid" },
    { '\0', NULL, "session" },
    { '\0', NULL, "real_lip" },
    { '\0', NULL, "real_rip" },
    { '\0', NULL, "real_lport" },
    { '\0', NULL, "real_rport" },
    { '\0', NULL, "orig_user" },
    { '\0', NULL, "orig_username" },
    { '\0', NULL, "orig_domain" },
    { '\0', NULL, "auth_user" },
    { '\0', NULL, "auth_username" },
    { '\0', NULL, "auth_domain" },
    { '\0', NULL, "listener" },
    { '\0', NULL, "local_name" },
    { '\0', NULL, NULL }
};

static void
get_var_expand_users(struct var_expand_table *tab, const char *user)
{
    unsigned int i;

    tab[0].value = user;
    tab[1].value = t_strcut(user, '@');
    tab[2].value = i_strchr_to_next(user, '@');

    for (i = 0; i < 3; i++)
        tab[i].value = str_sanitize(tab[i].value, 80);
}

static const struct var_expand_table *
get_var_expand_table(struct client *client)
{
    struct var_expand_table *tab;

    tab = t_malloc_no0(sizeof(login_var_expand_empty_tab));
    memcpy(tab, login_var_expand_empty_tab,
           sizeof(login_var_expand_empty_tab));

    if (client->virtual_user != NULL)
        get_var_expand_users(tab, client->virtual_user);
    tab[3].value = login_binary->protocol;
    tab[4].value = getenv("HOME");
    tab[5].value = net_ip2addr(&client->local_ip);
    tab[6].value = net_ip2addr(&client->ip);
    tab[7].value = my_pid;
    tab[8].value = client->auth_mech_name == NULL ? NULL :
        str_sanitize(client->auth_mech_name, MAX_MECH_NAME);
    tab[9].value = dec2str(client->local_port);
    tab[10].value = dec2str(client->remote_port);
    if (!client->tls) {
        tab[11].value = client->secured ? "secured" : NULL;
        tab[12].value = "";
    } else {
        const char *ssl_state =
            ssl_proxy_is_handshaked(client->ssl_proxy) ?
            "TLS" : "TLS handshaking";
        const char *ssl_error =
            ssl_proxy_get_last_error(client->ssl_proxy);

        tab[11].value = ssl_error == NULL ? ssl_state :
            t_strdup_printf("%s: %s", ssl_state, ssl_error);
        tab[12].value =
            ssl_proxy_get_security_string(client->ssl_proxy);
    }
    tab[13].value = client->mail_pid == 0 ? "" :
        dec2str(client->mail_pid);
    tab[14].value = client_get_session_id(client);
    tab[15].value = net_ip2addr(&client->real_local_ip);
    tab[16].value = net_ip2addr(&client->real_remote_ip);
    tab[17].value = dec2str(client->real_local_port);
    tab[18].value = dec2str(client->real_remote_port);
    if (client->virtual_user_orig != NULL)
        get_var_expand_users(tab+19, client->virtual_user_orig);
    else {
        tab[19].value = tab[0].value;
        tab[20].value = tab[1].value;
        tab[21].value = tab[2].value;
    }
    if (client->virtual_auth_user != NULL)
        get_var_expand_users(tab+22, client->virtual_auth_user);
    else {
        tab[22].value = tab[19].value;
        tab[23].value = tab[20].value;
        tab[24].value = tab[21].value;
    }
    tab[25].value = client->listener_name;
    tab[26].value = str_sanitize(client->local_name, 256);
    return tab;
}

static bool have_username_key(const char *str)
{
    char key;

    for (; *str != '\0'; str++) {
        if (str[0] == '%' && str[1] != '\0') {
            str++;
            key = var_get_key(str);
            if (key == 'u' || key == 'n')
                return TRUE;
        }
    }
    return FALSE;
}

static const char *
client_var_expand_func_passdb(const char *data, void *context)
{
    struct client *client = context;
    const char *field_name = data;
    unsigned int i, field_name_len;

    if (client->auth_passdb_args == NULL)
        return NULL;

    field_name_len = strlen(field_name);
    for (i = 0; client->auth_passdb_args[i] != NULL; i++) {
        if (strncmp(client->auth_passdb_args[i], field_name,
                field_name_len) == 0 &&
            client->auth_passdb_args[i][field_name_len] == '=')
            return client->auth_passdb_args[i] + field_name_len+1;
    }
    return NULL;
}

static const char *
client_get_log_str(struct client *client, const char *msg)
{
    static const struct var_expand_func_table func_table[] = {
        { "passdb", client_var_expand_func_passdb },
        { NULL, NULL }
    };
    const struct var_expand_table *var_expand_table;
    char *const *e;
    string_t *str, *str2;
    unsigned int pos;

    var_expand_table = get_var_expand_table(client);

    str = t_str_new(256);
    str2 = t_str_new(128);
    for (e = client->set->log_format_elements_split; *e != NULL; e++) {
        pos = str_len(str);
        var_expand_with_funcs(str, *e, var_expand_table,
                      func_table, client);
        if (have_username_key(*e)) {
            /* username is added even if it's empty */
        } else {
            str_truncate(str2, 0);
            var_expand(str2, *e, login_var_expand_empty_tab);
            if (strcmp(str_c(str)+pos, str_c(str2)) == 0) {
                /* empty %variables, don't add */
                str_truncate(str, pos);
                continue;
            }
        }

        if (str_len(str) > 0)
            str_append(str, ", ");
    }

    if (str_len(str) > 0)
        str_truncate(str, str_len(str)-2);

    const struct var_expand_table tab[3] = {
        { 's', t_strdup(str_c(str)), NULL },
        { '$', msg, NULL },
        { '\0', NULL, NULL }
    };

    str_truncate(str, 0);
    var_expand(str, client->set->login_log_format, tab);
    return str_c(str);
}

void client_log(struct client *client, const char *msg)
{
    T_BEGIN {
        i_info("%s", client_get_log_str(client, msg));
    } T_END;
}

void client_log_err(struct client *client, const char *msg)
{
    T_BEGIN {
        i_error("%s", client_get_log_str(client, msg));
    } T_END;
}

void client_log_warn(struct client *client, const char *msg)
{
    T_BEGIN {
        i_warning("%s", client_get_log_str(client, msg));
    } T_END;
}

bool client_is_tls_enabled(struct client *client)
{
    return ssl_initialized && strcmp(client->ssl_set->ssl, "no") != 0;
}

const char *client_get_extra_disconnect_reason(struct client *client)
{
    unsigned int auth_secs = client->auth_first_started == 0 ? 0 :
        ioloop_time - client->auth_first_started;

    if (client->set->auth_ssl_require_client_cert &&
        client->ssl_proxy != NULL) {
        if (ssl_proxy_has_broken_client_cert(client->ssl_proxy))
            return "(client sent an invalid cert)";
        if (!ssl_proxy_has_valid_client_cert(client->ssl_proxy))
            return "(client didn't send a cert)";
    }

    if (!client->notified_auth_ready)
        return t_strdup_printf(
            "(disconnected before auth was ready, waited %u secs)",
            (unsigned int)(ioloop_time - client->created));

    if (client->auth_attempts == 0) {
        return t_strdup_printf("(no auth attempts in %u secs)",
            (unsigned int)(ioloop_time - client->created));
    }

    /* some auth attempts without SSL/TLS */
    if (client->set->auth_ssl_require_client_cert &&
        client->ssl_proxy == NULL)
        return "(cert required, client didn't start TLS)";

    if (client->auth_waiting && client->auth_attempts == 1) {
        return t_strdup_printf("(client didn't finish SASL auth, "
                       "waited %u secs)", auth_secs);
    }
    if (client->auth_request != NULL && client->auth_attempts == 1) {
        return t_strdup_printf("(disconnected while authenticating, "
                       "waited %u secs)", auth_secs);
    }
    if (client->authenticating && client->auth_attempts == 1) {
        return t_strdup_printf("(disconnected while finishing login, "
                       "waited %u secs)", auth_secs);
    }
    if (client->auth_try_aborted && client->auth_attempts == 1)
        return "(aborted authentication)";
    if (client->auth_process_comm_fail)
        return "(auth process communication failure)";

    if (client->proxy_auth_failed)
        return "(proxy dest auth failed)";
    if (client->auth_successes > 0) {
        return t_strdup_printf("(internal failure, %u successful auths)",
                       client->auth_successes);
    }

    switch (client->last_auth_fail) {
    case CLIENT_AUTH_FAIL_CODE_AUTHZFAILED:
        return t_strdup_printf(
            "(authorization failed, %u attempts in %u secs)",
            client->auth_attempts, auth_secs);
    case CLIENT_AUTH_FAIL_CODE_TEMPFAIL:
        return "(auth service reported temporary failure)";
    case CLIENT_AUTH_FAIL_CODE_USER_DISABLED:
        return "(user disabled)";
    case CLIENT_AUTH_FAIL_CODE_PASS_EXPIRED:
        return "(password expired)";
    case CLIENT_AUTH_FAIL_CODE_LOGIN_DISABLED:
        return "(login disabled)";
    case CLIENT_AUTH_FAIL_CODE_MECH_INVALID:
        return "(tried to use unsupported auth mechanism)";
    case CLIENT_AUTH_FAIL_CODE_MECH_SSL_REQUIRED:
        return "(tried to use disallowed plaintext auth)";
    default:
        break;
    }

    return t_strdup_printf("(auth failed, %u attempts in %u secs)",
                   client->auth_attempts, auth_secs);
}

void client_notify_disconnect(struct client *client,
                  enum client_disconnect_reason reason,
                  const char *text)
{
    if (!client->notified_disconnect) {
        if (client->v.notify_disconnect != NULL)
            client->v.notify_disconnect(client, reason, text);
        client->notified_disconnect = TRUE;
    }
}

void client_notify_auth_ready(struct client *client)
{
    if (!client->notified_auth_ready) {
        if (client->v.notify_auth_ready != NULL)
            client->v.notify_auth_ready(client);
        client->notified_auth_ready = TRUE;
    }
}

void client_notify_status(struct client *client, bool bad, const char *text)
{
    if (client->v.notify_status != NULL)
        client->v.notify_status(client, bad, text);
}

void client_send_raw_data(struct client *client, const void *data, size_t size)
{
    ssize_t ret;

    ret = o_stream_send(client->output, data, size);
    if (ret < 0 || (size_t)ret != size) {
        /* either disconnection or buffer full. in either case we want
           this connection destroyed. however destroying it here might
           break things if client is still tried to be accessed without
           being referenced.. */
        i_stream_close(client->input);
    }
}

void client_send_raw(struct client *client, const char *data)
{
    client_send_raw_data(client, data, strlen(data));
}

bool client_read(struct client *client)
{
    switch (i_stream_read(client->input)) {
    case -2:
        /* buffer full */
        client_notify_disconnect(client,
            CLIENT_DISCONNECT_RESOURCE_CONSTRAINT,
            "Input buffer full, aborting");
        client_destroy(client, "Disconnected: Input buffer full");
        return FALSE;
    case -1:
        /* disconnected */
        client_destroy(client, "Disconnected");
        return FALSE;
    case 0:
        /* nothing new read */
        return TRUE;
    default:
        /* something was read */
        return TRUE;
    }
}

void client_input(struct client *client)
{
    client->v.input(client);
}