]> arthur.barton.de Git - netatalk.git/commitdiff
Add lots of debugging code in the DSI handling routines
authorFrank Lahm <franklahm@googlemail.com>
Fri, 25 Nov 2011 16:41:54 +0000 (17:41 +0100)
committerFrank Lahm <franklahm@googlemail.com>
Fri, 25 Nov 2011 16:41:54 +0000 (17:41 +0100)
configure.ac
etc/afpd/afp_dsi.c
etc/afpd/fork.c
include/atalk/dsi.h
libatalk/dsi/dsi_cmdreply.c
libatalk/dsi/dsi_read.c
libatalk/dsi/dsi_stream.c

index 0c711b14856fd1cbe2f376a331c1bc22b7af8131..d6a36899e9801fbccc9e22ccad865ed341684135 100644 (file)
@@ -839,7 +839,7 @@ if test x"$netatalk_cv_search_sendfile" = x"yes"; then
         AC_SEARCH_LIBS(sendfile, sendfile)
         AC_CHECK_FUNC([sendfile], [netatalk_cv_HAVE_SENDFILE=yes])
 dnl -- there's a bug somewhere, disable for now
-        netatalk_cv_HAVE_SENDFILE=no
+#        netatalk_cv_HAVE_SENDFILE=no
         ;;
 
     *freebsd*)
index 295e03df7d8dcbc7b9249f34b726b6724831269b..3105db63efb4fde7831736e11204b83646b8fa48 100644 (file)
@@ -483,7 +483,7 @@ void afp_over_dsi(AFPObj *obj)
             continue;
 
         /* Blocking read on the network socket */
