From b74ae0f24e31dd364e6d7a7602a3f3e0d8ae1830 Mon Sep 17 00:00:00 2001 From: kanoi Date: Sat, 21 Mar 2015 14:40:46 +1100 Subject: [PATCH 1/2] ckdb - console warning log out of order shares only if more than 1 second --- src/ckdb.h | 2 +- src/ckdb_dbio.c | 20 ++++++++++++++++---- 2 files changed, 17 insertions(+), 5 deletions(-) diff --git a/src/ckdb.h b/src/ckdb.h index a26a04ac..95a5791f 100644 --- a/src/ckdb.h +++ b/src/ckdb.h @@ -55,7 +55,7 @@ #define DB_VLOCK "1" #define DB_VERSION "1.0.0" -#define CKDB_VERSION DB_VERSION"-1.033" +#define CKDB_VERSION DB_VERSION"-1.034" #define WHERE_FFL " - from %s %s() line %d" #define WHERE_FFL_HERE __FILE__, __func__, __LINE__ diff --git a/src/ckdb_dbio.c b/src/ckdb_dbio.c index 5b3c1544..e5528df3 100644 --- a/src/ckdb_dbio.c +++ b/src/ckdb_dbio.c @@ -3438,10 +3438,16 @@ bool _sharesummary_update(PGconn *conn, SHARES *s_row, SHAREERRORS *e_row, K_ITE if (!new) { double td; td = tvdiff(sharecreatedate, &(row->firstshare)); - // don't LOGERR '=' in case shares come from ckpool with the same timestamp + // don't LOG '=' in case shares come from ckpool with the same timestamp if (td < 0.0) { char *tmp1, *tmp2; - LOGERR("%s(): %s createdate (%s) is < summary firstshare (%s)", + int level; + // DEBUG only for shares out of order up to 1 second + if (td < -1.0) + level = LOG_WARNING; + else + level = LOG_DEBUG; + LOGMSG(level, "%s(): OoO %s createdate (%s) is < summary firstshare (%s)", __func__, s_row ? "shares" : "shareerrors", (tmp1 = ctv_to_buf(sharecreatedate, NULL, 0)), (tmp2 = ctv_to_buf(&(row->firstshare), NULL, 0))); @@ -3452,14 +3458,20 @@ bool _sharesummary_update(PGconn *conn, SHARES *s_row, SHAREERRORS *e_row, K_ITE // Don't change lastdiffacc } td = tvdiff(sharecreatedate, &(row->lastshare)); - // don't LOGERR '=' in case shares come from ckpool with the same timestamp + // don't LOG '=' in case shares come from ckpool with the same timestamp if (td >= 0.0) { row->lastshare.tv_sec = sharecreatedate->tv_sec; row->lastshare.tv_usec = sharecreatedate->tv_usec; row->lastdiffacc = diff; } else { char *tmp1, *tmp2; - LOGERR("%s(): %s createdate (%s) is < summary lastshare (%s)", + int level; + // DEBUG only for shares out of order up to 1 second + if (td < -1.0) + level = LOG_WARNING; + else + level = LOG_DEBUG; + LOGMSG(level, "%s(): OoO %s createdate (%s) is < summary lastshare (%s)", __func__, s_row ? "shares" : "shareerrors", (tmp1 = ctv_to_buf(sharecreatedate, NULL, 0)), (tmp2 = ctv_to_buf(&(row->lastshare), NULL, 0))); From 2230bd6d65ced5fbaca68c648ba4a35b7c297955 Mon Sep 17 00:00:00 2001 From: kanoi Date: Sat, 21 Mar 2015 15:53:07 +1100 Subject: [PATCH 2/2] ckdb - stat the share OoO messages and increase the warning limit to 2s --- src/ckdb.h | 2 +- src/ckdb_dbio.c | 37 +++++++++++++++++++++++++++---------- 2 files changed, 28 insertions(+), 11 deletions(-) diff --git a/src/ckdb.h b/src/ckdb.h index 95a5791f..ed9d615d 100644 --- a/src/ckdb.h +++ b/src/ckdb.h @@ -55,7 +55,7 @@ #define DB_VLOCK "1" #define DB_VERSION "1.0.0" -#define CKDB_VERSION DB_VERSION"-1.034" +#define CKDB_VERSION DB_VERSION"-1.035" #define WHERE_FFL " - from %s %s() line %d" #define WHERE_FFL_HERE __FILE__, __func__, __LINE__ diff --git a/src/ckdb_dbio.c b/src/ckdb_dbio.c index e5528df3..033112af 100644 --- a/src/ckdb_dbio.c +++ b/src/ckdb_dbio.c @@ -3313,6 +3313,11 @@ flail: return ok; } +/* Keep some simple stats on how often shares are out of order + * and how often they produce a WARNING due to OOOLIMIT */ +static int64_t ooof0, ooof, oool0, oool; +#define OOOLIMIT -2.0 + bool _sharesummary_update(PGconn *conn, SHARES *s_row, SHAREERRORS *e_row, K_ITEM *ss_item, char *by, char *code, char *inet, tv_t *cd, WHERE_FFL_ARGS) { @@ -3442,15 +3447,21 @@ bool _sharesummary_update(PGconn *conn, SHARES *s_row, SHAREERRORS *e_row, K_ITE if (td < 0.0) { char *tmp1, *tmp2; int level; - // DEBUG only for shares out of order up to 1 second - if (td < -1.0) + // DEBUG only for shares out of order up to OOOLIMIT seconds + if (td < OOOLIMIT) { level = LOG_WARNING; - else + ooof++; + } else { level = LOG_DEBUG; - LOGMSG(level, "%s(): OoO %s createdate (%s) is < summary firstshare (%s)", + ooof0++; + } + LOGMSG(level, "%s(): OoO %s createdate (%s) is < summary" + " firstshare (%s) (F%"PRId64":%"PRId64 + "/L%"PRId64":%"PRId64"/%.1f)", __func__, s_row ? "shares" : "shareerrors", (tmp1 = ctv_to_buf(sharecreatedate, NULL, 0)), - (tmp2 = ctv_to_buf(&(row->firstshare), NULL, 0))); + (tmp2 = ctv_to_buf(&(row->firstshare), NULL, 0)), + ooof, ooof0, oool, oool0, OOOLIMIT); free(tmp2); free(tmp1); row->firstshare.tv_sec = sharecreatedate->tv_sec; @@ -3466,15 +3477,21 @@ bool _sharesummary_update(PGconn *conn, SHARES *s_row, SHAREERRORS *e_row, K_ITE } else { char *tmp1, *tmp2; int level; - // DEBUG only for shares out of order up to 1 second - if (td < -1.0) + // DEBUG only for shares out of order up to OOOLIMIT seconds + if (td < OOOLIMIT) { level = LOG_WARNING; - else + oool++; + } else { level = LOG_DEBUG; - LOGMSG(level, "%s(): OoO %s createdate (%s) is < summary lastshare (%s)", + oool0++; + } + LOGMSG(level, "%s(): OoO %s createdate (%s) is < summary" + " lastshare (%s) (F%"PRId64":%"PRId64 + "/L%"PRId64":%"PRId64"/%.1f)", __func__, s_row ? "shares" : "shareerrors", (tmp1 = ctv_to_buf(sharecreatedate, NULL, 0)), - (tmp2 = ctv_to_buf(&(row->lastshare), NULL, 0))); + (tmp2 = ctv_to_buf(&(row->lastshare), NULL, 0)), + ooof, ooof0, oool, oool0, OOOLIMIT); free(tmp2); free(tmp1); }