lowlevel.cpp

Go to the documentation of this file.

/*
 * Crossfire -- cooperative multi-player graphical RPG and adventure game
 *
 * Copyright (c) 1999-2014 Mark Wedel and the Crossfire Development Team
 * Copyright (c) 1992 Frank Tore Johansen
 *
 * Crossfire is free software and comes with ABSOLUTELY NO WARRANTY. You are
 * welcome to redistribute it under certain conditions. For details, please
 * see COPYING and LICENSE.
 *
 * The authors can be reached via e-mail at <crossfire@metalforge.org>.
 */

#include "global.h"

#include <assert.h>
#include <errno.h>
#include <stdarg.h>
#include <stdlib.h>
#include <stdio.h>
#include <string.h>

#include "output_file.h"
#include "shared/newclient.h"
#include "sproto.h"
#include "stats.h"

#ifdef WIN32
#include <winsock2.h>
#endif

/***********************************************************************
 *
 * SockList functions/utilities
 *
 **********************************************************************/

void SockList_Init(SockList *sl) {
    SockList_Reset(sl);
}

void SockList_Term(SockList *sl) {
    (void)sl;
}

void SockList_Reset(SockList *sl) {
    sl->len = 2;
}

void SockList_ResetRead(SockList *sl) {
    sl->len = 0;
}

static void SockList_Ensure(const SockList *sl, size_t size) {
    if (sl->len+size > sizeof(sl->buf)) {
        fatal(OUT_OF_MEMORY);
    }
}

void SockList_AddChar(SockList *sl, unsigned char data) {
    SockList_Ensure(sl, 1);
    sl->buf[sl->len++] = data;
}

void SockList_AddShort(SockList *sl, uint16_t data) {
    SockList_Ensure(sl, 2);
    sl->buf[sl->len++] = (data>>8)&0xff;
    sl->buf[sl->len++] = data&0xff;
}

void SockList_AddInt(SockList *sl, uint32_t data) {
    SockList_Ensure(sl, 4);
    sl->buf[sl->len++] = (data>>24)&0xff;
    sl->buf[sl->len++] = (data>>16)&0xff;
    sl->buf[sl->len++] = (data>>8)&0xff;
    sl->buf[sl->len++] = data&0xff;
}

void SockList_AddInt64(SockList *sl, uint64_t data) {
    SockList_Ensure(sl, 8);
    sl->buf[sl->len++] = (char)((data>>56)&0xff);
    sl->buf[sl->len++] = (char)((data>>48)&0xff);
    sl->buf[sl->len++] = (char)((data>>40)&0xff);
    sl->buf[sl->len++] = (char)((data>>32)&0xff);
    sl->buf[sl->len++] = (char)((data>>24)&0xff);
    sl->buf[sl->len++] = (char)((data>>16)&0xff);
    sl->buf[sl->len++] = (char)((data>>8)&0xff);
    sl->buf[sl->len++] = (char)(data&0xff);
}

void SockList_AddString(SockList *sl, const char *data) {
    SockList_AddData(sl, data, strlen(data));
}

void SockList_AddData(SockList *sl, const void *data, size_t len) {
    SockList_Ensure(sl, len);
    memcpy(sl->buf+sl->len, data, len);
    sl->len += len;
}

void SockList_AddLen8Data(SockList *sl, const void *data, size_t len) {
    assert(len <= 255);
    SockList_AddChar(sl, len);
    SockList_AddData(sl, data, len);
}

void SockList_AddLen16Data(SockList *sl, const void *data, size_t len) {
    assert(len <= 65535);
    SockList_AddShort(sl, len);
    SockList_AddData(sl, data, len);
}

void SockList_AddPrintf(SockList *sl, const char *format, ...) {
    size_t size;
    int n;
    va_list arg;

    size = sizeof(sl->buf)-sl->len;

    va_start(arg, format);
    n = vsnprintf((char *)sl->buf+sl->len, size, format, arg);
    va_end(arg);

    if (n <= -1 || (size_t)n >= size) {
        LOG(llevError, "Truncating message exceeding MAXSOCKBUF. The message was:\n%s\n", sl->buf+sl->len);
    }
    sl->len += (size_t)n;
}

void SockList_AddStringBuffer(SockList *sl, StringBuffer *sb) {
    char *p;

    p = stringbuffer_finish(sb);
    SockList_AddString(sl, p);
    free(p);
}

void SockList_NullTerminate(SockList *sl) {
    SockList_Ensure(sl, 1);
    sl->buf[sl->len] = '\0';
}

size_t SockList_Avail(const SockList *sl) {
    return sizeof(sl->buf)-sl->len;
}

int GetInt_String(const unsigned char *data) {
    return ((data[0]<<24)+(data[1]<<16)+(data[2]<<8)+data[3]);
}

short GetShort_String(const unsigned char *data) {
    return ((data[0]<<8)+data[1]);
}

/******************************************************************************
 *
 * Start of read routines.
 *
 ******************************************************************************/

