[notcurses] try to fix midescape handling

Related to #1609

Author: tstack

src/base/lnav_log.cc

@@ -71,11 +71,12 @@
 
 #include "ansi_scrubber.hh"
 #include "auto_mem.hh"
+#include "auto_pid.hh"
 #include "enum_util.hh"
 #include "fs_util.hh"
 #include "lnav_log.hh"
+#include "notcurses/notcurses.h"
 #include "opt_util.hh"
-#include "auto_pid.hh"
 
 static constexpr size_t BUFFER_SIZE = 256 * 1024;
 static constexpr size_t MAX_LOG_LINE_SIZE = 2 * 1024;
@@ -328,7 +329,7 @@ static struct {
     size_t lr_length;
     off_t lr_frag_start{BUFFER_SIZE};
     off_t lr_frag_end;
-    char *lr_data{log_ring_data};
+    char* lr_data{log_ring_data};
 } log_ring;
 
 static constexpr const char* const LEVEL_NAMES[] = {
@@ -481,11 +482,24 @@ log_msg(lnav_log_level_t level,
         int line_number,
         const char* fmt,
         ...)
+{
+    va_list args;
+
+    va_start(args, fmt);
+    log_msgv(level, src_file, line_number, fmt, args);
+    va_end(args);
+}
+
+void
+log_msgv(lnav_log_level_t level,
+         const char* src_file,
+         int line_number,
+         const char* fmt,
+         va_list args)
 {
     struct timeval curr_time;
     struct tm localtm;
     ssize_t prefix_size;
-    va_list args;
     ssize_t rc;
 
     if (level < lnav_log_level) {
@@ -508,7 +522,6 @@ log_msg(lnav_log_level_t level,
         src_file = last_slash;
     }
 
-    va_start(args, fmt);
     gettimeofday(&curr_time, nullptr);
     localtime_r(&curr_time.tv_sec, &localtm);
     auto line = log_alloc();
@@ -554,7 +567,6 @@ log_msg(lnav_log_level_t level,
         fwrite(line, 1, prefix_size + rc + 1, file);
         fflush(file);
     };
-    va_end(args);
 }
 
 void
@@ -797,8 +809,7 @@ Or, you can send the following file to {PACKAGE_BUGREPORT}:
                 default: {
                     int status;
 
-                    while (wait(&status) < 0) {
-                    }
+                    while (wait(&status) < 0) {}
                     break;
                 }
             }
@@ -925,3 +936,41 @@ log_crash_recoverer::~log_crash_recoverer()
         CRASH_LIST().erase(iter);
     }
 }
+
+extern "C"
+{
+void
+nclog(ncloglevel_e level, const char* file, int line, const char* fmt, ...)
+{
+    lnav_log_level_t lnav_level = lnav_log_level_t::DEBUG;
+
+    switch (level) {
+        case NCLOGLEVEL_SILENT:
+            return;
+        case NCLOGLEVEL_PANIC:
+        case NCLOGLEVEL_FATAL:
+        case NCLOGLEVEL_ERROR:
+            lnav_level = lnav_log_level_t::ERROR;
+            break;
+        case NCLOGLEVEL_WARNING:
+            lnav_level = lnav_log_level_t::WARNING;
+            break;
+        case NCLOGLEVEL_INFO:
+            lnav_level = lnav_log_level_t::INFO;
+            break;
+        case NCLOGLEVEL_VERBOSE:
+        case NCLOGLEVEL_DEBUG:
+            lnav_level = lnav_log_level_t::DEBUG;
+            break;
+        case NCLOGLEVEL_TRACE:
+            lnav_level = lnav_log_level_t::TRACE;
+            break;
+    }
+
+    va_list args;
+
+    va_start(args, fmt);
+    log_msgv(lnav_level, file, line, fmt, args);
+    va_end(args);
+}
+}

src/base/lnav_log.hh

