nhyatt/putty-source
1
0
Fork 0
mirror of https://git.tartarus.org/simon/putty.git synced 2025-01-09 09:27:59 +00:00
Code Issues Projects Releases Wiki Activity
3214563d8e
putty-source/logging.c
Simon Tatham 3214563d8e Convert a lot of 'int' variables to 'bool'. 
My normal habit these days, in new code, is to treat int and bool as
_almost_ completely separate types. I'm still willing to use C's
implicit test for zero on an integer (e.g. 'if (!blob.len)' is fine,
no need to spell it out as blob.len != 0), but generally, if a
variable is going to be conceptually a boolean, I like to declare it
bool and assign to it using 'true' or 'false' rather than 0 or 1.

PuTTY is an exception, because it predates the C99 bool, and I've
stuck to its existing coding style even when adding new code to it.
But it's been annoying me more and more, so now that I've decided C99
bool is an acceptable thing to require from our toolchain in the first
place, here's a quite thorough trawl through the source doing
'boolification'. Many variables and function parameters are now typed
as bool rather than int; many assignments of 0 or 1 to those variables
are now spelled 'true' or 'false'.

I managed this thorough conversion with the help of a custom clang
plugin that I wrote to trawl the AST and apply heuristics to point out
where things might want changing. So I've even managed to do a decent
job on parts of the code I haven't looked at in years!

To make the plugin's work easier, I pushed platform front ends
generally in the direction of using standard 'bool' in preference to
platform-specific boolean types like Windows BOOL or GTK's gboolean;
I've left the platform booleans in places they _have_ to be for the
platform APIs to work right, but variables only used by my own code
have been converted wherever I found them.

