Merge branch 'ticket29662_squashed' into ticket29662_squashed_merged

changes/ticket29662

@@ -0,0 +1,5 @@
+  o Minor features (debugging):
+    - Introduce tor_assertf() and tor_assertf_nonfatal() to enable logging of
+      additional information during assert failure. Now we can use format
+      strings to include pieces of information that are relevant for trouble
+      shooting. Resolves ticket 29662.

src/core/or/circuituse.c

@@ -3121,7 +3121,9 @@ circuit_sent_valid_data(origin_circuit_t *circ, uint16_t relay_body_len)
 {
   if (!circ) return;
 
-  tor_assert_nonfatal(relay_body_len <= RELAY_PAYLOAD_SIZE);
+  tor_assertf_nonfatal(relay_body_len <= RELAY_PAYLOAD_SIZE,
+                       "Wrong relay_body_len: %d (should be at most %d)",
+                       relay_body_len, RELAY_PAYLOAD_SIZE);
 
   circ->n_delivered_written_circ_bw =
       tor_add_u32_nowrap(circ->n_delivered_written_circ_bw, relay_body_len);

src/lib/log/util_bug.c

@@ -69,25 +69,45 @@ tor_set_failed_assertion_callback(void (*fn)(void))
 
 /** Helper for tor_assert: report the assertion failure. */
 void
+CHECK_PRINTF(5, 6)
 tor_assertion_failed_(const char *fname, unsigned int line,
-                      const char *func, const char *expr)
+                      const char *func, const char *expr,
+                      const char *fmt, ...)
 {
-  char buf[256];
+  char *buf = NULL;
+  char *extra = NULL;
+  va_list ap;
+
+#ifdef __clang__
+#pragma clang diagnostic push
+#pragma clang diagnostic ignored "-Wformat-nonliteral"
+#endif
+  if (fmt) {
+    va_start(ap,fmt);
+    tor_vasprintf(&extra, fmt, ap);
+    va_end(ap);
+  }
+#ifdef __clang__
+#pragma clang diagnostic pop
+#endif
+
   log_err(LD_BUG, "%s:%u: %s: Assertion %s failed; aborting.",
           fname, line, func, expr);
-  tor_snprintf(buf, sizeof(buf),
-               "Assertion %s failed in %s at %s:%u",
-               expr, func, fname, line);
+  tor_asprintf(&buf, "Assertion %s failed in %s at %s:%u: %s",
+               expr, func, fname, line, extra ? extra : "");
+  tor_free(extra);
   log_backtrace(LOG_ERR, LD_BUG, buf);
+  tor_free(buf);
 }
 
 /** Helper for tor_assert_nonfatal: report the assertion failure. */
 void