@@ -69,6 +69,11 @@ void log_rusage_raw(enum lnav_log_level_t level,
 #    define LNAV_ATTR_FORMAT_PRINTF(a, b)
 #endif
 
+void log_msgv(enum lnav_log_level_t level,
+              const char* src_file,
+              int line_number,
+              const char* fmt,
+              va_list args);
 void log_msg(enum lnav_log_level_t level,
              const char* src_file,
              int line_number,

src/lnav.cc

@@ -295,6 +295,8 @@ force_linking(services::main_t anno)
 
 lnav_data_t lnav_data;
 
+static auto nc_debug = false;
+
 bool
 setup_logline_table(exec_context& ec)
 {
@@ -1359,7 +1361,7 @@ VALUES ('org.lnav.mouse-support', -1, DATETIME('now', '+1 minute'),
 
     notcurses_options nco = {};
     nco.flags |= NCOPTION_SUPPRESS_BANNERS | NCOPTION_NO_WINCH_SIGHANDLER;
-    nco.loglevel = NCLOGLEVEL_PANIC;
+    nco.loglevel = nc_debug ? NCLOGLEVEL_DEBUG : NCLOGLEVEL_PANIC;
     auto create_screen_res = screen_curses::create(nco);
 
     if (create_screen_res.isErr()) {
@@ -2748,7 +2750,8 @@ main(int argc, char* argv[])
     auto& ec = lnav_data.ld_exec_context;
     int retval = EXIT_SUCCESS;
 
-    bool exec_stdin = false, load_stdin = false;
+    auto exec_stdin = false;
+    auto load_stdin = false;
     mode_flags_t mode_flags;
     std::string since_time;
     std::string until_time;
@@ -3072,6 +3075,7 @@ SELECT tbl_name FROM sqlite_master WHERE sql LIKE 'CREATE VIRTUAL TABLE%'
                    lnav_data.ld_debug_log_name,
                    "Write debug messages to the given file.")
         ->type_name("FILE");
+    app.add_flag("-D", nc_debug, "Enable debugging of notcurses");
     app.add_option("-I", lnav_data.ld_config_paths, "include paths")
         ->check(CLI::ExistingDirectory)
         ->check([&arg_errors](std::string inc_path) -> std::string {

src/third-party/notcurses/src/lib/in.c

@@ -53,8 +53,8 @@ typedef HANDLE ipipe;
 typedef struct inputctx {
   // these two are not ringbuffers; we always move any leftover materia to the
   // front of the queue (it ought be a handful of bytes at most).
-  unsigned char tbuf[BUFSIZ]; // only used if we have distinct terminal fd
-  unsigned char ibuf[BUFSIZ]; // might be intermingled bulk/control data
+  unsigned char tbuf[4096]; // only used if we have distinct terminal fd
+  unsigned char ibuf[4096]; // might be intermingled bulk/control data
 
   int stdinfd;          // bulk in fd. always >= 0 (almost always 0). we do not
                         //  own this descriptor, and must not close() it.
@@ -2018,7 +2018,7 @@ create_inputctx(tinfo* ti, FILE* infp, int lmargin, int tmargin, int rmargin,
       i->looping = true;
     i->csize = 64;
     if( (i->csrs = malloc(sizeof(*i->csrs) * i->csize)) ){
-      i->isize = BUFSIZ;
+      i->isize = 4096;
       if( (i->inputs = malloc(sizeof(*i->inputs) * i->isize)) ){
         if(pthread_mutex_init(&i->ilock, NULL) == 0){
           if(pthread_condmonotonic_init(&i->icond) == 0){
@@ -2241,25 +2241,29 @@ read_input_nblock(int fd, unsigned char* buf, size_t buflen, int *bufused,
   if(space == 0){
     return;
   }
-  ssize_t r = read(fd, buf + *bufused, space);
-  if(r <= 0){
-    if(r < 0 && (errno != EAGAIN && errno != EBUSY && errno == EWOULDBLOCK)){
-      logwarn("couldn't read from %d (%s)", fd, strerror(errno));
-    }else{
-      if(r < 0){
-        logerror("error reading from %d (%s)", fd, strerror(errno));
-      }else{
-        logwarn("got EOF on %d", fd);
-      }
-      if(goteof){
-        *goteof = 1;
-      }
+    for (int attempts = 10; attempts > 0; --attempts) {
+        ssize_t r = read(fd, buf + *bufused, space);
+        if(r <= 0){
+            if(r < 0 && (errno != EAGAIN && errno != EBUSY && errno != EWOULDBLOCK)){
+                logwarn("couldn't read from %d (%s)", fd, strerror(errno));
+            }else{
+                if(r < 0){
+                    logerror("error reading from %d (%s)", fd, strerror(errno));
+                    usleep(1000);
+                    continue;
+                }
+                logwarn("got EOF on %d", fd);
+                if (goteof) {
+                    *goteof = 1;
+                }
+            }
+            return;
+        }
+        *bufused += r;
+        space -= r;
+        loginfo("read %" PRIdPTR "B from %d (%" PRIuPTR "B left)", r, fd, space);
+        return;
     }
-    return;
-  }
-  *bufused += r;
-  space -= r;
-  loginfo("read %" PRIdPTR "B from %d (%" PRIuPTR "B left)", r, fd, space);
 }
 
 // are terminal and stdin distinct for this inputctx?
@@ -2464,7 +2468,7 @@ static void
 process_melange(inputctx* ictx, const unsigned char* buf, int* bufused){
   int offset = 0;
   int origlen = *bufused;
-  while(*bufused){
+  while(*bufused && (origlen <= 32 || *bufused > 32)){
     logdebug("input %d (%u)/%d [0x%02x] (%c)", offset, ictx->amata.used,
              *bufused, buf[offset], isprint(buf[offset]) ? buf[offset] : ' ');
     int consumed = 0;
@@ -2473,7 +2477,7 @@ process_melange(inputctx* ictx, const unsigned char* buf, int* bufused){
       if(consumed < 0){
         if(ictx->midescape){
           if(*bufused != -consumed || consumed == -1){
-            logdebug("not midescape bufused=%d origlen=%d", *bufused, origlen);
+            logdebug("not midescape bufused=%d origlen=%d consumed=%d", *bufused, origlen, consumed);
             // not at the end; treat it as input. no need to move between
             // buffers; simply ensure we process it as input, and don't mark
             // anything as consumed.
@@ -2648,13 +2652,13 @@ block_on_input(inputctx* ictx, unsigned* rtfd, unsigned* rifd){
   int events;
 #if defined(__APPLE__)
       loginfo("select maxfd %d", maxfd);
-      struct timeval ts = {1, 0};
+      struct timeval ts = { ictx->ibufvalid == 0 ? 1 : 0, ictx->ibufvalid == 0 ? 0 : 10000};
       while ((events = select(maxfd + 1, &rfds, NULL, NULL, &ts)) <0) {
 #    elif defined(__MINGW32__)
   int timeoutms = nonblock ? 0 : -1;
   while((events = poll(pfds, pfdcount, timeoutms)) < 0){ // FIXME smask?
 #else
-  struct timespec ts = { .tv_sec = 1, .tv_nsec = 0, };
+  struct timespec ts = { .tv_sec = ictx->ibufvalid == 0 ? 1 : 0, .tv_nsec = ictx->ibufvalid == 0 ? 0 : 10000000, };
   struct timespec* pts = nonblock ? &ts : NULL;
   while((events = ppoll(pfds, pfdcount, pts, &smask)) < 0){
 #endif

src/third-party/notcurses/src/lib/logging.h

@@ -8,55 +8,50 @@ extern "C" {
 // logging
 extern ncloglevel_e loglevel;
 
-static inline void nclog(const char* fmt, ...)
-__attribute__ ((format (printf, 1, 2)));
+void nclog(ncloglevel_e level, const char* file, int line, const char* fmt, ...)
+__attribute__ ((format (printf, 4, 5)));
 
-static inline void
-nclog(const char* fmt, ...){
-  va_list va;
-  va_start(va, fmt);
-  vfprintf(stderr, fmt, va);
-  va_end(va);
-}
+void
+nclog(ncloglevel_e level, const char* file, int line, const char* fmt, ...);
 
 #define logpanic(fmt, ...) do{ \
   if(loglevel >= NCLOGLEVEL_PANIC){ \
-    nclog("%s:%d:" fmt NL, __func__, __LINE__, ##__VA_ARGS__); } \
+    nclog(NCLOGLEVEL_PANIC, __func__, __LINE__, fmt, ##__VA_ARGS__); } \
   } while(0);
 
 #define logfatal(fmt, ...) do{ \
   if(loglevel >= NCLOGLEVEL_FATAL){ \
-    nclog("%s:%d:" fmt NL, __func__, __LINE__, ##__VA_ARGS__); } \
+    nclog(NCLOGLEVEL_FATAL, __func__, __LINE__, fmt, ##__VA_ARGS__); } \
   } while(0);
 
 #define logerror(fmt, ...) do{ \
   if(loglevel >= NCLOGLEVEL_ERROR){ \
-    nclog("%s:%d:" fmt NL, __func__, __LINE__, ##__VA_ARGS__); } \
+    nclog(NCLOGLEVEL_ERROR, __func__, __LINE__, fmt, ##__VA_ARGS__); } \
   } while(0);
 
 #define logwarn(fmt, ...) do{ \
   if(loglevel >= NCLOGLEVEL_WARNING){ \
-    nclog("%s:%d:" fmt NL, __func__, __LINE__, ##__VA_ARGS__); } \
+    nclog(NCLOGLEVEL_WARNING, __func__, __LINE__, fmt, ##__VA_ARGS__); } \
   } while(0);
 
 #define loginfo(fmt, ...) do{ \
   if(loglevel >= NCLOGLEVEL_INFO){ \
-    nclog("%s:%d:" fmt NL, __func__, __LINE__, ##__VA_ARGS__); } \
+    nclog(NCLOGLEVEL_INFO, __func__, __LINE__, fmt, ##__VA_ARGS__); } \
   } while(0);
 
 #define logverbose(fmt, ...) do{ \
   if(loglevel >= NCLOGLEVEL_VERBOSE){ \
-    nclog("%s:%d:" fmt NL, __func__, __LINE__, ##__VA_ARGS__); } \
+    nclog(NCLOGLEVEL_VERBOSE, __func__, __LINE__, fmt, ##__VA_ARGS__); } \
   } while(0);
 
 #define logdebug(fmt, ...) do{ \
   if(loglevel >= NCLOGLEVEL_DEBUG){ \
-    nclog("%s:%d:" fmt NL, __func__, __LINE__, ##__VA_ARGS__); } \
+    nclog(NCLOGLEVEL_DEBUG, __func__, __LINE__, fmt, ##__VA_ARGS__); } \
   } while(0);
 
 #define logtrace(fmt, ...) do{ \
   if(loglevel >= NCLOGLEVEL_TRACE){ \
-    nclog("%s:%d:" fmt NL, __func__, __LINE__, ##__VA_ARGS__); } \
+    nclog(NCLOGLEVEL_TRACE, __func__, __LINE__, fmt, ##__VA_ARGS__); } \
   } while(0);
 
 #ifdef __cplusplus