AST-2017-004: chan_skinny: Add EOF check in skinny_session
authorGeorge Joseph <gjoseph@digium.com>
Thu, 13 Apr 2017 16:14:48 +0000 (10:14 -0600)
committerMatthew Fredrickson <creslin@digium.com>
Fri, 19 May 2017 16:19:09 +0000 (11:19 -0500)
The while(1) loop in skinny_session wasn't checking for EOF so
a packet that was longer than a header but still truncated
would spin the while loop infinitely.  Not only does this
permanently tie up a thread and drive a core to 100% utilization,
the call of ast_log() in such a tight loop eats all available
process memory.

Added poll with timeout to top of read loop

ASTERISK-26940 #close
Reported-by: Sandro Gauci

Change-Id: I2ce65f3c5cb24b4943a9f75b64d545a1e2cd2898

channels/chan_skinny.c

index a053000..aeb0605 100644 (file)
@@ -6658,7 +6658,7 @@ static int handle_capabilities_res_message(struct skinny_req *req, struct skinny
 #ifdef AST_DEVMODE
        struct ast_str *codec_buf = ast_str_alloca(AST_FORMAT_CAP_NAMES_LEN);
 #endif
-       
+
 
        if (!codecs) {
                return 0;
@@ -7499,6 +7499,8 @@ static void skinny_session_cleanup(void *data)
        destroy_session(s);
 }
 
+#define PACKET_TIMEOUT 10000
+
 static void *skinny_session(void *data)
 {
        int res;
@@ -7545,78 +7547,86 @@ static void *skinny_session(void *data)
                        }
                }
 
-               if (fds[0].revents) {
+               if (!fds[0].revents) {
+                       continue;
+               }
+               ast_debug(1, "Reading header\n");
 
-                       if (!(req = ast_calloc(1, SKINNY_MAX_PACKET))) {
-                               ast_log(LOG_WARNING, "Unable to allocated memorey for skinny_req.\n");
-                               break;
-                       }
+               if (!(req = ast_calloc(1, SKINNY_MAX_PACKET))) {
+                       ast_log(LOG_WARNING, "Unable to allocated memorey for skinny_req.\n");
+                       break;
+               }
 
-                       ast_mutex_lock(&s->lock);
-                       s->lockstate = 1;
+               ast_mutex_lock(&s->lock);
+               s->lockstate = 1;
 
-                       if ((res = read(s->fd, req, skinny_header_size)) != skinny_header_size) {
-                               if (res < 0) {
-                                       ast_log(LOG_WARNING, "Header read() returned error: %s\n", strerror(errno));
-                               } else {
-                                       ast_log(LOG_WARNING, "Unable to read header. Only found %d bytes.\n", res);
-                               }
-                               break;
+               if ((res = read(s->fd, req, skinny_header_size)) != skinny_header_size) {
+                       if (res < 0) {
+                               ast_log(LOG_WARNING, "Header read() returned error: %s\n", strerror(errno));
+                       } else {
+                               ast_log(LOG_WARNING, "Unable to read header. Only found %d bytes.\n", res);
                        }
+                       break;
+               }
 
-                       eventmessage = letohl(req->e);
-                       if (eventmessage < 0) {
-                               ast_log(LOG_ERROR, "Event Message is NULL from socket %d, This is bad\n", s->fd);
-                               break;
-                       }
+               eventmessage = letohl(req->e);
+               if (eventmessage < 0) {
+                       ast_log(LOG_ERROR, "Event Message is NULL from socket %d, This is bad\n", s->fd);
+                       break;
+               }
 
-                       dlen = letohl(req->len) - 4;
-                       if (dlen < 0) {
-                               ast_log(LOG_WARNING, "Skinny Client sent invalid data.\n");
-                               break;
-                       }
-                       if (dlen > (SKINNY_MAX_PACKET - skinny_header_size)) {
-                               ast_log(LOG_WARNING, "Skinny packet too large (%d bytes), max length(%d bytes)\n", dlen+8, SKINNY_MAX_PACKET);
-                               break;
-                       }
+               dlen = letohl(req->len) - 4;
+               if (dlen < 0) {
+                       ast_log(LOG_WARNING, "Skinny Client sent invalid data.\n");
+                       break;
+               }
+               if (dlen > (SKINNY_MAX_PACKET - skinny_header_size)) {
+                       ast_log(LOG_WARNING, "Skinny packet too large (%d bytes), max length(%d bytes)\n", dlen+8, SKINNY_MAX_PACKET);
+                       break;
+               }
 
-                       bytesread = 0;
-                       while (1) {
-                               if ((res = read(s->fd, ((char*)&req->data)+bytesread, dlen-bytesread)) < 0) {
-                                       ast_log(LOG_WARNING, "Data read() returned error: %s\n", strerror(errno));
-                                       break;
-                               }
-                               bytesread += res;
-                               if (bytesread >= dlen) {
-                                       if (res < bytesread) {
-                                               ast_log(LOG_WARNING, "Rest of partial data received.\n");
-                                       }
-                                       if (bytesread > dlen) {
-                                               ast_log(LOG_WARNING, "Client sent wrong amount of data (%d), expected (%d).\n", bytesread, dlen);
-                                               res = -1;
-                                       }
-                                       break;
-                               }
+               ast_debug(1, "Read header: Message ID: 0x%04x,  %d bytes in packet\n", eventmessage, dlen);
 
-                               ast_log(LOG_WARNING, "Partial data received, waiting (%d bytes read of %d)\n", bytesread, dlen);
-                               if (sched_yield() < 0) {
-                                       ast_log(LOG_WARNING, "Data yield() returned error: %s\n", strerror(errno));
-                                       res = -1;
-                                       break;
+               bytesread = 0;
+               while (bytesread < dlen) {
+                       ast_debug(1, "Waiting %dms for %d bytes of %d\n", PACKET_TIMEOUT, dlen - bytesread, dlen);
+                       fds[0].revents = 0;
+                       res = ast_poll(fds, 1, PACKET_TIMEOUT);
+                       if (res <= 0) {
+                               if (res == 0) {
+                                       ast_debug(1, "Poll timed out waiting for %d bytes\n", dlen - bytesread);
+                               } else {
+                                       ast_log(LOG_WARNING, "Poll failed waiting for %d bytes: %s\n",
+                                               dlen - bytesread, strerror(errno));
                                }
+                               ast_verb(3, "Ending Skinny session from %s (bad input)\n", ast_inet_ntoa(s->sin.sin_addr));
+                               res = -1;
+
+                               break;
+                       }
+                       if (!fds[0].revents) {
+                               continue;
                        }
 
-                       s->lockstate = 0;
-                       ast_mutex_unlock(&s->lock);
+                       res = read(s->fd, ((char*)&req->data)+bytesread, dlen-bytesread);
                        if (res < 0) {
+                               ast_log(LOG_WARNING, "Data read() returned error: %s\n", strerror(errno));
                                break;
                        }
+                       bytesread += res;
+                       ast_debug(1, "Read %d bytes.  %d of %d now read\n", res, bytesread, dlen);
+               }
 
-                       pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
-                       res = handle_message(req, s);
-                       pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
+               s->lockstate = 0;
+               ast_mutex_unlock(&s->lock);
+               if (res < 0) {
+                       break;
                }
 
+               pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, NULL);
+               res = handle_message(req, s);
+               pthread_setcancelstate(PTHREAD_CANCEL_ENABLE, NULL);
+
                if (req) {
                        ast_free(req);
                        req = NULL;