In a few places there are int values that look very like booleans in
_most_ of the places they're used, but have a rarely-used third value,
or a distinction between different nonzero values that most users
don't care about. In these cases, I've _removed_ uses of 'true' and
'false' for the return values, to emphasise that there's something
more subtle going on than a simple boolean answer:
 - the 'multisel' field in dialog.h's list box structure, for which
   the GTK front end in particular recognises a difference between 1
   and 2 but nearly everything else treats as boolean
 - the 'urgent' parameter to plug_receive, where 1 vs 2 tells you
   something about the specific location of the urgent pointer, but
   most clients only care about 0 vs 'something nonzero'
 - the return value of wc_match, where -1 indicates a syntax error in
   the wildcard.
 - the return values from SSH-1 RSA-key loading functions, which use
   -1 for 'wrong passphrase' and 0 for all other failures (so any
   caller which already knows it's not loading an _encrypted private_
   key can treat them as boolean)
 - term->esc_query, and the 'query' parameter in toggle_mode in
   terminal.c, which _usually_ hold 0 for ESC[123h or 1 for ESC[?123h,
   but can also hold -1 for some other intervening character that we
   don't support.

In a few places there's an integer that I haven't turned into a bool
even though it really _can_ only take values 0 or 1 (and, as above,
tried to make the call sites consistent in not calling those values
true and false), on the grounds that I thought it would make it more
confusing to imply that the 0 value was in some sense 'negative' or
bad and the 1 positive or good:
 - the return value of plug_accepting uses the POSIXish convention of
   0=success and nonzero=error; I think if I made it bool then I'd
   also want to reverse its sense, and that's a job for a separate
   piece of work.
 - the 'screen' parameter to lineptr() in terminal.c, where 0 and 1
   represent the default and alternate screens. There's no obvious
   reason why one of those should be considered 'true' or 'positive'
   or 'success' - they're just indices - so I've left it as int.

ssh_scp_recv had particularly confusing semantics for its previous int
return value: its call sites used '<= 0' to check for error, but it
never actually returned a negative number, just 0 or 1. Now the
function and its call sites agree that it's a bool.

In a couple of places I've renamed variables called 'ret', because I
don't like that name any more - it's unclear whether it means the
return value (in preparation) for the _containing_ function or the
return value received from a subroutine call, and occasionally I've
accidentally used the same variable for both and introduced a bug. So
where one of those got in my way, I've renamed it to 'toret' or 'retd'
(the latter short for 'returned') in line with my usual modern
practice, but I haven't done a thorough job of finding all of them.

Finally, one amusing side effect of doing this is that I've had to
separate quite a few chained assignments. It used to be perfectly fine
to write 'a = b = c = TRUE' when a,b,c were int and TRUE was just a
the 'true' defined by stdbool.h, that idiom provokes a warning from
gcc: 'suggest parentheses around assignment used as truth value'!
2018-11-03 13:45:00 +00:00

526 lines
14 KiB
C
Raw Blame History

/*
* Session logging.
*/
#include <stdio.h>
#include <stdlib.h>
#include <ctype.h>
#include <time.h>
#include <assert.h>
#include "putty.h"
/* log session to file stuff ... */
struct LogContext {
FILE *lgfp;
enum { L_CLOSED, L_OPENING, L_OPEN, L_ERROR } state;
bufchain queue;
Filename *currlogfilename;
LogPolicy *lp;
Conf *conf;
int logtype; /* cached out of conf */
};
static Filename *xlatlognam(Filename *s, char *hostname, int port,
struct tm *tm);
/*
* Internal wrapper function which must be called for _all_ output
* to the log file. It takes care of opening the log file if it
* isn't open, buffering data if it's in the process of being
* opened asynchronously, etc.
*/
static void logwrite(LogContext *ctx, void *data, int len)
{
/*
* In state L_CLOSED, we call logfopen, which will set the state
* to one of L_OPENING, L_OPEN or L_ERROR. Hence we process all of
* those three _after_ processing L_CLOSED.
*/
if (ctx->state == L_CLOSED)
logfopen(ctx);
if (ctx->state == L_OPENING) {
bufchain_add(&ctx->queue, data, len);
} else if (ctx->state == L_OPEN) {
assert(ctx->lgfp);
if (fwrite(data, 1, len, ctx->lgfp) < (size_t)len) {
logfclose(ctx);
ctx->state = L_ERROR;
lp_eventlog(ctx->lp, "Disabled writing session log "
"due to error while writing");
}
} /* else L_ERROR, so ignore the write */
}
/*
* Convenience wrapper on logwrite() which printf-formats the
* string.
*/
static void logprintf(LogContext *ctx, const char *fmt, ...)
{
va_list ap;
char *data;
va_start(ap, fmt);
data = dupvprintf(fmt, ap);
va_end(ap);
logwrite(ctx, data, strlen(data));
sfree(data);
}
/*
* Flush any open log file.
*/
void logflush(LogContext *ctx)
{
if (ctx->logtype > 0)
if (ctx->state == L_OPEN)
fflush(ctx->lgfp);
}
static void logfopen_callback(void *vctx, int mode)
{
LogContext *ctx = (LogContext *)vctx;
char buf[256], *event;
struct tm tm;
const char *fmode;
bool shout = false;
if (mode == 0) {
ctx->state = L_ERROR; /* disable logging */
} else {
fmode = (mode == 1 ? "ab" : "wb");
ctx->lgfp = f_open(ctx->currlogfilename, fmode, false);
if (ctx->lgfp) {
ctx->state = L_OPEN;
} else {
ctx->state = L_ERROR;
shout = true;
}
}
if (ctx->state == L_OPEN && conf_get_bool(ctx->conf, CONF_logheader)) {
/* Write header line into log file. */
tm = ltime();
strftime(buf, 24, "%Y.%m.%d %H:%M:%S", &tm);
logprintf(ctx, "=~=~=~=~=~=~=~=~=~=~=~= PuTTY log %s"
" =~=~=~=~=~=~=~=~=~=~=~=\r\n", buf);
}
event = dupprintf("%s session log (%s mode) to file: %s",
ctx->state == L_ERROR ?
(mode == 0 ? "Disabled writing" : "Error writing") :
(mode == 1 ? "Appending" : "Writing new"),
(ctx->logtype == LGTYP_ASCII ? "ASCII" :
ctx->logtype == LGTYP_DEBUG ? "raw" :
ctx->logtype == LGTYP_PACKETS ? "SSH packets" :
ctx->logtype == LGTYP_SSHRAW ? "SSH raw data" :
"unknown"),
filename_to_str(ctx->currlogfilename));
lp_eventlog(ctx->lp, event);
if (shout) {
/*
* If we failed to open the log file due to filesystem error
* (as opposed to user action such as clicking Cancel in the
* askappend box), we should log it more prominently.
*/
lp_logging_error(ctx->lp, event);
}
sfree(event);
/*
* Having either succeeded or failed in opening the log file,
* we should write any queued data out.
*/
assert(ctx->state != L_OPENING); /* make _sure_ it won't be requeued */
while (bufchain_size(&ctx->queue)) {
void *data;
int len;
bufchain_prefix(&ctx->queue, &data, &len);
logwrite(ctx, data, len);
bufchain_consume(&ctx->queue, len);
}
logflush(ctx);
}
/*
* Open the log file. Takes care of detecting an already-existing
* file and asking the user whether they want to append, overwrite
* or cancel logging.
*/
void logfopen(LogContext *ctx)
{
struct tm tm;
int mode;
/* Prevent repeat calls */
if (ctx->state != L_CLOSED)
return;
if (!ctx->logtype)
return;
tm = ltime();
/* substitute special codes in file name */
if (ctx->currlogfilename)
filename_free(ctx->currlogfilename);
ctx->currlogfilename =
xlatlognam(conf_get_filename(ctx->conf, CONF_logfilename),
conf_get_str(ctx->conf, CONF_host),
conf_get_int(ctx->conf, CONF_port), &tm);
if (open_for_write_would_lose_data(ctx->currlogfilename)) {
int logxfovr = conf_get_int(ctx->conf, CONF_logxfovr);
if (logxfovr != LGXF_ASK) {
mode = ((logxfovr == LGXF_OVR) ? 2 : 1);
} else
mode = lp_askappend(ctx->lp, ctx->currlogfilename,
logfopen_callback, ctx);
} else
mode = 2; /* create == overwrite */
if (mode < 0)
ctx->state = L_OPENING;
else
logfopen_callback(ctx, mode); /* open the file */
}
void logfclose(LogContext *ctx)
{
if (ctx->lgfp) {
fclose(ctx->lgfp);
ctx->lgfp = NULL;
}
ctx->state = L_CLOSED;
}
/*
* Log session traffic.
*/
void logtraffic(LogContext *ctx, unsigned char c, int logmode)
{
if (ctx->logtype > 0) {
if (ctx->logtype == logmode)
logwrite(ctx, &c, 1);
}
}
static void logevent_internal(LogContext *ctx, const char *event)
{
if (ctx->logtype == LGTYP_PACKETS || ctx->logtype == LGTYP_SSHRAW) {
logprintf(ctx, "Event Log: %s\r\n", event);
logflush(ctx);
}
lp_eventlog(ctx->lp, event);
}
void logevent(LogContext *ctx, const char *event)
{
if (!ctx)
return;
/*
* Replace newlines in Event Log messages with spaces. (Sometimes
* the same message string is reused for the Event Log and a GUI
* dialog box; newlines are sometimes appropriate in the latter,
* but never in the former.)
*/
if (strchr(event, '\n') || strchr(event, '\r')) {
char *dup = dupstr(event);
char *p = dup, *q = dup;
while (*p) {
if (*p == '\r' || *p == '\n') {
do {
p++;
} while (*p == '\r' || *p == '\n');
*q++ = ' ';
} else {
*q++ = *p++;
}
}
*q = '\0';
logevent_internal(ctx, dup);
sfree(dup);
} else {
logevent_internal(ctx, event);
}
}
void logevent_and_free(LogContext *ctx, char *event)
{
logevent(ctx, event);
sfree(event);
}
void logeventvf(LogContext *ctx, const char *fmt, va_list ap)
{
logevent_and_free(ctx, dupvprintf(fmt, ap));
}
void logeventf(LogContext *ctx, const char *fmt, ...)
{
va_list ap;
va_start(ap, fmt);
logeventvf(ctx, fmt, ap);
va_end(ap);
}
/*
* Log an SSH packet.
* If n_blanks != 0, blank or omit some parts.
* Set of blanking areas must be in increasing order.
*/
void log_packet(LogContext *ctx, int direction, int type,
const char *texttype, const void *data, int len,
int n_blanks, const struct logblank_t *blanks,
const unsigned long *seq,
unsigned downstream_id, const char *additional_log_text)
{
char dumpdata[80], smalldata[5];
int p = 0, b = 0, omitted = 0;
int output_pos = 0; /* NZ if pending output in dumpdata */
if (!(ctx->logtype == LGTYP_SSHRAW ||
(ctx->logtype == LGTYP_PACKETS && texttype)))
return;
/* Packet header. */
if (texttype) {
logprintf(ctx, "%s packet ",
direction == PKT_INCOMING ? "Incoming" : "Outgoing");
if (seq)
logprintf(ctx, "#0x%lx, ", *seq);
logprintf(ctx, "type %d / 0x%02x (%s)", type, type, texttype);
if (downstream_id) {
logprintf(ctx, " on behalf of downstream #%u", downstream_id);
if (additional_log_text)
logprintf(ctx, " (%s)", additional_log_text);
}
logprintf(ctx, "\r\n");
} else {
/*
* Raw data is logged with a timestamp, so that it's possible
* to determine whether a mysterious delay occurred at the
* client or server end. (Timestamping the raw data avoids
* cluttering the normal case of only logging decrypted SSH
* messages, and also adds conceptual rigour in the case where
* an SSH message arrives in several pieces.)
*/
char buf[256];
struct tm tm;
tm = ltime();
strftime(buf, 24, "%Y-%m-%d %H:%M:%S", &tm);
logprintf(ctx, "%s raw data at %s\r\n",
direction == PKT_INCOMING ? "Incoming" : "Outgoing",
buf);
}
/*
* Output a hex/ASCII dump of the packet body, blanking/omitting
* parts as specified.
*/
while (p < len) {
int blktype;
/* Move to a current entry in the blanking array. */
while ((b < n_blanks) &&
(p >= blanks[b].offset + blanks[b].len))
b++;
/* Work out what type of blanking to apply to
* this byte. */
blktype = PKTLOG_EMIT; /* default */
if ((b < n_blanks) &&
(p >= blanks[b].offset) &&
(p < blanks[b].offset + blanks[b].len))
blktype = blanks[b].type;
/* If we're about to stop omitting, it's time to say how
* much we omitted. */
if ((blktype != PKTLOG_OMIT) && omitted) {
logprintf(ctx, " (%d byte%s omitted)\r\n",
omitted, (omitted==1?"":"s"));
omitted = 0;
}
/* (Re-)initialise dumpdata as necessary
* (start of row, or if we've just stopped omitting) */
if (!output_pos && !omitted)
sprintf(dumpdata, " %08x%*s\r\n", p-(p%16), 1+3*16+2+16, "");
/* Deal with the current byte. */
if (blktype == PKTLOG_OMIT) {
omitted++;
} else {
int c;
if (blktype == PKTLOG_BLANK) {
c = 'X';
sprintf(smalldata, "XX");
} else { /* PKTLOG_EMIT */
c = ((unsigned char *)data)[p];
sprintf(smalldata, "%02x", c);
}
dumpdata[10+2+3*(p%16)] = smalldata[0];
dumpdata[10+2+3*(p%16)+1] = smalldata[1];
dumpdata[10+1+3*16+2+(p%16)] = (c >= 0x20 && c < 0x7F ? c : '.');
output_pos = (p%16) + 1;
}
p++;
/* Flush row if necessary */
if (((p % 16) == 0) || (p == len) || omitted) {
if (output_pos) {
strcpy(dumpdata + 10+1+3*16+2+output_pos, "\r\n");
logwrite(ctx, dumpdata, strlen(dumpdata));
output_pos = 0;
}
}
}
/* Tidy up */
if (omitted)
logprintf(ctx, " (%d byte%s omitted)\r\n",
omitted, (omitted==1?"":"s"));
logflush(ctx);
}
LogContext *log_init(LogPolicy *lp, Conf *conf)
{
LogContext *ctx = snew(LogContext);
ctx->lgfp = NULL;
ctx->state = L_CLOSED;
ctx->lp = lp;
ctx->conf = conf_copy(conf);
ctx->logtype = conf_get_int(ctx->conf, CONF_logtype);
ctx->currlogfilename = NULL;
bufchain_init(&ctx->queue);
return ctx;
}
void log_free(LogContext *ctx)
{
logfclose(ctx);
bufchain_clear(&ctx->queue);
if (ctx->currlogfilename)
filename_free(ctx->currlogfilename);
conf_free(ctx->conf);
sfree(ctx);
}
void log_reconfig(LogContext *ctx, Conf *conf)
{
bool reset_logging;
if (!filename_equal(conf_get_filename(ctx->conf, CONF_logfilename),
conf_get_filename(conf, CONF_logfilename)) ||
conf_get_int(ctx->conf, CONF_logtype) !=
conf_get_int(conf, CONF_logtype))
reset_logging = true;
else
reset_logging = false;
if (reset_logging)
logfclose(ctx);
conf_free(ctx->conf);
ctx->conf = conf_copy(conf);
ctx->logtype = conf_get_int(ctx->conf, CONF_logtype);
if (reset_logging)
logfopen(ctx);
}
/*
* translate format codes into time/date strings
* and insert them into log file name
*
* "&Y":YYYY "&m":MM "&d":DD "&T":hhmmss "&h":<hostname> "&&":&
*/
static Filename *xlatlognam(Filename *src, char *hostname, int port,
struct tm *tm)
{
char buf[32], *bufp;
int size;
char *buffer;
int buflen, bufsize;
const char *s;
Filename *ret;
bufsize = FILENAME_MAX;
buffer = snewn(bufsize, char);
buflen = 0;
s = filename_to_str(src);
while (*s) {
bool sanitise = false;
/* Let (bufp, len) be the string to append. */
bufp = buf; /* don't usually override this */
if (*s == '&') {
char c;
s++;
size = 0;
if (*s) switch (c = *s++, tolower((unsigned char)c)) {
case 'y':
size = strftime(buf, sizeof(buf), "%Y", tm);
break;
case 'm':
size = strftime(buf, sizeof(buf), "%m", tm);
break;
case 'd':
size = strftime(buf, sizeof(buf), "%d", tm);
break;
case 't':
size = strftime(buf, sizeof(buf), "%H%M%S", tm);
break;
case 'h':
bufp = hostname;
size = strlen(bufp);
break;
case 'p':
size = sprintf(buf, "%d", port);
break;
default:
buf[0] = '&';
size = 1;
if (c != '&')
buf[size++] = c;
}
/* Never allow path separators - or any other illegal
* filename character - to come out of any of these
* auto-format directives. E.g. 'hostname' can contain
* colons, if it's an IPv6 address, and colons aren't
* legal in filenames on Windows. */
sanitise = true;
} else {
buf[0] = *s++;
size = 1;
}
if (bufsize <= buflen + size) {
bufsize = (buflen + size) * 5 / 4 + 512;
buffer = sresize(buffer, bufsize, char);
}
while (size-- > 0) {
char c = *bufp++;
if (sanitise)
c = filename_char_sanitise(c);
buffer[buflen++] = c;
}
}
buffer[buflen] = '\0';
ret = filename_from_str(buffer);
sfree(buffer);
return ret;
}
Reference in New Issue View Git Blame Copy Permalink