ttynvt version 0.14

Add some more debug
Proper flow-control handling
2019-03-21 08:52:05 +01:00 · 2019-03-21 08:46:08 +01:00 · 2019-03-21 08:45:36 +01:00 · 2019-01-16 11:17:18 +01:00 · 2018-10-31 12:09:37 +01:00
2 changed files with 82 additions and 25 deletions
@@ -1,4 +1,4 @@
-m4_define([pkg_version],  [0.13])
+m4_define([pkg_version],  [0.14])
 #m4_define([pkg_revision], [005])
 m4_define([pkg_version],  m4_ifdef([pkg_revision], [pkg_version.pkg_revision], [pkg_version]))

@@ -24,6 +24,7 @@
 #include <sys/ioctl.h>
 #include <sys/poll.h>
 #include <sys/socket.h>
+#include <sys/time.h>
 #include <sys/types.h>

 #include "telnet.h"
@@ -61,7 +62,9 @@ typedef struct {

    struct fuse_pollhandle *ph;

-    volatile char   n_fds;
+    volatile int    rel_pending;
+    volatile int    slave_suspended;    /*waiting for application to read data */
+    volatile int    master_suspended;   /*server is not ready to receive data */
    struct pollfd   fds[3];

    char            net_buf[NET_BUF_SIZE];
@@ -74,6 +77,7 @@ typedef struct {
    int             smcr_last;

    volatile int    pollin;
+    volatile int    pollout;
    volatile int    error;
    int             epipe;

@@ -83,18 +87,40 @@ typedef struct {
 #include <sys/syscall.h>
 #define gettid() (pid_t)syscall(__NR_gettid)

+static const char *_hms_txt(char *buf, unsigned int len)
+{
+    struct timeval  tv;
+    unsigned int    sod, hh, mm, ss;
+
+    gettimeofday(&tv, NULL);
+
+    sod = tv.tv_sec % (24 * 3600);
+    hh = sod / 3600;
+    mm = (sod - hh * 3600) / 60;
+    ss = sod - hh * 3600 - mm * 60;
+    snprintf(buf, len, "%02d:%02d:%02d.%06d",
+             hh, mm, ss, (unsigned int)tv.tv_usec);
+
+    return buf;
+}
+
 _PRF2_ static void _log(int prio, const char *fmt, ...)
 {
    va_list         arg;
-    char            buf[256];
+    char            buf[256], buft[64];

    va_start(arg, fmt);
    vsnprintf(buf, sizeof(buf), fmt, arg);

    if (ttynvt_param.logstd)
-        printf("[%d] %d: %s", gettid(), prio, buf);
+    {
+        printf("%s: [%d] %d: %s",
+               _hms_txt(buft, sizeof(buft)), gettid(), prio, buf);
+    }
    else
+    {
        syslog(prio, "[%d] %s", gettid(), buf);
+    }

    va_end(arg);
 }
@@ -189,7 +215,7 @@ static void ttynvt_release(fuse_req_t req, struct fuse_file_info *info)

    _log(LOG_INFO, "connection closed\n");

-    tty->n_fds = 0;
+    tty->rel_pending = 1;
    _fd_close(tty->fds[FD_NET].fd);
    _fd_close(tty->fds[FD_MASTER].fd);
    _fd_close(tty->fds[FD_SLAVE].fd);
@@ -255,22 +281,26 @@ static void    *_read_net(void *arg)
    pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
    DBG2("%s: net_cnt=%d\n", __func__, tty->net_cnt);

-    while (tty->n_fds > 0)
+    while (!tty->rel_pending)
    {
        tty->fds[FD_NET].revents = tty->fds[FD_MASTER].revents =
            tty->fds[FD_SLAVE].revents = 0;
-        res = poll(tty->fds, tty->n_fds, -1);
-        DBG2("%s: res=%d N=%d events-N/M/S=%#x/%#x/%#x\n", __func__,
-             res, tty->n_fds,
-             tty->fds[FD_NET].revents, tty->fds[FD_MASTER].revents,
-             tty->fds[FD_SLAVE].revents);
+        tty->fds[FD_SLAVE].events = tty->slave_suspended ? POLLPRI : POLLIN;
+        tty->fds[FD_MASTER].events = tty->master_suspended ? POLLPRI : POLLIN;
+
+        res = poll(tty->fds, 3, -1);
+        DBG2("%s: res=%d events-N/M/S=%x:%x/%x:%x/%x:%x SS=%d MS=%d\n",
+             __func__, res, tty->fds[FD_NET].events, tty->fds[FD_NET].revents,
+             tty->fds[FD_MASTER].events, tty->fds[FD_MASTER].revents,
+             tty->fds[FD_SLAVE].events, tty->fds[FD_SLAVE].revents,
+             tty->slave_suspended, tty->master_suspended);
        if (res < 0)
        {
            if (errno == EINTR)
                continue;
            break;
        }
-        if (tty->n_fds == 0)
+        if (tty->rel_pending)
            break;

        if (tty->fds[FD_NET].revents & POLLIN)
@@ -307,14 +337,20 @@ static void    *_read_net(void *arg)
                break;
        }

-        if (tty->fds[FD_MASTER].revents & POLLIN)
+        if ((tty->fds[FD_MASTER].revents & POLLIN) && !tty->master_suspended)
        {
            res = read(tty->fds[FD_MASTER].fd, buf, TMP_BUF_SIZE);
+            DBG("%s: read res=%d pollout=%d\n", __func__, res, tty->pollout);
            if (res < 0)
            {
                _log(LOG_ERR, "master read error: %m\n");
                break;
            }
+            if (tty->pollout == 0)
+            {
+                tty->pollout = 1;
+                _notify(tty);
+            }
            DBG2_BUF("TtyM in  ", buf, res);
            telnet_tx(tty->tn, buf, res);
        }
@@ -322,7 +358,7 @@ static void    *_read_net(void *arg)
        if (tty->fds[FD_SLAVE].revents & POLLIN)
        {
            tty->pollin = 1;
-            tty->n_fds = 2;     /* Disable polling of Slave */
+            tty->slave_suspended = 1;   /* Disable polling of Slave */
            _notify(tty);
        }
    }
@@ -442,6 +478,10 @@ static void _modem_status_cb(void *cctx, int status)
    if (status & TNS_STATE_CTS)
        mcr |= TIOCM_CTS;

+    tty->master_suspended = (mcr & TIOCM_CTS) ? 0 : 1;
+    DBG("%s: tty=%p mcr=%x MS=%d\n", __func__, tty, mcr,
+        tty->master_suspended);
+
    pthread_mutex_lock(&tty->tty_lock);
    tty->smcr_last = tty->smcr;
    tty->smcr = mcr;
@@ -474,6 +514,8 @@ static void ttynvt_open(fuse_req_t req, struct fuse_file_info *info)
    for (n = 0; n < 3; n++)
        tty->fds[n].fd = -1;

+    tty->pollout = 1;
+
    tty->tn = telnet_ctx_init(tty, _srv_write, _srv_read, _modem_status_cb);
    if (!tty->tn)
    {
@@ -542,8 +584,6 @@ static void ttynvt_open(fuse_req_t req, struct fuse_file_info *info)
        goto open_err;
    }

-    tty->n_fds = 3;             /* Initially poll Net, Master, and Slave */
-
    info->fh = (uintptr_t) tty;
    info->nonseekable = 1;
    info->direct_io = 1;
@@ -574,7 +614,7 @@ ttynvt_read(fuse_req_t req, size_t size, off_t off,
 {
    ttynvt_t       *tty = (ttynvt_t *) (uintptr_t) info->fh;
    char            buf[TMP_BUF_SIZE];
-    int             res;
+    int             res, nr;

    DBG2("%s\n", __func__);

@@ -601,8 +641,18 @@ ttynvt_read(fuse_req_t req, size_t size, off_t off,
    res = _is_interrupted ? -2 : read(tty->fds[FD_SLAVE].fd, buf, size);
    _is_interrupted = 0;
    tty->ptid_read = 0;
-    tty->n_fds = 3;             /* Enable polling of Slave */
+    tty->slave_suspended = 0;   /* Enable polling of Slave */
    fuse_req_interrupt_func(req, NULL, NULL);
+    if (res < (int)size)
+    {
+        tty->pollin = 0;
+    }
+    else
+    {
+        nr = 0;
+        ioctl(tty->fds[FD_SLAVE].fd, FIONREAD, &nr);
+        tty->pollin = nr > 0;
+    }
    if (res < 0)
    {
        DBG2("%s: error: %m\n", __func__);
@@ -647,6 +697,10 @@ ttynvt_write(fuse_req_t req, const char *data, size_t size, off_t off,
        fuse_reply_err(req, errno);
        return;
    }
+    else if (res != (int)size)
+    {
+        tty->pollout = 0;
+    }

    fuse_reply_write(req, res);
 }
@@ -837,7 +891,7 @@ ttynvt_ioctl(fuse_req_t req, int cmd, void *arg,
            ioctl(tty->fds[FD_SLAVE].fd, cmd, tio);

            if (cmd == TCSETSF)
-                tty->n_fds = 3; /* Re-enable polling of Slave */
+                tty->slave_suspended = 0;       /* Re-enable polling of Slave */

            fuse_reply_ioctl(req, 0, 0, 0);
        }
@@ -866,14 +920,16 @@ ttynvt_ioctl(fuse_req_t req, int cmd, void *arg,
        default:
        case TCIFLUSH:
            byte = 1;
-            tty->n_fds = 3;     /* Re-enable polling of Slave */
+            tty->slave_suspended = 0;   /* Re-enable polling of Slave */
            break;
        case TCOFLUSH:
            byte = 2;
+            tty->pollout = 1;
            break;
        case TCIOFLUSH:
            byte = 3;
-            tty->n_fds = 3;     /* Re-enable polling of Slave */
+            tty->slave_suspended = 0;   /* Re-enable polling of Slave */
+            tty->pollout = 1;
            break;
        }
        telnet_rfc2217_cfg(tty->tn, TNS_SET_PURGE, &byte, 1);
@@ -1023,18 +1079,19 @@ ttynvt_poll(fuse_req_t req, struct fuse_file_info *info,
            struct fuse_pollhandle *ph)
 {
    ttynvt_t       *tty = (ttynvt_t *) (uintptr_t) info->fh;
-    int             revents;
+    int             revents = 0;

    DBG2("%s: tty->pollin=%d tty->error/epipe=%d/%d\n",
         __func__, tty->pollin, tty->error, tty->epipe);

    _update_notify(tty, ph);

+    if (tty->pollout)
+    {
        revents = POLLOUT;
-
+    }
    if (tty->pollin)
    {
-        tty->pollin = 0;
        revents |= POLLIN;
    }
    if (tty->error)
Author	SHA1	Message	Date
Kim Woelders	cf6b334bcc	ttynvt version 0.14	2019-03-21 08:52:05 +01:00
Kim Woelders	09e96e72f7	Add some more debug	2019-03-21 08:46:08 +01:00
Kim Woelders	688fc53caf	Proper flow-control handling Patch by FRJ.	2019-03-21 08:45:36 +01:00
Kim Woelders	4d1d6978e4	Don't clear readable flag on poll When the slave becomes readable we set the pollin flag, and cleared it in ttynvt_poll(). So if ttynvt_poll() is called twice, the readable flag was lost. Now we clear it in ttynvt_read() if there actually are no more data to be read.	2019-01-16 11:17:18 +01:00
Kim Woelders	8f03aabe30	Add timestamp when logging to stdout	2018-10-31 12:09:37 +01:00