-        cmd = dsi_receive(dsi);
+        cmd = dsi_stream_receive(dsi);
 
         if (cmd == 0) {
             /* cmd == 0 is the error condition */
@@ -592,7 +592,7 @@ void afp_over_dsi(AFPObj *obj)
 
             /* AFP replay cache */
             rc_idx = dsi->clientID % REPLAYCACHE_SIZE;
-            LOG(log_debug, logtype_afpd, "DSI request ID: %u", dsi->clientID);
+            LOG(log_debug, logtype_dsi, "DSI request ID: %u", dsi->clientID);
 
             if (replaycache[rc_idx].DSIreqID == dsi->clientID
                 && replaycache[rc_idx].AFPcommand == function) {
@@ -640,9 +640,7 @@ void afp_over_dsi(AFPObj *obj)
             if (dsi->flags & DSI_NOREPLY) {
                 dsi->flags &= ~DSI_NOREPLY;
                 break;
-            }
-
-            if (!dsi_cmdreply(dsi, err)) {
+            } else if (!dsi_cmdreply(dsi, err)) {
                 LOG(log_error, logtype_afpd, "dsi_cmdreply(%d): %s", dsi->socket, strerror(errno) );
                 if (dsi_disconnect(dsi) != 0)
                     afp_dsi_die(EXITERR_CLNT);
index 69ab4a33d77c3923ff299dc954d3691756327653..41749b944308a6fdbeab9a4788d98e613ffd9c4b 100644 (file)
@@ -893,6 +893,9 @@ static int read_fork(AFPObj *obj, char *ibuf, size_t ibuflen _U_, char *rbuf, si
         goto afp_read_err;
     }
 
+    LOG(log_debug, logtype_afpd, "afp_read(name: \"%s\", offset: %jd, reqcount: %jd)",
+        of_name(ofork), (intmax_t)offset, (intmax_t)reqcount);
+
     savereqcount = reqcount;
     saveoff = offset;
     if (ad_tmplock(ofork->of_ad, eid, ADLOCK_RD, saveoff, savereqcount,ofork->of_refnum) < 0) {
@@ -901,9 +904,13 @@ static int read_fork(AFPObj *obj, char *ibuf, size_t ibuflen _U_, char *rbuf, si
     }
 
     *rbuflen = MIN(reqcount, *rbuflen);
+    LOG(log_debug, logtype_afpd, "afp_read(name: \"%s\", offset: %jd, reqcount: %jd): reading %jd bytes from file",
+        of_name(ofork), (intmax_t)offset, (intmax_t)reqcount, (intmax_t)*rbuflen);
     err = read_file(ofork, eid, offset, nlmask, nlchar, rbuf, rbuflen, xlate);
     if (err < 0)
         goto afp_read_done;
+    LOG(log_debug, logtype_afpd, "afp_read(name: \"%s\", offset: %jd, reqcount: %jd): got %jd bytes from file",
+        of_name(ofork), (intmax_t)offset, (intmax_t)reqcount, (intmax_t)*rbuflen);
 
     /* dsi can stream requests. we can only do this if we're not checking
      * for an end-of-line character. oh well. */
@@ -936,6 +943,7 @@ static int read_fork(AFPObj *obj, char *ibuf, size_t ibuflen _U_, char *rbuf, si
             int fd;
                         
             fd = ad_readfile_init(ofork->of_ad, eid, &offset, 0);
+
             if (dsi_stream_read_file(dsi, fd, offset, dsi->datasize) < 0) {
                 if (errno == EINVAL || errno == ENOSYS)
                     goto afp_read_loop;
@@ -959,12 +967,6 @@ afp_read_loop:
                 goto afp_read_exit;
 
             offset += *rbuflen;
-#ifdef DEBUG1
-            if (obj->options.flags & OPTION_DEBUG) {
-                printf( "(read) reply: %d, %d\n", *rbuflen, dsi->clientID);
-                bprint(rbuf, *rbuflen);
-            }
-#endif
             /* dsi_read() also returns buffer size of next allocation */
             cc = dsi_read(dsi, rbuf, *rbuflen); /* send it off */
             if (cc < 0)
index 7ae0bd24e44e77ccd395232fd5985ddf64431b03..eded2b8f5ad7d5e97980970694f1bf51381d6de8 100644 (file)
@@ -187,7 +187,7 @@ extern void dsi_close (DSI *);
 extern ssize_t dsi_stream_write (DSI *, void *, const size_t, const int mode);
 extern size_t dsi_stream_read (DSI *, void *, const size_t);
 extern int dsi_stream_send (DSI *, void *, size_t);
-extern int dsi_stream_receive (DSI *, void *, const size_t, size_t *);
+extern int dsi_stream_receive (DSI *);
 extern int dsi_disconnect(DSI *dsi);
 
 #ifdef WITH_SENDFILE
@@ -212,6 +212,5 @@ extern void dsi_readdone (DSI *);
     (x)->header.dsi_len = htonl((x)->cmdlen); \
     dsi_stream_send((x), (x)->commands, (x)->cmdlen); \
 } while (0)
-#define dsi_receive(x)    (dsi_stream_receive((x), (x)->commands, \
-                                             DSI_CMDSIZ, &(x)->cmdlen))
+
 #endif /* atalk/dsi.h */
index f924da5a5e0429d6104f4f5bf494189ebefdcbac..ae24535ddd11b85fb9e0a70eaf59f32520e81e72 100644 (file)
@@ -1,6 +1,4 @@
 /*
- * $Id: dsi_cmdreply.c,v 1.5 2009-10-25 06:13:11 didg Exp $
- *
  * Copyright (c) 1997 Adrian Sun (asun@zoology.washington.edu)
  * All rights reserved. See COPYRIGHT.
  */
@@ -11,6 +9,7 @@
 
 #include <stdio.h>
 #include <atalk/dsi.h>
+#include <atalk/logger.h>
 #include <netatalk/endian.h>
 
 /* this assumes that the reply follows right after the command, saving
  * reserved field are assumed to already be set. */ 
 int dsi_cmdreply(DSI *dsi, const int err)
 {
-int ret;
-  dsi->header.dsi_flags = DSIFL_REPLY;
-  /*dsi->header.dsi_command = DSIFUNC_CMD;*/
-  dsi->header.dsi_len = htonl(dsi->datalen);
-  dsi->header.dsi_code = htonl(err);
-
-  ret = dsi_stream_send(dsi, dsi->data, dsi->datalen);
-  return ret;
+    int ret;
+
+    LOG(log_debug, logtype_dsi, "dsi_cmdreply(DSI ID: %u, len: %jd): START",
+        dsi->clientID, (intmax_t)dsi->datalen);
+
+    dsi->header.dsi_flags = DSIFL_REPLY;
+    dsi->header.dsi_len = htonl(dsi->datalen);
+    dsi->header.dsi_code = htonl(err);
+
+    ret = dsi_stream_send(dsi, dsi->data, dsi->datalen);
+
+    LOG(log_debug, logtype_dsi, "dsi_cmdreply(DSI ID: %u, len: %jd): END",
+        dsi->clientID, (intmax_t)dsi->datalen);
+
+    return ret;
 }
index 092544ad3198f51b24354863561941b409709f57..12971511022f00835b61b922871b36bb75fa5789 100644 (file)
@@ -23,6 +23,7 @@
 
 #include <atalk/dsi.h>
 #include <atalk/util.h>
+#include <atalk/logger.h>
 
 /* streaming i/o for afp_read. this is all from the perspective of the
  * client. it basically does the reverse of dsi_write. on first entry,
  * buffer. it returns the amount of stuff still to be read
  * (constrained by the buffer size). */
 ssize_t dsi_readinit(DSI *dsi, void *buf, const size_t buflen,
-                   const size_t size, const int err)
+                     const size_t size, const int err)
 {
+    LOG(log_maxdebug, logtype_dsi, "dsi_readinit: sending %zd bytes from buffer, total size: %zd",
+        buflen, size);
 
-  dsi->flags |= DSI_NOREPLY; /* we will handle our own replies */
-  dsi->header.dsi_flags = DSIFL_REPLY;
-  /*dsi->header.dsi_command = DSIFUNC_CMD;*/
-  dsi->header.dsi_len = htonl(size);
-  dsi->header.dsi_code = htonl(err);
+    dsi->flags |= DSI_NOREPLY; /* we will handle our own replies */
+    dsi->header.dsi_flags = DSIFL_REPLY;
+    dsi->header.dsi_len = htonl(size);
+    dsi->header.dsi_code = htonl(err);
 
-  dsi->in_write++;
-  if (dsi_stream_send(dsi, buf, buflen)) {
-    dsi->datasize = size - buflen;
-    return MIN(dsi->datasize, buflen);
-  }
+    dsi->in_write++;
+    if (dsi_stream_send(dsi, buf, buflen)) {
+        dsi->datasize = size - buflen;
+        LOG(log_maxdebug, logtype_dsi, "dsi_readinit: remaining data for sendfile: %zd", dsi->datasize);
+        return MIN(dsi->datasize, buflen);
+    }
 
-  return -1; /* error */
+    return -1; /* error */
 }
 
 void dsi_readdone(DSI *dsi)
 {
-  dsi->in_write--;
+    dsi->in_write--;
 }
 
 /* send off the data */
 ssize_t dsi_read(DSI *dsi, void *buf, const size_t buflen)
 {
-  size_t len;
-  
-  len  = dsi_stream_write(dsi, buf, buflen, 0);
+    size_t len;
 
-  if (len == buflen) {
-    dsi->datasize -= len;
-    return MIN(dsi->datasize, buflen);
-  }
+    len  = dsi_stream_write(dsi, buf, buflen, 0);
 
-  return -1;
+    if (len == buflen) {
+        dsi->datasize -= len;
+        return MIN(dsi->datasize, buflen);
+    }
+
+    return -1;
 }
index b7f1bb459ae6e89281001b92f6f2274f24149fb7..6c8b51e4b620da5e5ceec9197e6f5150d4db6f99 100644 (file)
@@ -266,7 +266,7 @@ ssize_t dsi_stream_write(DSI *dsi, void *data, const size_t length, int mode)
   dsi->in_write++;
   written = 0;
 
-  LOG(log_maxdebug, logtype_dsi, "dsi_stream_write: sending %u bytes", length);
+  LOG(log_maxdebug, logtype_dsi, "dsi_stream_write(send: %zd bytes): START", length);
 
   if (dsi->flags & DSI_DISCONNECTED)
       return -1;
@@ -305,6 +305,7 @@ ssize_t dsi_stream_write(DSI *dsi, void *data, const size_t length, int mode)
   }
 
   dsi->write_count += written;
+  LOG(log_maxdebug, logtype_dsi, "dsi_stream_write(send: %zd bytes): END", length);
 
 exit:
   dsi->in_write--;
@@ -317,10 +318,12 @@ exit:
 #ifdef WITH_SENDFILE
 ssize_t dsi_stream_read_file(DSI *dsi, int fromfd, off_t offset, const size_t length)
 {
+  int ret = 0;
   size_t written;
   ssize_t len;
+  off_t pos = offset;
 
-  LOG(log_maxdebug, logtype_dsi, "dsi_stream_read_file: sending %u bytes", length);
+  LOG(log_maxdebug, logtype_dsi, "dsi_stream_read_file(send %zd bytes): START", length);
 
   if (dsi->flags & DSI_DISCONNECTED)
       return -1;
@@ -329,14 +332,15 @@ ssize_t dsi_stream_read_file(DSI *dsi, int fromfd, off_t offset, const size_t le
   written = 0;
 
   while (written < length) {
-    len = sys_sendfile(dsi->socket, fromfd, &offset, length - written);
+    len = sys_sendfile(dsi->socket, fromfd, &pos, length - written);
         
     if (len < 0) {
       if (errno == EINTR)
           continue;
-      if (errno == EINVAL || errno == ENOSYS)
-          return -1;
-          
+      if (errno == EINVAL || errno == ENOSYS) {
+          ret = -1;
+          goto exit;
+      }          
       if (errno == EAGAIN || errno == EWOULDBLOCK) {
           if (dsi_peek(dsi)) {
               /* can't go back to blocking mode, exit, the next read
@@ -351,15 +355,20 @@ ssize_t dsi_stream_read_file(DSI *dsi, int fromfd, off_t offset, const size_t le
     }
     else if (!len) {
         /* afpd is going to exit */
-        errno = EIO;
-        return -1; /* I think we're at EOF here... */
+          ret = -1;
+          goto exit;
     }
     else 
         written += len;
   }
 
   dsi->write_count += written;
+
+exit:
   dsi->in_write--;
+  LOG(log_maxdebug, logtype_dsi, "dsi_stream_read_file: sent: %zd", written);
+  if (ret != 0)
+      return -1;
   return written;
 }
 #endif
@@ -423,8 +432,7 @@ int dsi_stream_send(DSI *dsi, void *buf, size_t length)
   size_t towrite;
   ssize_t len;
 
-  LOG(log_maxdebug, logtype_dsi, "dsi_stream_send: %u bytes",
-      length ? length : sizeof(block));
+  LOG(log_maxdebug, logtype_dsi, "dsi_stream_send(%u bytes): START", length);
 
   if (dsi->flags & DSI_DISCONNECTED)
       return 0;
@@ -439,6 +447,7 @@ int dsi_stream_send(DSI *dsi, void *buf, size_t length)
         sizeof(dsi->header.dsi_reserved));
 
   if (!length) { /* just write the header */
+      LOG(log_maxdebug, logtype_dsi, "dsi_stream_send(%u bytes): DSI header, no data", sizeof(block));
     length = (dsi_stream_write(dsi, block, sizeof(block), 0) == sizeof(block));
     return length; /* really 0 on failure, 1 on success */
   }
@@ -482,22 +491,26 @@ int dsi_stream_send(DSI *dsi, void *buf, size_t length)
           iov[1].iov_len -= len;
       }
   }
+
+  LOG(log_maxdebug, logtype_dsi, "dsi_stream_send(%u bytes): END", length);
   
   unblock_sig(dsi);
   return 1;
 }
 
 
