windows-buf-waiting-20050605
authorJeffrey Altman <jaltman@secure-endpoints.com>
Sun, 5 Jun 2005 07:44:32 +0000 (07:44 +0000)
committerJeffrey Altman <jaltman@secure-endpoints.com>
Sun, 5 Jun 2005 07:44:32 +0000 (07:44 +0000)
The function cm_SyncOp() can cause threads to wait either because there
is a state conflict on the current use of the cm_scache_t object or
a state conflict on the cm_buf_t object.  Waiting is always performed
on the cm_scache_t object.  However, if the conflict was with the cm_buf_t
object there was no method for waking up the thread when the conflict is
cleared.  Now all of the cm_buf_t waiting functions also take a cm_scache_t
and waiting threads are woken if necessary.

cm_scache_t and cm_buf_t objects now have waitCount and waitRequest fields.
The WAITING flag is now cleared by the waking thread who sets waitCount to
zero.

Many improvements to trace logging for these issues.

src/WINNT/afsd/cm_buf.c
src/WINNT/afsd/cm_buf.h
src/WINNT/afsd/cm_callback.c
src/WINNT/afsd/cm_conn.c
src/WINNT/afsd/cm_conn.h
src/WINNT/afsd/cm_dcache.c
src/WINNT/afsd/cm_scache.c
src/WINNT/afsd/cm_scache.h
src/WINNT/afsd/cm_vnodeops.c
src/WINNT/afsd/smb.c

index 641d450..9b28eb4 100644 (file)
@@ -309,6 +309,9 @@ long buf_Init(int newFile, cm_buf_ops_t *opsp, long nbuffers)
             for (i=0; i<cm_data.buf_nbuffers; i++) {
                 lock_InitializeMutex(&bp->mx, "Buffer mutex");
                 bp->userp = NULL;
+                bp->waitCount = 0;
+                bp->waitRequests = 0;
+                bp->flags &= ~CM_BUF_WAITING;
                 bp++;
             }       
         }
@@ -426,8 +429,10 @@ void buf_Release(cm_buf_t *bp)
 /* wait for reading or writing to clear; called with write-locked
  * buffer, and returns with locked buffer.
  */
-void buf_WaitIO(cm_buf_t *bp)
+void buf_WaitIO(cm_scache_t * scp, cm_buf_t *bp)
 {
+    if (scp)
+        osi_assert(scp->magic == CM_SCACHE_MAGIC);
     osi_assert(bp->magic == CM_BUF_MAGIC);
 
     while (1) {
@@ -439,20 +444,40 @@ void buf_WaitIO(cm_buf_t *bp)
          * the I/O already.  Wait for that guy to figure out what happened,
          * and then check again.
          */
-        if ( bp->flags & CM_BUF_WAITING ) 
+        if ( bp->flags & CM_BUF_WAITING ) {
+            bp->waitCount++;
+            bp->waitRequests++;
             osi_Log1(buf_logp, "buf_WaitIO CM_BUF_WAITING already set for 0x%x", bp);
-
-        bp->flags |= CM_BUF_WAITING;
+        } else {
+            osi_Log1(buf_logp, "buf_WaitIO CM_BUF_WAITING set for 0x%x", bp);
+            bp->flags |= CM_BUF_WAITING;
+            bp->waitCount = bp->waitRequests = 1;
+        }
         osi_SleepM((long) bp, &bp->mx);
         lock_ObtainMutex(&bp->mx);
         osi_Log1(buf_logp, "buf_WaitIO conflict wait done for 0x%x", bp);
+        bp->waitCount--;
+        if (bp->waitCount == 0) {
+            osi_Log1(afsd_logp, "buf_WaitIO CM_BUF_WAITING reset for 0x%x", bp);
+            bp->flags &= ~CM_BUF_WAITING;
+            bp->waitRequests = 0;
+        }
+
+        if ( scp ) {
+            lock_ObtainMutex(&scp->mx);
+            if (scp->flags & CM_SCACHEFLAG_WAITING) {
+                osi_Log1(buf_logp, "buf_WaitIO waking scp 0x%x", scp);
+                osi_Wakeup(&scp->flags);
+                lock_ReleaseMutex(&scp->mx);
+            }
+        }
     }
         
     /* if we get here, the IO is done, but we may have to wakeup people waiting for
      * the I/O to complete.  Do so.
      */
     if (bp->flags & CM_BUF_WAITING) {
-        bp->flags &= ~CM_BUF_WAITING;
+        osi_Log1(buf_logp, "buf_WaitIO Waking bp 0x%x", bp);
         osi_Wakeup((long) bp);
     }
     osi_Log1(buf_logp, "WaitIO finished wait for bp 0x%x", (long) bp);
@@ -550,7 +575,7 @@ void buf_LockedCleanAsync(cm_buf_t *bp, cm_req_t *reqp)
      */
     if (bp->flags & CM_BUF_WAITING) {
         /* turn off flags and wakeup users */
-        bp->flags &= ~CM_BUF_WAITING;
+        osi_Log1(buf_logp, "buf_WaitIO Waking bp 0x%x", bp);
         osi_Wakeup((long) bp);
     }
 }