+CHECK_PRINTF(6, 7)
 tor_bug_occurred_(const char *fname, unsigned int line,
                   const char *func, const char *expr,
-                  int once)
+                  int once, const char *fmt, ...)
 {
-  char buf[256];
+  char *buf = NULL;
   const char *once_str = once ?
     " (Future instances of this warning will be silenced.)": "";
   if (! expr) {
@@ -105,13 +125,32 @@ tor_bug_occurred_(const char *fname, unsigned int line,
       add_captured_bug(expr);
       return;
     }
+
+    va_list ap;
+    char *extra = NULL;
+
+#ifdef __clang__
+#pragma clang diagnostic push
+#pragma clang diagnostic ignored "-Wformat-nonliteral"
+#endif
+    if (fmt) {
+      va_start(ap,fmt);
+      tor_vasprintf(&extra, fmt, ap);
+      va_end(ap);
+    }
+#ifdef __clang__
+#pragma clang diagnostic pop
+#endif
+
     log_warn(LD_BUG, "%s:%u: %s: Non-fatal assertion %s failed.%s",
              fname, line, func, expr, once_str);
-    tor_snprintf(buf, sizeof(buf),
-                 "Non-fatal assertion %s failed in %s at %s:%u",
-                 expr, func, fname, line);
+    tor_asprintf(&buf, "Non-fatal assertion %s failed in %s at %s:%u%s%s",
+                 expr, func, fname, line, fmt ? " : " : "",
+                 extra ? extra : "");
+    tor_free(extra);
   }
   log_backtrace(LOG_WARN, LD_BUG, buf);
+  tor_free(buf);
 
 #ifdef TOR_UNIT_TESTS
   if (failed_assertion_cb) {

src/lib/log/util_bug.h

@@ -92,13 +92,20 @@
 #define tor_assert(a) STMT_BEGIN                                        \
   (void)(a);                                                            \
   STMT_END
+#define tor_assertf(a, fmt, ...) STMT_BEGIN                             \
+  (void)(a);                                                            \
+  (void)(fmt);                                                          \
+  STMT_END
 #else
 /** Like assert(3), but send assertion failures to the log as well as to
  * stderr. */
-#define tor_assert(expr) STMT_BEGIN                                     \
+#define tor_assert(expr) tor_assertf(expr, NULL)
+
+#define tor_assertf(expr, fmt, ...) STMT_BEGIN                          \
   if (ASSERT_PREDICT_LIKELY_(expr)) {                                   \
   } else {                                                              \
-    tor_assertion_failed_(SHORT_FILE__, __LINE__, __func__, #expr);     \
+    tor_assertion_failed_(SHORT_FILE__, __LINE__, __func__, #expr,      \
+                          fmt, ##__VA_ARGS__);                          \
     abort();                                                            \
   } STMT_END
 #endif /* defined(TOR_UNIT_TESTS) && defined(DISABLE_ASSERTS_IN_UNIT_TESTS) */
@@ -106,7 +113,7 @@
 #define tor_assert_unreached()                                  \
   STMT_BEGIN {                                                  \
     tor_assertion_failed_(SHORT_FILE__, __LINE__, __func__,     \
-                          "line should be unreached");          \
+                          "line should be unreached", NULL);    \
     abort();                                                    \
   } STMT_END
 
@@ -136,6 +143,7 @@
 #ifdef ALL_BUGS_ARE_FATAL
 #define tor_assert_nonfatal_unreached() tor_assert(0)
 #define tor_assert_nonfatal(cond) tor_assert((cond))
+#define tor_assertf_nonfatal(cond, fmt, ...) tor_assertf(cond, fmt, ...)
 #define tor_assert_nonfatal_unreached_once() tor_assert(0)
 #define tor_assert_nonfatal_once(cond) tor_assert((cond))
 #define BUG(cond)                                                       \
@@ -146,24 +154,35 @@
 #elif defined(TOR_UNIT_TESTS) && defined(DISABLE_ASSERTS_IN_UNIT_TESTS)
 #define tor_assert_nonfatal_unreached() STMT_NIL
 #define tor_assert_nonfatal(cond) ((void)(cond))
+#define tor_assertf_nonfatal(cond, fmt, ...) STMT_BEGIN                 \
+  (void)cond;                                                           \
+  (void)fmt;                                                            \
+  STMT_END
 #define tor_assert_nonfatal_unreached_once() STMT_NIL
 #define tor_assert_nonfatal_once(cond) ((void)(cond))
 #define BUG(cond) (ASSERT_PREDICT_UNLIKELY_(cond) ? 1 : 0)
 #else /* Normal case, !ALL_BUGS_ARE_FATAL, !DISABLE_ASSERTS_IN_UNIT_TESTS */
 #define tor_assert_nonfatal_unreached() STMT_BEGIN                      \
-  tor_bug_occurred_(SHORT_FILE__, __LINE__, __func__, NULL, 0);         \
+  tor_bug_occurred_(SHORT_FILE__, __LINE__, __func__, NULL, 0, NULL);   \
   STMT_END
 #define tor_assert_nonfatal(cond) STMT_BEGIN                            \
   if (ASSERT_PREDICT_LIKELY_(cond)) {                                   \
   } else {                                                              \
-    tor_bug_occurred_(SHORT_FILE__, __LINE__, __func__, #cond, 0);      \
+    tor_bug_occurred_(SHORT_FILE__, __LINE__, __func__, #cond, 0, NULL);\
+  }                                                                     \
+  STMT_END
+#define tor_assertf_nonfatal(cond, fmt, ...) STMT_BEGIN                 \
+  if (ASSERT_PREDICT_UNLIKELY_(cond)) {                                 \
+  } else {                                                              \
+    tor_bug_occurred_(SHORT_FILE__, __LINE__, __func__, #cond, 0,        \
+                      fmt, ##__VA_ARGS__);                               \
   }                                                                     \
   STMT_END
 #define tor_assert_nonfatal_unreached_once() STMT_BEGIN                 \
   static int warning_logged__ = 0;                                      \
   if (!warning_logged__) {                                              \
     warning_logged__ = 1;                                               \
-    tor_bug_occurred_(SHORT_FILE__, __LINE__, __func__, NULL, 1);       \
+    tor_bug_occurred_(SHORT_FILE__, __LINE__, __func__, NULL, 1, NULL); \
   }                                                                     \
   STMT_END
 #define tor_assert_nonfatal_once(cond) STMT_BEGIN                       \
@@ -171,12 +190,12 @@
   if (ASSERT_PREDICT_LIKELY_(cond)) {                                   \
   } else if (!warning_logged__) {                                       \
     warning_logged__ = 1;                                               \
-    tor_bug_occurred_(SHORT_FILE__, __LINE__, __func__, #cond, 1);      \
+    tor_bug_occurred_(SHORT_FILE__, __LINE__, __func__, #cond, 1, NULL);\
   }                                                                     \
   STMT_END
 #define BUG(cond)                                                       \
   (ASSERT_PREDICT_UNLIKELY_(cond) ?                                     \
-   (tor_bug_occurred_(SHORT_FILE__,__LINE__,__func__,"!("#cond")",0), 1) \
+  (tor_bug_occurred_(SHORT_FILE__,__LINE__,__func__,"!("#cond")",1,NULL),1) \
    : 0)
 #endif /* defined(ALL_BUGS_ARE_FATAL) || ... */
 
@@ -188,7 +207,7 @@
       if (bool_result && !var) {                                        \
         var = 1;                                                        \
         tor_bug_occurred_(SHORT_FILE__, __LINE__, __func__,             \
-                          "!("#cond")", 1);                             \
+                          "!("#cond")", 1, NULL);                       \
       }                                                                 \
       bool_result; } ))
 #else /* !(defined(__GNUC__)) */
@@ -198,7 +217,7 @@
       (var ? 1 :                                                        \
        (var=1,                                                          \
         tor_bug_occurred_(SHORT_FILE__, __LINE__, __func__,             \
-                           "!("#cond")", 1),                            \
+                           "!("#cond")", 1, NULL),                      \
         1))                                                             \
       : 0)
 #endif /* defined(__GNUC__) */
@@ -221,10 +240,11 @@
 #define tor_fragile_assert() tor_assert_nonfatal_unreached_once()
 
 void tor_assertion_failed_(const char *fname, unsigned int line,
-                           const char *func, const char *expr);
+                           const char *func, const char *expr,
+                           const char *fmt, ...);
 void tor_bug_occurred_(const char *fname, unsigned int line,
                        const char *func, const char *expr,
-                       int once);
+                       int once, const char *fmt, ...);
 
 #ifdef _WIN32
 #define SHORT_FILE__ (tor_fix_source_file(__FILE__))

src/test/test_bt_cl.c

@@ -46,7 +46,7 @@ crash(int x)
     *(volatile int *)0 = 0;
 #endif /* defined(__clang_analyzer__) || defined(__COVERITY__) */
   } else if (crashtype == 1) {
-    tor_assert(1 == 0);
+    tor_assertf(1 == 0, "%d != %d", 1, 0);
   } else if (crashtype == -1) {
     ;
   }

src/test/testing_rsakeys.c

@@ -448,7 +448,8 @@ static int next_key_idx_2048;
 static crypto_pk_t *
 pk_generate_internal(int bits)
 {
-  tor_assert(bits == 2048 || bits == 1024);
+  tor_assertf(bits == 2048 || bits == 1024,
+             "Wrong key size: %d", bits);
 
 #ifdef USE_PREGENERATED_RSA_KEYS
   int *idxp;