Windows: Trace log smb_FindFID errors

To assist with debugging, add consistent trace log messages for
smb operations that generate an error because smb_FindFID failed.

LICENSE MIT

Reviewed-on: http://gerrit.openafs.org/545
Reviewed-by: Jeffrey Altman <jaltman@openafs.org>
Tested-by: Jeffrey Altman <jaltman@openafs.org>

diff --git a/src/WINNT/afsd/smb.c b/src/WINNT/afsd/smb.c
index 7e2ddec..0d37332 100644 (file)
--- a/src/WINNT/afsd/smb.c
+++ b/src/WINNT/afsd/smb.c
@@ -2561,10 +2561,13 @@ void smb_StripLastComponent(clientchar_t *outPathp, clientchar_t **lastComponent
         if (typep && cm_ClientStrCmpI(typep, L":$DATA") == 0) {
             *typep = '\0';
             streamp = cm_ClientStrRChr(lastSlashp, L':');
-            if (streamp && cm_ClientStrCmpI(streamp, L":") == 0)
+            if (streamp && cm_ClientStrCmpI(streamp, L":") == 0) {
                 *streamp = '\0';
-            else
+            } else
                 *typep = ':';
+            osi_Log2(smb_logp, "smb_StripLastComponent found stream [%S] type [%S]",
+                     osi_LogSaveClientString(smb_logp,streamp),
+                     osi_LogSaveClientString(smb_logp,typep));
         }
 
         while (1) {
@@ -3583,9 +3586,11 @@ long smb_ReceiveCoreReadRaw(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *outp
              fd, offset.HighPart, offset.LowPart, count);
 
     fidp = smb_FindFID(vcp, fd, 0);
-    if (!fidp)
+    if (!fidp) {
+        osi_Log2(smb_logp, "smb_ReceiveCoreReadRaw Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fd);
         goto send1;
-
+    }
     lock_ObtainMutex(&fidp->mx);
     if (!fidp->scp) {
         lock_ReleaseMutex(&fidp->mx);
@@ -6609,9 +6614,11 @@ long smb_ReceiveCoreFlush(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *outp)
 
     fid = smb_ChainFID(fid, inp);
     fidp = smb_FindFID(vcp, fid, 0);
-    if (!fidp)
+    if (!fidp) {
+        osi_Log2(smb_logp, "smb_ReceiveCoreFlush Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fid);
         return CM_ERROR_BADFD;
-    
+    }
     userp = smb_GetUserFromVCP(vcp, inp);
 
     lock_ObtainMutex(&fidp->mx);
@@ -6928,6 +6935,8 @@ long smb_ReceiveCoreClose(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *outp)
     fid = smb_ChainFID(fid, inp);
     fidp = smb_FindFID(vcp, fid, 0);
     if (!fidp) {
+        osi_Log2(smb_logp, "smb_ReceiveCoreClose Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fid);
         return CM_ERROR_BADFD;
     }
         
@@ -7408,7 +7417,8 @@ long smb_ReceiveCoreWrite(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *outp)
     fd = smb_ChainFID(fd, inp);
     fidp = smb_FindFID(vcp, fd, 0);
     if (!fidp) {
-       osi_Log0(smb_logp, "smb_ReceiveCoreWrite fid not found");
+        osi_Log2(smb_logp, "smb_ReceiveCoreWrite Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fd);
         return CM_ERROR_BADFD;
     }
         
@@ -7668,9 +7678,11 @@ long smb_ReceiveCoreWriteRaw(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *out
         
     fd = smb_ChainFID(fd, inp);
     fidp = smb_FindFID(vcp, fd, 0);
-    if (!fidp)
+    if (!fidp) {
+        osi_Log2(smb_logp, "smb_ReceiveCoreWriteRaw Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fd);
         return CM_ERROR_BADFD;
-
+    }
     lock_ObtainMutex(&fidp->mx);
     if (!fidp->scp) {
         lock_ReleaseMutex(&fidp->mx);
@@ -7826,9 +7838,11 @@ long smb_ReceiveCoreRead(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *outp)
         
     fd = smb_ChainFID(fd, inp);
     fidp = smb_FindFID(vcp, fd, 0);
-    if (!fidp)
+    if (!fidp) {
+        osi_Log2(smb_logp, "smb_ReceiveCoreRead Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fd);
         return CM_ERROR_BADFD;
-
+    }
     lock_ObtainMutex(&fidp->mx);
     if (fidp->flags & SMB_FID_IOCTL) {
        lock_ReleaseMutex(&fidp->mx);
@@ -8278,9 +8292,11 @@ long smb_ReceiveCoreSeek(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *outp)
     /* try to find the file descriptor */
     fd = smb_ChainFID(fd, inp);
     fidp = smb_FindFID(vcp, fd, 0);
-    if (!fidp)
+    if (!fidp) {
+        osi_Log2(smb_logp, "smb_ReceiveCoreSeek Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fd);
        return CM_ERROR_BADFD;
-
+    }
     lock_ObtainMutex(&fidp->mx);
     if (!fidp->scp || (fidp->flags & SMB_FID_IOCTL)) {
        lock_ReleaseMutex(&fidp->mx);

diff --git a/src/WINNT/afsd/smb3.c b/src/WINNT/afsd/smb3.c
index afff9cf..3b19838 100644 (file)
--- a/src/WINNT/afsd/smb3.c
+++ b/src/WINNT/afsd/smb3.c
@@ -1445,9 +1445,11 @@ long smb_nmpipeSetState(smb_vc_t *vcp, smb_tran2Packet_t *p, smb_packet_t *op)
     osi_Log2(smb_logp, "smb_nmpipeSetState for fd[%d] with state[0x%x]", fd, pipeState);
 
     fidp = smb_FindFID(vcp, fd, 0);
-    if (!fidp)
+    if (!fidp) {
+        osi_Log2(smb_logp, "smb_nmpipeSetState Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fd);
        return CM_ERROR_BADFD;
-
+    }
     lock_ObtainMutex(&fidp->mx);
     if (pipeState & 0x8000)
        fidp->flags |= SMB_FID_BLOCKINGPIPE;
@@ -1478,9 +1480,11 @@ long smb_nmpipeTransact(smb_vc_t * vcp, smb_tran2Packet_t *p, smb_packet_t *op)
             fd, p->totalData, p->maxReturnData);
 
     fidp = smb_FindFID(vcp, fd, 0);
-    if (!fidp)
+    if (!fidp) {
+        osi_Log2(smb_logp, "smb_nmpipeTransact Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fd);
        return CM_ERROR_BADFD;
-
+    }
     lock_ObtainMutex(&fidp->mx);
     if (fidp->flags & SMB_FID_RPC) {
        is_rpc = 1;
@@ -1492,6 +1496,8 @@ long smb_nmpipeTransact(smb_vc_t * vcp, smb_tran2Packet_t *p, smb_packet_t *op)
        smb_ReleaseFID(fidp);
     } else {
        /* We only deal with RPC pipes */
+        osi_Log2(smb_logp, "smb_nmpipeTransact Not a RPC vcp 0x%p fid %d",
+                 vcp, fd);
        code = CM_ERROR_BADFD;
     }
 
@@ -2596,7 +2602,7 @@ long smb_ReceiveTran2Open(smb_vc_t *vcp, smb_tran2Packet_t *p, smb_packet_t *op)
 
 #ifndef DFS_SUPPORT
     if (is_ipc) {
-        osi_Log0(smb_logp, "Tran2Open rejecting IPC TID");
+        osi_Log1(smb_logp, "Tran2Open rejecting IPC TID vcp %p", vcp);
        smb_FreeTran2Packet(outp);
        return CM_ERROR_BADFD;
     }
@@ -3701,6 +3707,8 @@ long smb_ReceiveTran2QFileInfo(smb_vc_t *vcp, smb_tran2Packet_t *p, smb_packet_t
     fidp = smb_FindFID(vcp, fid, 0);
 
     if (fidp == NULL) {
+        osi_Log2(smb_logp, "Tran2QFileInfo Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fid);
         smb_SendTran2Error(vcp, p, opx, CM_ERROR_BADFD);
         return 0;
     }
@@ -3868,6 +3876,8 @@ long smb_ReceiveTran2SetFileInfo(smb_vc_t *vcp, smb_tran2Packet_t *p, smb_packet
     fidp = smb_FindFID(vcp, fid, 0);
 
     if (fidp == NULL) {
+        osi_Log2(smb_logp, "Tran2SetFileInfo Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fid);
         smb_SendTran2Error(vcp, p, opx, CM_ERROR_BADFD);
         return 0;
     }
@@ -6325,9 +6335,11 @@ long smb_ReceiveV3LockingX(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *outp)
     fid = smb_ChainFID(fid, inp);
 
     fidp = smb_FindFID(vcp, fid, 0);
-    if (!fidp)
+    if (!fidp) {
+        osi_Log2(smb_logp, "V3LockingX Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fid);
        return CM_ERROR_BADFD;
-    
+    }
     lock_ObtainMutex(&fidp->mx);
     if (fidp->scp && (fidp->scp->flags & CM_SCACHEFLAG_DELETED)) {
         lock_ReleaseMutex(&fidp->mx);
@@ -6611,9 +6623,11 @@ long smb_ReceiveV3GetAttributes(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *
     fid = smb_ChainFID(fid, inp);
         
     fidp = smb_FindFID(vcp, fid, 0);
-    if (!fidp)
+    if (!fidp) {
+        osi_Log2(smb_logp, "V3GetAttributes Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fid);
        return CM_ERROR_BADFD;
-    
+    }
     lock_ObtainMutex(&fidp->mx);
     if (fidp->scp && (fidp->scp->flags & CM_SCACHEFLAG_DELETED)) {
         lock_ReleaseMutex(&fidp->mx);
@@ -6702,9 +6716,11 @@ long smb_ReceiveV3SetAttributes(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *
     fid = smb_ChainFID(fid, inp);
         
     fidp = smb_FindFID(vcp, fid, 0);
-    if (!fidp)
+    if (!fidp) {
+        osi_Log2(smb_logp, "V3SetAttributes Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fid);
        return CM_ERROR_BADFD;
-    
+    }
     lock_ObtainMutex(&fidp->mx);
     if (fidp->scp && (fidp->scp->flags & CM_SCACHEFLAG_DELETED)) {
         lock_ReleaseMutex(&fidp->mx);
@@ -6797,9 +6813,11 @@ long smb_ReceiveV3WriteX(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *outp)
         
     fd = smb_ChainFID(fd, inp);
     fidp = smb_FindFID(vcp, fd, 0);
-    if (!fidp)
+    if (!fidp) {
+        osi_Log2(smb_logp, "smb_ReceiveV3WriteX Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fd);
         return CM_ERROR_BADFD;
-        
+    }
     lock_ObtainMutex(&fidp->mx);
     if (fidp->scp && (fidp->scp->flags & CM_SCACHEFLAG_DELETED)) {
         lock_ReleaseMutex(&fidp->mx);
@@ -6955,6 +6973,8 @@ long smb_ReceiveV3ReadX(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *outp)
     fd = smb_ChainFID(fd, inp);
     fidp = smb_FindFID(vcp, fd, 0);
     if (!fidp) {
+        osi_Log2(smb_logp, "smb_ReceiveV3Read Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fd);
         return CM_ERROR_BADFD;
     }
 
@@ -8183,7 +8203,8 @@ long smb_ReceiveNTTranCreate(smb_vc_t *vcp, smb_packet_t *inp, smb_packet_t *out
     } else {
         baseFidp = smb_FindFID(vcp, baseFid, 0);
         if (!baseFidp) {
-           osi_Log1(smb_logp, "NTTranCreate Invalid fid [%d]", baseFid);
+            osi_Log2(smb_logp, "NTTranCreate Unknown SMB Fid vcp 0x%p fid %d",
+                      vcp, baseFid);
             free(realPathp);
             cm_ReleaseUser(userp);
             return CM_ERROR_BADFD;
@@ -8792,7 +8813,8 @@ long smb_ReceiveNTTranNotifyChange(smb_vc_t *vcp, smb_packet_t *inp,
 
     fidp = smb_FindFID(vcp, fid, 0);
     if (!fidp) {
-        osi_Log1(smb_logp, "ERROR: NotifyChange given invalid fid [%d]", fid);
+        osi_Log2(smb_logp, "NotifyChange Unknown SMB Fid vcp 0x%p fid %d",
+                 vcp, fid);
         return CM_ERROR_BADFD;
     }