@@ -833,7 +858,7 @@ long buf_GetNew(struct cm_scache *scp, osi_hyper_t *offsetp, cm_buf_t **bufpp)
 
     /* wait for reads */
     if (bp->flags & CM_BUF_READING)
-        buf_WaitIO(bp);
+        buf_WaitIO(scp, bp);
 
     /* once it has been read once, we can unlock it and return it, still
      * with its refcount held.
@@ -933,7 +958,7 @@ long buf_Get(struct cm_scache *scp, osi_hyper_t *offsetp, cm_buf_t **bufpp)
                 bp->flags |= CM_BUF_ERROR;
                 bp->flags &= ~CM_BUF_READING;
                 if (bp->flags & CM_BUF_WAITING) {
-                    bp->flags &= ~CM_BUF_WAITING;
+                    osi_Log1(buf_logp, "buf_Get Waking bp 0x%x", bp);
                     osi_Wakeup((long) bp);
                 }
                 lock_ReleaseMutex(&bp->mx);
@@ -956,7 +981,7 @@ long buf_Get(struct cm_scache *scp, osi_hyper_t *offsetp, cm_buf_t **bufpp)
             }
             bp->flags &= ~CM_BUF_READING;
             if (bp->flags & CM_BUF_WAITING) {
-                bp->flags &= ~CM_BUF_WAITING;
+                osi_Log1(buf_logp, "buf_Get Waking bp 0x%x", bp);
                 osi_Wakeup((long) bp);
             }
         }
@@ -967,7 +992,7 @@ long buf_Get(struct cm_scache *scp, osi_hyper_t *offsetp, cm_buf_t **bufpp)
      * else started.  We don't care if we return a buffer being cleaned.
      */
     if (bp->flags & CM_BUF_READING)
-        buf_WaitIO(bp);
+        buf_WaitIO(scp, bp);
 
     /* once it has been read once, we can unlock it and return it, still
      * with its refcount held.
@@ -1030,13 +1055,13 @@ void buf_CleanAsync(cm_buf_t *bp, cm_req_t *reqp)
 }       
 
 /* wait for a buffer's cleaning to finish */
-void buf_CleanWait(cm_buf_t *bp)
+void buf_CleanWait(cm_scache_t * scp, cm_buf_t *bp)
 {
     osi_assert(bp->magic == CM_BUF_MAGIC);
 
     lock_ObtainMutex(&bp->mx);
     if (bp->flags & CM_BUF_WRITING) {
-        buf_WaitIO(bp);
+        buf_WaitIO(scp, bp);
     }
     lock_ReleaseMutex(&bp->mx);
 }       
@@ -1096,7 +1121,7 @@ long buf_CleanAndReset(void)
                 /* now no locks are held; clean buffer and go on */
                 cm_InitReq(&req);
                 buf_CleanAsync(bp, &req);
-                buf_CleanWait(bp);
+                buf_CleanWait(NULL, bp);
 
                 /* relock and release buffer */
                 lock_ObtainWrite(&buf_globalLock);
@@ -1207,7 +1232,7 @@ long buf_Truncate(cm_scache_t *scp, cm_user_t *userp, cm_req_t *reqp,
 
         if (cm_FidCmp(&bufp->fid, &scp->fid) == 0 &&
              LargeIntegerLessThan(*sizep, bufEnd)) {
-            buf_WaitIO(bufp);
+            buf_WaitIO(scp, bufp);
         }
         lock_ObtainMutex(&scp->mx);
        
@@ -1316,7 +1341,7 @@ long buf_FlushCleanPages(cm_scache_t *scp, cm_user_t *userp, cm_req_t *reqp)
 
             /* start cleaning the buffer, and wait for it to finish */
             buf_LockedCleanAsync(bp, reqp);
-            buf_WaitIO(bp);
+            buf_WaitIO(scp, bp);
             lock_ReleaseMutex(&bp->mx);
 
             code = (*cm_buf_opsp->Stabilizep)(scp, userp, reqp);
@@ -1387,7 +1412,7 @@ long buf_CleanVnode(struct cm_scache *scp, cm_user_t *userp, cm_req_t *reqp)
                 lock_ReleaseMutex(&bp->mx);
             }   
             buf_CleanAsync(bp, reqp);