-/* ---------------------------------------
- * read data. function on success. 0 on failure. data length gets
- * stored in length variable. this should really use size_t's, but
- * that would require changes elsewhere. */
-int dsi_stream_receive(DSI *dsi, void *buf, const size_t ilength,
-                      size_t *rlength)
+/*!
+ * Read DSI command and data
+ *
+ * @param  dsi   (rw) DSI handle
+ *
+ * @return    DSI function on success, 0 on failure
+ */
+int dsi_stream_receive(DSI *dsi)
 {
   char block[DSI_BLOCKSIZ];
 
-  LOG(log_maxdebug, logtype_dsi, "dsi_stream_receive: %u bytes", ilength);
+  LOG(log_maxdebug, logtype_dsi, "dsi_stream_receive: START");
 
   if (dsi->flags & DSI_DISCONNECTED)
       return 0;
@@ -508,26 +521,22 @@ int dsi_stream_receive(DSI *dsi, void *buf, const size_t ilength,
 
   dsi->header.dsi_flags = block[0];
   dsi->header.dsi_command = block[1];
-  /* FIXME, not the right place, 
-     but we get a server disconnect without reason in the log
-  */
-  if (!block[1]) {
-      LOG(log_error, logtype_dsi, "dsi_stream_receive: invalid packet, fatal");
+
+  if (dsi->header.dsi_command == 0)
       return 0;
-  }
 
-  memcpy(&dsi->header.dsi_requestID, block + 2, 
-        sizeof(dsi->header.dsi_requestID));
+  memcpy(&dsi->header.dsi_requestID, block + 2, sizeof(dsi->header.dsi_requestID));
   memcpy(&dsi->header.dsi_code, block + 4, sizeof(dsi->header.dsi_code));
   memcpy(&dsi->header.dsi_len, block + 8, sizeof(dsi->header.dsi_len));
-  memcpy(&dsi->header.dsi_reserved, block + 12,
-        sizeof(dsi->header.dsi_reserved));
+  memcpy(&dsi->header.dsi_reserved, block + 12, sizeof(dsi->header.dsi_reserved));
   dsi->clientID = ntohs(dsi->header.dsi_requestID);
   
   /* make sure we don't over-write our buffers. */
-  *rlength = min(ntohl(dsi->header.dsi_len), ilength);
-  if (dsi_stream_read(dsi, buf, *rlength) != *rlength
+  dsi->cmdlen = min(ntohl(dsi->header.dsi_len), DSI_CMDSIZ);
+  if (dsi_stream_read(dsi, dsi->commands, dsi->cmdlen) != dsi->cmdlen
     return 0;
 
+  LOG(log_debug, logtype_dsi, "dsi_stream_receive: DSI cmdlen: %zd", dsi->cmdlen);
+
   return block[1];
 }