int SockList_ReadPacket(int fd, SockList *sl, int len) {
    int stat, toread;

    /* We already have a partial packet */
    if (sl->len < 2) {
#ifdef WIN32 /* ***WIN32 SockList_ReadPacket: change read() to recv() */

        stat = recv(fd, reinterpret_cast<char *>(sl->buf+sl->len), 2-sl->len, 0);

#else
        do {
            stat = read(fd, sl->buf+sl->len, 2-sl->len);
        } while ((stat == -1) && (errno == EINTR));
#endif
        if (stat < 0) {
            /* In non blocking mode, EAGAIN is set when there is no
             * data available.
             */
#ifdef WIN32 /* ***WIN32 SockList_ReadPacket: error handling for win32 */
            if ((stat == -1) && WSAGetLastError() != WSAEWOULDBLOCK) {
                if (WSAGetLastError() == WSAECONNRESET)
                    LOG(llevDebug, "Connection closed by client\n");
                else {
                    LOG(llevDebug, "ReadPacket got error %d, returning -1\n", WSAGetLastError());
                }
                return -1; /* kick this user! */
            }
#else
            if (errno == ECONNRESET) {
                LOG(llevDebug, "ReadPacket got error %s, returning -1\n", strerror(errno));
                return -1;
            }
            if (errno != EAGAIN && errno != EWOULDBLOCK) {
                LOG(llevDebug, "ReadPacket got error %s, returning 0\n", strerror(errno));
            }
#endif
            return 0; /*Error */
        }
        if (stat == 0)
            return -1;
        sl->len += stat;
#ifdef CS_LOGSTATS
        cst_tot.ibytes += stat;
        cst_lst.ibytes += stat;
#endif
        if (stat < 2)
            return 0; /* Still don't have a full packet */
    }
    /* Figure out how much more data we need to read.  Add 2 from the
     * end of this - size header information is not included.
     */
    toread = 2+(sl->buf[0]<<8)+sl->buf[1]-sl->len;
    if ((toread+(int)sl->len) >= len) {
        LOG(llevError, "SockList_ReadPacket: Want to read more bytes than will fit in buffer (%lu>=%lu).\n", (unsigned long)toread+sl->len, (unsigned long)len);
        /* Quick hack in case for 'oldsocketmode' input.  If we are
         * closing the socket anyways, then reading this extra 100 bytes
         * shouldn't hurt.
         */
#ifdef WIN32 /* ***win32 SockList_ReadPacket: change read() to recv() */
        stat = recv(fd, reinterpret_cast<char *>(sl->buf+2), 100, 0);
#else
        stat = read(fd, sl->buf+2, 100);
#endif /* end win32 */
        (void) stat; // Don't care how much we read; avoid complier warnings

        /* return error so the socket is closed */
        return -1;
    }
    do {
#ifdef WIN32 /* ***win32 SockList_ReadPacket: change read() to recv() */
        stat = recv(fd, reinterpret_cast<char *>(sl->buf+sl->len), toread, 0);
#else
        do {
            stat = read(fd, sl->buf+sl->len, toread);
        } while ((stat < 0) && (errno == EINTR));
#endif
        if (stat < 0) {
#ifdef WIN32 /* ***win32 SockList_ReadPacket: change error handling for win32 */
            if ((stat == -1) && WSAGetLastError() != WSAEWOULDBLOCK) {
                if (WSAGetLastError() == WSAECONNRESET)
                    LOG(llevDebug, "Connection closed by client\n");
                else {
                    LOG(llevDebug, "ReadPacket got error %d, returning -1\n", WSAGetLastError());
                }
                return -1; /* kick this user! */
            }
#else
            if (errno != EAGAIN && errno != EWOULDBLOCK) {
                LOG(llevDebug, "ReadPacket got error %s, returning 0\n", strerror(errno));
            }
#endif
            return 0; /*Error */
        }
        if (stat == 0)
            return -1;
        sl->len += stat;
#ifdef CS_LOGSTATS
        cst_tot.ibytes += stat;
        cst_lst.ibytes += stat;
#endif
        toread -= stat;
        if (toread == 0)
            return 1;
        if (toread < 0) {
            LOG(llevError, "SockList_ReadPacket: Read more bytes than desired.\n");
            return 1;
        }
    } while (toread > 0);
    return 0;
}

/*******************************************************************************
 *
 * Start of write related routines.
 *
 ******************************************************************************/