-            buf_CleanWait(bp);
+            buf_CleanWait(scp, bp);
             lock_ObtainMutex(&bp->mx);
             if (bp->flags & CM_BUF_ERROR) {
                 if (code == 0 || code == -1) 
index 8174d0d..d597d8d 100644 (file)
@@ -95,6 +95,10 @@ typedef struct cm_buf {
 #ifdef DISKCACHE95
     cm_diskcache_t *dcp;        /* diskcache structure */
 #endif /* DISKCACHE95 */
+
+    /* syncop state */
+    afs_uint32 waitCount;           /* number of threads waiting */
+    afs_uint32 waitRequests;        /* num of thread wait requests */
 } cm_buf_t;
 
 /* values for cmFlags */
@@ -140,7 +144,7 @@ extern void buf_Release(cm_buf_t *);
 
 extern void buf_Hold(cm_buf_t *);
 
-extern void buf_WaitIO(cm_buf_t *);
+extern void buf_WaitIO(cm_scache_t *, cm_buf_t *);
 
 extern void buf_LockedRelease(cm_buf_t *);
 
@@ -162,7 +166,7 @@ extern long buf_GetNew(struct cm_scache *, osi_hyper_t *, cm_buf_t **);
 
 extern void buf_CleanAsync(cm_buf_t *, cm_req_t *);
 
-extern void buf_CleanWait(cm_buf_t *);
+extern void buf_CleanWait(cm_scache_t *, cm_buf_t *);
 
 extern void buf_SetDirty(cm_buf_t *);
 
index e572697..4fa09dc 100644 (file)
@@ -1701,8 +1701,9 @@ long cm_GetCallback(cm_scache_t *scp, struct cm_user *userp,
 
         /* now check to see if we got an error */
         if (code) {
-            osi_Log4(afsd_logp, "GetCallback Failed code 0x%x scp 0x%x cell %d vol %d", 
-                     code, scp, scp->fid.cell, scp->fid.volume);
+            osi_Log2(afsd_logp, "GetCallback Failed code 0x%x scp 0x%x -->",code, scp);
+            osi_Log4(afsd_logp, "            cell %d vol %d vn %d uniq %d",
+                     scp->fid.cell, scp->fid.volume, scp->fid.vnode, scp->fid.unique);
             return code;
         }
     }
index e4f4533..485fa74 100644 (file)
@@ -303,8 +303,8 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
     }
 
     /* special codes:  missing volumes */
