Permalink
Browse files

Updates/improvements for logging

Send program name (program_invocation_name from glibc) along with the
tag.

Along the way, restructure the fds/pids/tags arrays to be an array
of client structures in pseudo_server, and add the message type
to the set of things logged -- logging that a message was a ping is
more useful than appending the text "ping" to it.  Add support
for type and program to pseudolog.

Add deletion to pseudolog.

Handle usage message formatting when there's an odd number of known
specifiers for pseudolog.

Conflicts:

	ChangeLog.txt
	pseudo_server.c
  • Loading branch information...
wr-seebs committed Apr 27, 2010
1 parent 4038d05 commit 2cc5cc8fb02ce787753f2b3903864c7e1b98bd4d
Showing with 322 additions and 148 deletions.
  1. +7 −7 pseudo.c
  2. +2 −2 pseudo.h
  3. +13 −6 pseudo_client.c
  4. +83 −27 pseudo_db.c
  5. +4 −2 pseudo_db.h
  6. +4 −0 pseudo_ipc.h
  7. +102 −85 pseudo_server.c
  8. +1 −1 pseudo_server.h
  9. +34 −1 pseudo_table.c
  10. +32 −8 pseudolog.1
  11. +40 −9 pseudolog.c
View
@@ -45,7 +45,7 @@ long opt_p = 0;
char *opt_r = NULL;
int opt_S = 0;
-static int pseudo_op(pseudo_msg_t *msg, const char *tag);
+static int pseudo_op(pseudo_msg_t *msg, const char *program, const char *tag);
void
usage(int status) {
@@ -273,7 +273,7 @@ main(int argc, char *argv[]) {
* sanity checks, then implements the fairly small DB changes required.
*/
int
-pseudo_op(pseudo_msg_t *msg, const char *tag) {
+pseudo_op(pseudo_msg_t *msg, const char *program, const char *tag) {
pseudo_msg_t msg_header;
pseudo_msg_t by_path = { .op = 0 }, by_ino = { .op = 0 };
pseudo_msg_t db_header;
@@ -678,27 +678,27 @@ pseudo_op(pseudo_msg_t *msg, const char *tag) {
free(path_by_ino);
pseudo_debug(2, "completed %s.\n", pseudo_op_name(msg->op));
if (opt_l)
- pdb_log_msg(SEVERITY_INFO, msg, tag, NULL);
+ pdb_log_msg(SEVERITY_INFO, msg, program, tag, NULL);
return 0;
}
/* SHUTDOWN does not get this far, it's handled in pseudo_server.c */
int
-pseudo_server_response(pseudo_msg_t *msg, const char *tag) {
+pseudo_server_response(pseudo_msg_t *msg, const char *program, const char *tag) {
switch (msg->type) {
case PSEUDO_MSG_PING:
msg->result = RESULT_SUCCEED;
if (opt_l)
- pdb_log_msg(SEVERITY_INFO, msg, tag, "ping");
+ pdb_log_msg(SEVERITY_INFO, msg, program, tag, NULL);
return 0;
break;
case PSEUDO_MSG_OP:
- return pseudo_op(msg, tag);
+ return pseudo_op(msg, program, tag);
break;
case PSEUDO_MSG_ACK: /* FALLTHROUGH */
case PSEUDO_MSG_NAK: /* FALLTHROUGH */
default:
- pdb_log_msg(SEVERITY_WARN, msg, tag, "invalid message");
+ pdb_log_msg(SEVERITY_WARN, msg, program, tag, "invalid message");
return 1;
}
}
View
@@ -99,8 +99,8 @@ typedef enum pseudo_query_field {
PSQF_CLIENT, PSQF_DEV, PSQF_FD, PSQF_FTYPE,
PSQF_GID, PSQF_ID, PSQF_INODE, PSQF_MODE,
PSQF_OP, PSQF_ORDER, PSQF_PATH, PSQF_PERM,
- PSQF_RESULT, PSQF_SEVERITY, PSQF_STAMP, PSQF_TAG,
- PSQF_TEXT, PSQF_UID,
+ PSQF_PROGRAM, PSQF_RESULT, PSQF_SEVERITY, PSQF_STAMP,
+ PSQF_TAG, PSQF_TEXT, PSQF_TYPE, PSQF_UID,
PSQF_MAX
} pseudo_query_field_t;
extern char *pseudo_query_field_name(pseudo_query_field_t id);
View
@@ -37,6 +37,9 @@
#include "pseudo_ipc.h"
#include "pseudo_client.h"
+/* GNU extension */
+extern char *program_invocation_name;
+
static char *base_path(int dirfd, const char *path, int leave_last);
static int connect_fd = -1;
@@ -465,20 +468,24 @@ static int
client_ping(void) {
pseudo_msg_t ping;
pseudo_msg_t *ack;
+ char tagbuf[pseudo_path_max()];
char *tag = getenv("PSEUDO_TAG");
ping.type = PSEUDO_MSG_PING;
ping.op = OP_NONE;
- if (tag) {
- ping.pathlen = strlen(tag);
- } else {
- ping.pathlen = 0;
- }
+
+ if (!tag)
+ tag = "";
+
+ ping.pathlen = snprintf(tagbuf, sizeof(tagbuf), "%s%c%s",
+ program_invocation_name ? program_invocation_name : "<unknown>",
+ 0,
+ tag);
ping.client = getpid();
ping.result = 0;
errno = 0;
pseudo_debug(4, "sending ping\n");
- if (pseudo_msg_send(connect_fd, &ping, ping.pathlen, tag)) {
+ if (pseudo_msg_send(connect_fd, &ping, ping.pathlen, tagbuf)) {
pseudo_debug(3, "error pinging server: %s\n", strerror(errno));
return 1;
}
View
@@ -223,6 +223,10 @@ static struct sql_migration {
{ "ALTER TABLE logs ADD gid INTEGER;" },
/* track access types (read/write, etc) */
{ "ALTER TABLE logs ADD access INTEGER;" },
+ /* client program/path */
+ { "ALTER TABLE logs ADD program VARCHAR;" },
+ /* message type (ping, op) */
+ { "ALTER TABLE logs ADD type INTEGER;" },
{ NULL },
};
@@ -595,6 +599,10 @@ pdb_log_traits(pseudo_query_t *traits) {
case PSQF_PERM:
e->mode |= (trait->data.ivalue & ~(S_IFMT) & 0177777);
break;
+ case PSQF_PROGRAM:
+ e->program = trait->data.svalue ?
+ strdup(trait->data.svalue) : NULL;
+ break;
case PSQF_RESULT:
e->result = trait->data.ivalue;
break;
@@ -612,6 +620,9 @@ pdb_log_traits(pseudo_query_t *traits) {
e->text = trait->data.svalue ?
strdup(trait->data.svalue) : NULL;
break;
+ case PSQF_TYPE:
+ e->type = trait->data.ivalue;
+ break;
case PSQF_UID:
e->uid = trait->data.ivalue;
break;
@@ -634,9 +645,9 @@ pdb_log_traits(pseudo_query_t *traits) {
int
pdb_log_entry(log_entry *e) {
char *sql = "INSERT INTO logs "
- "(stamp, op, access, client, dev, gid, ino, mode, path, result, severity, text, tag, uid)"
+ "(stamp, op, access, client, dev, gid, ino, mode, path, result, severity, text, program, tag, type, uid)"
" VALUES "
- "(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?);";
+ "(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?);";
static sqlite3_stmt *insert;
int field;
int rc;
@@ -680,11 +691,17 @@ pdb_log_entry(log_entry *e) {
} else {
sqlite3_bind_null(insert, field++);
}
+ if (e->program) {
+ sqlite3_bind_text(insert, field++, e->program, -1, SQLITE_STATIC);
+ } else {
+ sqlite3_bind_null(insert, field++);
+ }
if (e->tag) {
sqlite3_bind_text(insert, field++, e->tag, -1, SQLITE_STATIC);
} else {
sqlite3_bind_null(insert, field++);
}
+ sqlite3_bind_int(insert, field++, e->type);
sqlite3_bind_int(insert, field++, e->uid);
} else {
sqlite3_bind_int(insert, field++, (unsigned long) time(NULL));
@@ -700,6 +717,8 @@ pdb_log_entry(log_entry *e) {
sqlite3_bind_int(insert, field++, 0);
sqlite3_bind_null(insert, field++);
sqlite3_bind_null(insert, field++);
+ sqlite3_bind_null(insert, field++);
+ sqlite3_bind_int(insert, field++, 0);
sqlite3_bind_int(insert, field++, 0);
}
@@ -713,11 +732,11 @@ pdb_log_entry(log_entry *e) {
}
/* create a log from a given message, with tag and text */
int
-pdb_log_msg(sev_id_t severity, pseudo_msg_t *msg, const char *tag, const char *text, ...) {
+pdb_log_msg(sev_id_t severity, pseudo_msg_t *msg, const char *program, const char *tag, const char *text, ...) {
char *sql = "INSERT INTO logs "
- "(stamp, op, access, client, dev, gid, ino, mode, path, result, uid, severity, text, tag)"
+ "(stamp, op, access, client, dev, gid, ino, mode, path, result, uid, severity, text, program, tag, type)"
" VALUES "
- "(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?);";
+ "(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?);";
static sqlite3_stmt *insert;
char buffer[8192];
int field;
@@ -779,11 +798,21 @@ pdb_log_msg(sev_id_t severity, pseudo_msg_t *msg, const char *tag, const char *t
} else {
sqlite3_bind_null(insert, field++);
}
+ if (program) {
+ sqlite3_bind_text(insert, field++, program, -1, SQLITE_STATIC);
+ } else {
+ sqlite3_bind_null(insert, field++);
+ }
if (tag) {
sqlite3_bind_text(insert, field++, tag, -1, SQLITE_STATIC);
} else {
sqlite3_bind_null(insert, field++);
}
+ if (msg) {
+ sqlite3_bind_int(insert, field++, msg->type);
+ } else {
+ sqlite3_bind_int(insert, field++, 0);
+ }
rc = sqlite3_step(insert);
if (rc != SQLITE_DONE) {
@@ -844,7 +873,7 @@ frag(buffer *b, char *fmt, ...) {
}
log_history
-pdb_history(pseudo_query_t *traits, unsigned long fields, int distinct) {
+pdb_history(pseudo_query_t *traits, unsigned long fields, int unique, int do_delete) {
log_history h = NULL;
pseudo_query_t *trait;
sqlite3_stmt *select;
@@ -856,7 +885,6 @@ pdb_history(pseudo_query_t *traits, unsigned long fields, int distinct) {
pseudo_query_field_t f;
static buffer *sql;
- /* this column arrangement is used by pdb_history_entry() */
if (!sql) {
sql = malloc(sizeof *sql);
if (!sql) {
@@ -872,23 +900,28 @@ pdb_history(pseudo_query_t *traits, unsigned long fields, int distinct) {
}
}
sql->tail = sql->data;
- frag(sql, "SELECT ");
+ if (do_delete)
+ frag(sql, "DELETE ");
+ else
+ frag(sql, "SELECT ");
if (!log_db && get_db(&log_db)) {
pseudo_diag("database error.\n");
return 0;
}
- if (distinct)
- frag(sql, "DISTINCT ");
+ if (!do_delete) {
+ if (unique)
+ frag(sql, "DISTINCT ");
- done_any = 0;
- for (f = PSQF_NONE + 1; f < PSQF_MAX; ++f) {
- if (fields & (1 << f)) {
- frag(sql, "%s%s",
- done_any ? ", " : "",
- pseudo_query_field_name(f));
- done_any = 1;
+ done_any = 0;
+ for (f = PSQF_NONE + 1; f < PSQF_MAX; ++f) {
+ if (fields & (1 << f)) {
+ frag(sql, "%s%s",
+ done_any ? ", " : "",
+ pseudo_query_field_name(f));
+ done_any = 1;
+ }
}
}
@@ -905,6 +938,7 @@ pdb_history(pseudo_query_t *traits, unsigned long fields, int distinct) {
}
}
switch (trait->field) {
+ case PSQF_PROGRAM: /* FALLTHROUGH */
case PSQF_TEXT: /* FALLTHROUGH */
case PSQF_TAG: /* FALLTHROUGH */
case PSQF_PATH:
@@ -996,13 +1030,14 @@ pdb_history(pseudo_query_t *traits, unsigned long fields, int distinct) {
break;
}
}
- frag(sql, "ORDER BY %s %s;", order_by, order_dir);
+ if (!do_delete)
+ frag(sql, "ORDER BY %s %s;", order_by, order_dir);
pseudo_debug(1, "created SQL: <%s>\n", sql->data);
/* second, prepare it */
rc = sqlite3_prepare_v2(log_db, sql->data, strlen(sql->data), &select, NULL);
if (rc) {
- dberr(log_db, "couldn't prepare SELECT statement");
+ dberr(log_db, "couldn't prepare %s statement", do_delete ? "DELETE" : "SELECT");
return 0;
}
@@ -1013,6 +1048,7 @@ pdb_history(pseudo_query_t *traits, unsigned long fields, int distinct) {
case PSQF_ORDER:
/* this just creates a hunk of SQL above */
break;
+ case PSQF_PROGRAM: /* FALLTHROUGH */
case PSQF_PATH: /* FALLTHROUGH */
case PSQF_TAG: /* FALLTHROUGH */
case PSQF_TEXT:
@@ -1032,6 +1068,7 @@ pdb_history(pseudo_query_t *traits, unsigned long fields, int distinct) {
case PSQF_RESULT: /* FALLTHROUGH */
case PSQF_SEVERITY: /* FALLTHROUGH */
case PSQF_STAMP: /* FALLTHROUGH */
+ case PSQF_TYPE: /* FALLTHROUGH */
case PSQF_UID: /* FALLTHROUGH */
sqlite3_bind_int(select, field++, trait->data.ivalue);
break;
@@ -1042,6 +1079,16 @@ pdb_history(pseudo_query_t *traits, unsigned long fields, int distinct) {
}
}
+ if (do_delete) {
+ /* no need to return it, so... */
+ int rc = sqlite3_step(select);
+ if (rc != SQLITE_DONE) {
+ dberr(log_db, "deletion failed");
+ }
+ sqlite3_finalize(select);
+ return 0;
+ }
+
/* fourth, return the statement, now ready to be stepped through */
h = malloc(sizeof(*h));
if (h) {
@@ -1114,6 +1161,11 @@ pdb_history_entry(log_history h) {
if (s)
l->path = strdup((char *) s);
break;
+ case PSQF_PROGRAM:
+ s = sqlite3_column_text(h->stmt, column++);
+ if (s)
+ l->program = strdup((char *) s);
+ break;
case PSQF_RESULT:
l->result = sqlite3_column_int64(h->stmt, column++);
break;
@@ -1133,6 +1185,9 @@ pdb_history_entry(log_history h) {
if (s)
l->text = strdup((char *) s);
break;
+ case PSQF_TYPE:
+ l->type = sqlite3_column_int64(h->stmt, column++);
+ break;
case PSQF_UID:
l->uid = sqlite3_column_int64(h->stmt, column++);
break;
@@ -1170,6 +1225,7 @@ log_entry_free(log_entry *e) {
return;
free(e->text);
free(e->path);
+ free(e->program);
free(e->tag);
free(e);
}
@@ -1228,16 +1284,16 @@ pdb_link_file(pseudo_msg_t *msg) {
/* pdb_unlink_file_dev: Delete every instance of a dev/inode pair. */
int
pdb_unlink_file_dev(pseudo_msg_t *msg) {
- static sqlite3_stmt *delete;
+ static sqlite3_stmt *sql_delete;
int rc;
char *sql = "DELETE FROM files WHERE dev = ? AND ino = ?;";
if (!file_db && get_db(&file_db)) {
pseudo_diag("database error.\n");
return 0;
}
- if (!delete) {
- rc = sqlite3_prepare_v2(file_db, sql, strlen(sql), &delete, NULL);
+ if (!sql_delete) {
+ rc = sqlite3_prepare_v2(file_db, sql, strlen(sql), &sql_delete, NULL);
if (rc) {
dberr(file_db, "couldn't prepare DELETE statement");
return 1;
@@ -1246,14 +1302,14 @@ pdb_unlink_file_dev(pseudo_msg_t *msg) {
if (!msg) {
return 1;
}
- sqlite3_bind_int(delete, 1, msg->dev);
- sqlite3_bind_int(delete, 2, msg->ino);
- rc = sqlite3_step(delete);
+ sqlite3_bind_int(sql_delete, 1, msg->dev);
+ sqlite3_bind_int(sql_delete, 2, msg->ino);
+ rc = sqlite3_step(sql_delete);
if (rc != SQLITE_DONE) {
dberr(file_db, "delete by inode may have failed");
}
- sqlite3_reset(delete);
- sqlite3_clear_bindings(delete);
+ sqlite3_reset(sql_delete);
+ sqlite3_clear_bindings(sql_delete);
return rc != SQLITE_DONE;
}
Oops, something went wrong.

0 comments on commit 2cc5cc8

Please sign in to comment.