static void Write_To_Socket(socket_struct* ns, const unsigned char* buf, const int len) {
    if (ns->status == Ns_Dead || !buf) {
        LOG(llevDebug, "Write_To_Socket called with dead socket\n");
        return;
    }

#ifdef WIN32
    const int amt = send(ns->fd, reinterpret_cast<const char *>(buf), len, 0);
#else
    const int amt = send(ns->fd, buf, len, 0);
#endif
    if (amt < 0) { /* We got an error */
#ifdef WIN32       /* ***win32 Write_To_Socket: change error handling */
        if (amt == -1 && WSAGetLastError() != WSAEWOULDBLOCK) {
            LOG(llevInfo, "socket write failed: error code %d, disconnecting client\n",
                WSAGetLastError());
#else
        if (errno != EWOULDBLOCK) {
            LOG(llevInfo, "socket write failed: %s, disconnecting client\n",
                strerror(errno));
#endif
            ns->status = Ns_Dead;
            return;
        } else { /* EWOULDBLOCK */
            LOG(llevError,
                "Write_To_Socket: write would block; disconnecting. Try "
                "increasing SOCKETBUFSIZE.\n");
            ns->status = Ns_Dead;
            return;
        }
    } else if (amt != len) {
        LOG(llevError, "Write_To_Socket: write wrote less than requested; "
                       "disconnecting. Try increasing SOCKETBUFSIZE.\n");
        ns->status = Ns_Dead;
        return;
    }
#ifdef CS_LOGSTATS
    cst_tot.obytes += amt;
    cst_lst.obytes += amt;
#endif
}

void Send_With_Handling(socket_struct *ns, SockList *sl) {
    if (ns->status == Ns_Dead || sl == NULL)
        return;

    sl->buf[0] = ((sl->len-2)>>8)&0xFF;
    sl->buf[1] = (sl->len-2)&0xFF;
    Write_To_Socket(ns, sl->buf, sl->len);
}

/******************************************************************************
 *
 * statistics logging functions.
 *
 ******************************************************************************/

#ifdef CS_LOGSTATS

static int count_all_players() {
    int players = 0;
    player *pl;
    for (pl = first_player, players = 0; pl != NULL; pl = pl->next, players++);
    return players;
}

/* cst_tot is for the life of the server, cst_last is for the last series of
 * stats
 */
CS_Stats cst_tot, cst_lst;

void reset_stats(struct CS_Stats *stats) {
    memset(stats, 0, sizeof(CS_Stats));
    stats->time_start = time(NULL);
}

#define STAT(name, fmt, val) fprintf(f, "%s %" fmt "\n", name, val);

void write_cs_stats(void) {
    time_t now = time(NULL);
    int players_active = count_players();
    int players_total = count_all_players();

    // Old statistics format logged to the log file
    LOG(llevInfo, "STAT: players: %d active, %d total\n", players_active, players_total);
    LOG(llevInfo, "CSSTAT: %.16s tot %d %d %d %ld inc %d %d %d %ld\n",
        ctime(&now),
        cst_tot.ibytes, cst_tot.obytes, cst_tot.max_conn, (long)(now-cst_tot.time_start),
        cst_lst.ibytes, cst_lst.obytes, cst_lst.max_conn, (long)(now-cst_lst.time_start));

    // Write OpenMetrics-formatted server stats to a file. This can be exported
    // to tools like Prometheus to monitor the server.
    if (settings.stat_file) {
        OutputFile of;
        FILE *f = of_open(&of, settings.stat_file);
        if (f) {
            // ticks can be zero due to idling, so prevent divide by zero
            float ticks_over = cst_lst.ticks > 0 ? (float)cst_lst.ticks_overtime / cst_lst.ticks : 0;
            float avg = cst_lst.ticks > 0 ? (float)cst_lst.total_ticktime / cst_lst.ticks : 0; // in us

            STAT("players_total", "d", players_total);
            STAT("players_active", "d", players_active);
            STAT("ticks_overtime_percent", "f", ticks_over * 100);
            STAT("ticktime_max", "f", cst_lst.max_ticktime / 1e3); // in ms
            STAT("ticktime_avg", "f", avg / 1e3); // in ms
            STAT("bytes_in_total", "d", cst_tot.ibytes);
            STAT("bytes_out_total", "d", cst_tot.obytes);

            int maps_in_memory = 0;
            int maps_swapped = 0;
            for (mapstruct *m = first_map; m != NULL; m = m->next) {
                switch (m->in_memory) {
                case MAP_IN_MEMORY:
                    maps_in_memory++;
                    break;
                case MAP_SWAPPED:
                    maps_swapped++;
                    break;
                }
            }
            STAT("maps_in_memory", "d", maps_in_memory);
            STAT("maps_loaded_total", "d", maps_loaded_total);
            STAT("maps_saved_total", "d", maps_saved_total);
            STAT("maps_swapped", "d", maps_swapped);
            STAT("maps_swapped_total", "d", maps_swapped_total);

            STAT("objects_alloc", "d", nrofallocobjects);
            STAT("objects_free", "d", nroffreeobjects);
            STAT("objects_active", "d", object_count_active());

            STAT("events_total", "d", events_total);
            STAT("global_events_total", "d", global_events_total);

            STAT("log_total", "d", log_total);
            of_close(&of);
        } else {
            LOG(llevError, "Unable to write to stat file: %s\n", settings.stat_file);
        }
    }

    reset_stats(&cst_lst);
    cst_lst.max_conn = socket_info.allocated_sockets;
}
#endif