-    else if (errorCode == VNOVOL || errorCode == VMOVED || errorCode == VOFFLINE
-         || errorCode == VSALVAGE || errorCode == VNOSERVICE) 
+    else if (errorCode == VNOVOL || errorCode == VMOVED || errorCode == VOFFLINE ||
+             errorCode == VSALVAGE || errorCode == VNOSERVICE || errorCode == VIO) 
     {       
         /* Log server being offline for this volume */
         osi_Log4(afsd_logp, "cm_Analyze found server %d.%d.%d.%d marked offline for a volume",
@@ -398,21 +398,37 @@ cm_Analyze(cm_conn_t *connp, cm_user_t *userp, cm_req_t *reqp,
             char * s = "unknown error";
             switch ( errorCode ) {
             case RXKADINCONSISTENCY: s = "RXKADINCONSISTENCY"; break;
-            case RXKADPACKETSHORT  : s = "RXKADPACKETSHORT  "; break;
-            case RXKADLEVELFAIL    : s = "RXKADLEVELFAIL    "; break;
-            case RXKADTICKETLEN    : s = "RXKADTICKETLEN    "; break;
+            case RXKADPACKETSHORT  : s = "RXKADPACKETSHORT";   break;
+            case RXKADLEVELFAIL    : s = "RXKADLEVELFAIL";     break;
+            case RXKADTICKETLEN    : s = "RXKADTICKETLEN";     break;
             case RXKADOUTOFSEQUENCE: s = "RXKADOUTOFSEQUENCE"; break;
-            case RXKADNOAUTH       : s = "RXKADNOAUTH       "; break;
-            case RXKADBADKEY       : s = "RXKADBADKEY       "; break;
-            case RXKADBADTICKET    : s = "RXKADBADTICKET    "; break;
-            case RXKADUNKNOWNKEY   : s = "RXKADUNKNOWNKEY   "; break;
-            case RXKADEXPIRED      : s = "RXKADEXPIRED      "; break;
-            case RXKADSEALEDINCON  : s = "RXKADSEALEDINCON  "; break;
-            case RXKADDATALEN      : s = "RXKADDATALEN      "; break;
-            case RXKADILLEGALLEVEL : s = "RXKADILLEGALLEVEL "; break;
+            case RXKADNOAUTH       : s = "RXKADNOAUTH";        break;
+            case RXKADBADKEY       : s = "RXKADBADKEY";        break;
+            case RXKADBADTICKET    : s = "RXKADBADTICKET";     break;
+            case RXKADUNKNOWNKEY   : s = "RXKADUNKNOWNKEY";    break;
+            case RXKADEXPIRED      : s = "RXKADEXPIRED";       break;
+            case RXKADSEALEDINCON  : s = "RXKADSEALEDINCON";   break;
+            case RXKADDATALEN      : s = "RXKADDATALEN";       break;
+            case RXKADILLEGALLEVEL : s = "RXKADILLEGALLEVEL";  break;
+            case VSALVAGE          : s = "VSALVAGE";           break;
+            case VNOVNODE          : s = "VNOVNODE";           break;
+            case VNOVOL            : s = "VNOVOL";             break;
+            case VVOLEXISTS        : s = "VVOLEXISTS";         break;
+            case VNOSERVICE        : s = "VNOSERVICE";         break;
+            case VOFFLINE          : s = "VOFFLINE";           break;
+            case VONLINE           : s = "VONLINE";            break;
+            case VDISKFULL         : s = "VDISKFULL";          break;
+            case VOVERQUOTA        : s = "VOVERQUOTA";         break;
+            case VBUSY             : s = "VBUSY";              break;
+            case VMOVED            : s = "VMOVED";             break;
+            case VIO               : s = "VIO";                break;
+            case VRESTRICTED       : s = "VRESTRICTED";        break;
+            case VRESTARTING       : s = "VRESTARTING";        break;
+            case VREADONLY         : s = "VREADONLY";          break;
             }
             osi_Log2(afsd_logp, "cm_Analyze: ignoring error code 0x%x (%s)", 
                      errorCode, s);
+            retry = 0;
         }
     }
 
index 0e9e023..e993eda 100644 (file)
@@ -77,6 +77,12 @@ typedef struct cm_req {
 #define VMOVED         111     /* Volume has moved to another server;
                                   do a VGetVolumeInfo to THIS server to find
                                   out where */
+#define VIO             112     /* Vnode temporarily unaccessible, but not known
+                                 * to be permanently bad. */
+#define VRESTRICTED     120     /* Volume is restricted from using one or more
+                                 * of the given residencies; do a
+                                 * vos examine to find out the current
+                                 * restrictions. */
 
 #define VRESTARTING    -100    /* server is restarting, otherwise similar to 
                                   VBUSY above.  This is negative so that old
index d5d7c70..f7bbb8d 100644 (file)
@@ -379,9 +379,7 @@ int cm_HaveBuffer(cm_scache_t *scp, cm_buf_t *bufp, int isBufLocked)
     int code;
     if (!cm_HaveCallback(scp))
         return 0;
-    if ((bufp->cmFlags
-          & (CM_BUF_CMFETCHING | CM_BUF_CMFULLYFETCHED))
-         == (CM_BUF_CMFETCHING | CM_BUF_CMFULLYFETCHED))
+    if ((bufp->cmFlags & (CM_BUF_CMFETCHING | CM_BUF_CMFULLYFETCHED)) == (CM_BUF_CMFETCHING | CM_BUF_CMFULLYFETCHED))
         return 1;
     if (bufp->dataVersion == scp->dataVersion)
         return 1;
@@ -443,8 +441,7 @@ long cm_CheckFetchRange(cm_scache_t *scp, osi_hyper_t *startBasep, long length,
         bp = buf_Find(scp, &tbase);
         /* We cheat slightly by not locking the bp mutex. */
         if (bp) {
-            if ((bp->cmFlags
-                  & (CM_BUF_CMFETCHING | CM_BUF_CMSTORING)) == 0
+            if ((bp->cmFlags & (CM_BUF_CMFETCHING | CM_BUF_CMSTORING)) == 0
                  && bp->dataVersion != scp->dataVersion)
                 stop = 1;
             buf_Release(bp);
@@ -907,7 +904,7 @@ long cm_SetupFetchBIOD(cm_scache_t *scp, osi_hyper_t *offsetp,
 
         code = buf_Get(scp, &pageBase, &tbp);
         if (code) {
-            lock_ReleaseMutex(&cm_bufGetMutex);
+            //lock_ReleaseMutex(&cm_bufGetMutex);
             lock_ObtainMutex(&scp->mx);
             cm_SyncOpDone(scp, NULL, CM_SCACHESYNC_NEEDCALLBACK | CM_SCACHESYNC_GETSTATUS);
             return code;
@@ -1097,9 +1094,10 @@ void cm_ReleaseBIOD(cm_bulkIO_t *biop, int isStore)
         /* turn off writing and wakeup users */
         if (isStore) {
             if (bufp->flags & CM_BUF_WAITING) {
+                osi_Log1(afsd_logp, "cm_ReleaseBIOD Waking bp 0x%x", bufp);
                 osi_Wakeup((long) bufp);
             }
-            bufp->flags &= ~(CM_BUF_WAITING | CM_BUF_WRITING | CM_BUF_DIRTY);
+            bufp->flags &= ~(CM_BUF_WRITING | CM_BUF_DIRTY);
         }
 
         lock_ReleaseMutex(&bufp->mx);
@@ -1125,7 +1123,7 @@ long cm_GetBuffer(cm_scache_t *scp, cm_buf_t *bufp, int *cpffp, cm_user_t *up,
     AFSCallBack callback;
     AFSVolSync volSync;
     char *bufferp;
-    cm_buf_t *tbufp;           /* buf we're filling */
+    cm_buf_t *tbufp;                   /* buf we're filling */
     osi_queueData_t *qdp;              /* q element we're scanning */
     AFSFid tfid;
     struct rx_call *callp;
@@ -1319,7 +1317,7 @@ long cm_GetBuffer(cm_scache_t *scp, cm_buf_t *bufp, int *cpffp, cm_user_t *up,
                 tbufp->cmFlags |= CM_BUF_CMFULLYFETCHED;
                 lock_ObtainMutex(&scp->mx);
                 if (scp->flags & CM_SCACHEFLAG_WAITING) {
-                    scp->flags &= ~CM_SCACHEFLAG_WAITING;
+                    osi_Log1(afsd_logp, "CM GetBuffer Waking scp 0x%x", scp);
                     osi_Wakeup((long) &scp->flags);
                 }
                 if (cpffp && !*cpffp && !osi_QPrev(&qdp->q)) {
@@ -1412,5 +1410,6 @@ long cm_GetBuffer(cm_scache_t *scp, cm_buf_t *bufp, int *cpffp, cm_user_t *up,
 
     if (code == 0) 
         cm_MergeStatus(scp, &afsStatus, &volSync, up, 0);
+    
     return code;
 }
index 304edbc..30d010c 100644 (file)
@@ -100,6 +100,12 @@ cm_scache_t *cm_GetNewSCache(void)
             scp->serverModTime = 0;
             scp->dataVersion = 0;
             scp->bulkStatProgress = hzero;
+            scp->waitCount = 0;
+
+            scp->fid.vnode = 0;
+            scp->fid.volume = 0;
+            scp->fid.unique = 0;
+            scp->fid.cell = 0;
 
             /* discard callback */
             if (scp->cbServerp) {
@@ -281,9 +287,9 @@ cm_ShutdownSCache(void)
     for ( scp = cm_data.scacheLRULastp; scp;
           scp = (cm_scache_t *) osi_QPrev(&scp->q) ) {
         if (scp->randomACLp) {
-            lock_ObtainWrite(&scp->mx);
+            lock_ObtainMutex(&scp->mx);
             cm_FreeAllACLEnts(scp);
-            lock_ReleaseWrite(&scp->mx);
+            lock_ReleaseMutex(&scp->mx);
         }
         lock_FinalizeMutex(&scp->mx);
         lock_FinalizeRWLock(&scp->bufCreateLock);
@@ -318,6 +324,8 @@ void cm_InitSCache(int newFile, long maxSCaches)
                 scp->openWrites = 0;
                 scp->openShares = 0;
                 scp->openExcls = 0;
+                scp->waitCount = 0;
+                scp->flags &= ~CM_SCACHEFLAG_WAITING;
             }
         }
         cm_allFileLocks = NULL;
@@ -412,7 +420,7 @@ long cm_GetSCache(cm_fid_t *fidp, cm_scache_t **outScpp, cm_user_t *userp,
          
     if (cm_freelanceEnabled && special) {
         osi_Log0(afsd_logp,"cm_getSCache Freelance and special");
-        if (fidp->vnode > 1 && fidp->vnode <= cm_localMountPoints + 2) {
+        if (fidp->vnode > 1 && fidp->vnode <= cm_noLocalMountPoints + 2) {
            lock_ObtainMutex(&cm_Freelance_Lock);
             mp =(cm_localMountPoints+fidp->vnode-2)->mountPointStringp;
             lock_ReleaseMutex(&cm_Freelance_Lock);
@@ -432,7 +440,7 @@ long cm_GetSCache(cm_fid_t *fidp, cm_scache_t **outScpp, cm_user_t *userp,
         cm_data.hashTablep[hash]=scp;
         scp->flags |= CM_SCACHEFLAG_INHASH;
         scp->refCount = 1;
-        if (fidp->vnode > 1 && fidp->vnode <= cm_localMountPoints + 2)
+        if (fidp->vnode > 1 && fidp->vnode <= cm_noLocalMountPoints + 2)
             scp->fileType = (cm_localMountPoints+fidp->vnode-2)->fileType;
         else 
             scp->fileType = CM_SCACHETYPE_INVALID;
@@ -658,7 +666,8 @@ long cm_SyncOp(cm_scache_t *scp, cm_buf_t *bufp, cm_user_t *up, cm_req_t *reqp,
                 goto sleep;
             }
             if (bufp && (bufp->cmFlags & (CM_BUF_CMFETCHING | CM_BUF_CMSTORING))) {
-                osi_Log1(afsd_logp, "CM SyncOp scp 0x%x is BUF_CMFETCHING|BUF_CMSTORING want FETCHDATA", scp);
+                osi_Log2(afsd_logp, "CM SyncOp scp 0x%x bufp 0x%x is BUF_CMFETCHING|BUF_CMSTORING want FETCHDATA", scp, bufp);
+                sleepOnBuf = 1;
                 goto sleep;
             }
         }
@@ -670,7 +679,8 @@ long cm_SyncOp(cm_scache_t *scp, cm_buf_t *bufp, cm_user_t *up, cm_req_t *reqp,
                 goto sleep;
             }
             if (bufp && (bufp->cmFlags & (CM_BUF_CMFETCHING | CM_BUF_CMSTORING))) {
-                osi_Log1(afsd_logp, "CM SyncOp scp 0x%x is BUF_CMFETCHING|BUF_CMSTORING want STOREDATA", scp);
+                osi_Log2(afsd_logp, "CM SyncOp scp 0x%x bufp 0x%x is BUF_CMFETCHING|BUF_CMSTORING want STOREDATA", scp, bufp);
+                sleepOnBuf = 1;
                 goto sleep;
             }
         }
@@ -718,8 +728,7 @@ long cm_SyncOp(cm_scache_t *scp, cm_buf_t *bufp, cm_user_t *up, cm_req_t *reqp,
              * operations don't change any of the data that we're
              * changing here.
              */
-            if (scp->flags & (CM_SCACHEFLAG_FETCHING | CM_SCACHEFLAG_STORING
-                               | CM_SCACHEFLAG_SIZESTORING)) {
+            if (scp->flags & (CM_SCACHEFLAG_FETCHING | CM_SCACHEFLAG_STORING | CM_SCACHEFLAG_SIZESTORING)) {
                 osi_Log1(afsd_logp, "CM SyncOp scp 0x%x is FETCHING|STORING|SIZESTORING want SETSTATUS", scp);
                 goto sleep;
             }
@@ -733,11 +742,9 @@ long cm_SyncOp(cm_scache_t *scp, cm_buf_t *bufp, cm_user_t *up, cm_req_t *reqp,
                 osi_Log1(afsd_logp, "CM SyncOp scp 0x%x is FETCHING want READ", scp);
                 goto sleep;
             }
-            if (bufp && ((bufp->cmFlags
-                           & (CM_BUF_CMFETCHING
-                               | CM_BUF_CMFULLYFETCHED))
-                          == CM_BUF_CMFETCHING)) {
-                osi_Log1(afsd_logp, "CM SyncOp scp 0x%x is BUF_CMFETCHING want READ", scp);
+            if (bufp && ((bufp->cmFlags & (CM_BUF_CMFETCHING | CM_BUF_CMFULLYFETCHED)) == CM_BUF_CMFETCHING)) {
+                osi_Log2(afsd_logp, "CM SyncOp scp 0x%x bufp 0x%x is BUF_CMFETCHING want READ", scp, bufp);
+                sleepOnBuf = 1;
                 goto sleep;
             }
         }
@@ -751,7 +758,8 @@ long cm_SyncOp(cm_scache_t *scp, cm_buf_t *bufp, cm_user_t *up, cm_req_t *reqp,
                 goto sleep;
             }
             if (bufp && (bufp->cmFlags & (CM_BUF_CMFETCHING | CM_BUF_CMSTORING))) {
-                osi_Log1(afsd_logp, "CM SyncOp scp 0x%x is BUF_CMFETCHING|BUF_CMSTORING want WRITE", scp);
+                osi_Log2(afsd_logp, "CM SyncOp scp 0x%x bufp 0x%x is BUF_CMFETCHING|BUF_CMSTORING want WRITE", scp, bufp);
+                sleepOnBuf = 1;
                 goto sleep;
             }
         }
@@ -822,10 +830,14 @@ long cm_SyncOp(cm_scache_t *scp, cm_buf_t *bufp, cm_user_t *up, cm_req_t *reqp,
         /* wait here, then try again */
         osi_Log1(afsd_logp, "CM SyncOp sleeping scp 0x%x", scp);
         if ( scp->flags & CM_SCACHEFLAG_WAITING ) {
-            osi_Log1(afsd_logp, "CM SyncOp CM_SCACHEFLAG_WAITING already set for 0x%x", scp);
+            scp->waitCount++;
+            scp->waitRequests++;
+            osi_Log3(afsd_logp, "CM SyncOp CM_SCACHEFLAG_WAITING already set for 0x%x; %d threads; %d requests", 
+                     scp, scp->waitCount, scp->waitRequests);
         } else {
             osi_Log1(afsd_logp, "CM SyncOp CM_SCACHEFLAG_WAITING set for 0x%x", scp);
             scp->flags |= CM_SCACHEFLAG_WAITING;
+            scp->waitCount = scp->waitRequests = 1;
         }
         if (bufLocked) 
             lock_ReleaseMutex(&bufp->mx);
@@ -833,7 +845,14 @@ long cm_SyncOp(cm_scache_t *scp, cm_buf_t *bufp, cm_user_t *up, cm_req_t *reqp,
         if (bufLocked) 
             lock_ObtainMutex(&bufp->mx);
         lock_ObtainMutex(&scp->mx);
-        osi_Log1(afsd_logp, "CM SyncOp woke! scp 0x%x", scp);
+        scp->waitCount--;
+        osi_Log3(afsd_logp, "CM SyncOp woke! scp 0x%x; still waiting %d threads of %d requests", 
+                 scp, scp->waitCount, scp->waitRequests);
+        if (scp->waitCount == 0) {
+            osi_Log1(afsd_logp, "CM SyncOp CM_SCACHEFLAG_WAITING reset for 0x%x", scp);
+            scp->flags &= ~CM_SCACHEFLAG_WAITING;
+            scp->waitRequests = 0;
+        }
     } /* big while loop */
         
     /* now, update the recorded state for RPC-type calls */
@@ -930,8 +949,11 @@ void cm_SyncOpDone(cm_scache_t *scp, cm_buf_t *bufp, long flags)
         osi_QRemove((osi_queue_t **) &scp->bufReadsp, &qdp->q);
         osi_QDFree(qdp);
         if (bufp) {
-            bufp->cmFlags &=
-                ~(CM_BUF_CMFETCHING | CM_BUF_CMFULLYFETCHED);
+            bufp->cmFlags &= ~(CM_BUF_CMFETCHING | CM_BUF_CMFULLYFETCHED);
+            if (bufp->flags & CM_BUF_WAITING) {
+                osi_Log2(afsd_logp, "CM SyncOpDone Waking [scp 0x%x] bufp 0x%x", scp, bufp);
+                osi_Wakeup((long) &bufp);
+            }
             buf_Release(bufp);
         }
     }
@@ -949,14 +971,17 @@ void cm_SyncOpDone(cm_scache_t *scp, cm_buf_t *bufp, long flags)
         osi_QDFree(qdp);
         if (bufp) {
             bufp->cmFlags &= ~CM_BUF_CMSTORING;
+            if (bufp->flags & CM_BUF_WAITING) {
+                osi_Log2(afsd_logp, "CM SyncOpDone Waking [scp 0x%x] bufp 0x%x", scp, bufp);
+                osi_Wakeup((long) &bufp);
+            }
             buf_Release(bufp);
         }
     }
 
     /* and wakeup anyone who is waiting */
     if (scp->flags & CM_SCACHEFLAG_WAITING) {
-        osi_Log1(afsd_logp, "CM SyncOp CM_SCACHEFLAG_WAITING reset for 0x%x", scp);
-        scp->flags &= ~CM_SCACHEFLAG_WAITING;
+        osi_Log1(afsd_logp, "CM SyncOpDone Waking scp 0x%x", scp);
         osi_Wakeup((long) &scp->flags);
     }
 }       
index a17988e..ab947be 100644 (file)
@@ -130,6 +130,10 @@ typedef struct cm_scache {
         afs_uint16 openWrites;         /* open for writing */
         afs_uint16 openShares;         /* open for read excl */
         afs_uint16 openExcls;          /* open for exclusives */
+
+        /* syncop state */
+        afs_uint32 waitCount;           /* number of threads waiting */
+        afs_uint32 waitRequests;        /* num of thread wait requests */
 } cm_scache_t;
 
 /* mask field - tell what has been modified */
index 555023a..13e735c 100644 (file)
@@ -128,7 +128,6 @@ char cm_LegalChars[256] = {
 int cm_Is8Dot3(char *namep)
 {
     int sawDot = 0;
-    int sawUpper = 0, sawLower = 0;
     unsigned char tc;
     int charCount = 0;
         
@@ -153,10 +152,6 @@ int cm_Is8Dot3(char *namep)
         }
         if (cm_LegalChars[tc] == 0)
             return 0;
-        if (tc >= 'A' && tc <= 'Z')
-            sawUpper = 1;
-        else if (tc >= 'a' && tc <= 'z')
-            sawLower = 1;
         charCount++;
         if (!sawDot && charCount > 8)
             /* more than 8 chars in name */
@@ -165,14 +160,6 @@ int cm_Is8Dot3(char *namep)
             /* more than 3 chars in extension */
             return 0;
     }
-    /*
-     * Used to check that all characters were the same case.
-     * This doesn't help 16-bit apps, and meanwhile it causes the
-     * MS-DOS Command Prompt to misbehave; see Sybase defect 10709.
-     *
-     if (sawUpper && sawLower)
-         return 0;
-     */
     return 1;
 }
 
index 27703fa..87693ba 100644 (file)
@@ -2250,8 +2250,51 @@ void smb_SendPacket(smb_vc_t *vcp, smb_packet_t *inp)
     code = Netbios(ncbp, dos_ncb);
 #endif /* !DJGPP */
         
-    if (code != 0)
-        osi_Log1(smb_logp, "SendPacket failure code %d", code);
+    if (code != 0) {
+        char * s;
+        switch ( code ) {
+        case 0x01: s = "llegal buffer length                     "; break; 
+        case 0x03: s = "illegal command                          "; break; 
+        case 0x05: s = "command timed out                        "; break; 
+        case 0x06: s = "message incomplete, issue another command"; break; 
+        case 0x07: s = "illegal buffer address                   "; break; 
+        case 0x08: s = "session number out of range              "; break; 
+        case 0x09: s = "no resource available                    "; break; 
+        case 0x0a: s = "session closed                           "; break; 
+        case 0x0b: s = "command cancelled                        "; break; 
+        case 0x0d: s = "duplicate name                           "; break; 
+        case 0x0e: s = "name table full                          "; break; 
+        case 0x0f: s = "no deletions, name has active sessions   "; break; 
+        case 0x11: s = "local session table full                 "; break; 
+        case 0x12: s = "remote session table full                "; break; 
+        case 0x13: s = "illegal name number                      "; break; 
+        case 0x14: s = "no callname                              "; break; 
+        case 0x15: s = "cannot put * in NCB_NAME                 "; break; 
+        case 0x16: s = "name in use on remote adapter            "; break; 
+        case 0x17: s = "name deleted                             "; break; 
+        case 0x18: s = "session ended abnormally                 "; break; 
+        case 0x19: s = "name conflict detected                   "; break; 
+        case 0x21: s = "interface busy, IRET before retrying     "; break; 
+        case 0x22: s = "too many commands outstanding, retry later"; break;
+        case 0x23: s = "ncb_lana_num field invalid               "; break; 
+        case 0x24: s = "command completed while cancel occurring "; break; 
+        case 0x26: s = "command not valid to cancel              "; break; 
+        case 0x30: s = "name defined by anther local process     "; break; 
+        case 0x34: s = "environment undefined. RESET required    "; break; 
+        case 0x35: s = "required OS resources exhausted          "; break; 
+        case 0x36: s = "max number of applications exceeded      "; break; 
+        case 0x37: s = "no saps available for netbios            "; break; 
+        case 0x38: s = "requested resources are not available    "; break; 
+        case 0x39: s = "invalid ncb address or length > segment  "; break; 
+        case 0x3B: s = "invalid NCB DDID                         "; break; 
+        case 0x3C: s = "lock of user area failed                 "; break; 
+        case 0x3f: s = "NETBIOS not loaded                       "; break; 
+        case 0x40: s = "system error                             "; break;                 
+        default:
+            s = "unknown error";
+        }
+        osi_Log2(smb_logp, "SendPacket failure code %d \"%s\"", code, s);
+    }
 
     if (localNCB)
         FreeNCB(ncbp);
@@ -5519,14 +5562,10 @@ long smb_WriteData(smb_fid_t *fidp, osi_hyper_t *offsetp, long count, char *op,
     lock_ObtainMutex(&scp->mx);
 
     /* start by looking up the file's end */
-    osi_Log1(smb_logp, "smb_WriteData fid %d calling cm_SyncOp NEEDCALLBACK|SETSTATUS|GETSTATUS",
-              fidp->fid);
     code = cm_SyncOp(scp, NULL, userp, &req, 0,
                       CM_SCACHESYNC_NEEDCALLBACK
                       | CM_SCACHESYNC_SETSTATUS
                       | CM_SCACHESYNC_GETSTATUS);
-    osi_Log2(smb_logp, "smb_WriteData fid %d calling cm_SyncOp NEEDCALLBACK|SETSTATUS|GETSTATUS returns %d",
-              fidp->fid,code);
     if (code) 
         goto done;
         
@@ -5606,14 +5645,10 @@ long smb_WriteData(smb_fid_t *fidp, osi_hyper_t *offsetp, long count, char *op,
 
             /* now get the data in the cache */
             while (1) {
-                osi_Log1(smb_logp, "smb_WriteData fid %d calling cm_SyncOp NEEDCALLBACK|WRITE|BUFLOCKED",
-                          fidp->fid);
                 code = cm_SyncOp(scp, bufferp, userp, &req, 0,
                                   CM_SCACHESYNC_NEEDCALLBACK
                                   | CM_SCACHESYNC_WRITE
                                   | CM_SCACHESYNC_BUFLOCKED);
-                osi_Log2(smb_logp, "smb_WriteData fid %d calling cm_SyncOp NEEDCALLBACK|WRITE|BUFLOCKED returns %d",
-                          fidp->fid,code);
                 if (code) 
                     goto done;