[OpenAFS] Another bout of Windows failure

Jeff Blaine jblaine@kickflop.net
Wed, 16 Sep 2009 14:31:55 -0400


Windows XP
OpenAFS 1.5.63 with RxMaxMTU = 1244
Cisco VPN

Cannot get to \\afs\our.cell.com

Tried with all default OpenAFS install checkboxes
     Long delay, loud noise, error

Tried with all default OpenAFS install checkboxes cleared
     Long delay, empty explorer window with location
     \\afs\our.cell.com

1.  ping -f -l 1244 afsserver works fine (for all servers)

2.  Cell data is configured properly

3.  rxdebug can see the servers fine

4.  C:\WINDOWS\Temp\afsd.log is empty

5.  C:\WINDOWS\Temp\afsd_init.log contains:

9/16/2009 1:45:26 PM: locale =  C
9/16/2009 1:45:26 PM: running on 2000+ - using RegisterServiceCtrlHandlerEx
9/16/2009 1:45:26 PM: C:\Program 
Files\OpenAFS\Client\Program\afsd_service.exe version 1.5.6300
9/16/2009 1:45:26 PM: Num of Process Modules: 45
9/16/2009 1:45:26 PM: C:\Program Files\OpenAFS\Client\Program\libosi.dll 
version 1.5.6300
9/16/2009 1:45:26 PM: C:\Program Files\OpenAFS\Common\afsrpc.dll version 
1.5.6300
9/16/2009 1:45:26 PM: C:\Program Files\OpenAFS\Common\afspthread.dll 
version 1.5.6300
9/16/2009 1:45:26 PM: C:\Program Files\OpenAFS\Common\afsauthent.dll 
version 1.5.6300
9/16/2009 1:45:26 PM: C:\Program Files\OpenAFS\Common\libafsconf.dll 
version 1.5.6300
9/16/2009 1:45:26 PM: osi_InitDebug code 0
9/16/2009 1:45:26 PM: gethostname MM160913-PC
9/16/2009 1:45:26 PM: PriorityClass 0x80
9/16/2009 1:45:26 PM: Lock Order Validation Off
9/16/2009 1:45:26 PM: Trace Options = 0
9/16/2009 1:45:26 PM: Default trace buffer size 10000
9/16/2009 1:45:26 PM: osi_LogCreate log addr 735950
9/16/2009 1:45:26 PM: Default cache size 98304
9/16/2009 1:45:26 PM: Chunk size 262144 (18)
9/16/2009 1:45:26 PM: Block size 4096
9/16/2009 1:45:26 PM: Defaulting to 4 background daemons
9/16/2009 1:45:26 PM: Defaulting to 25 server threads
9/16/2009 1:45:26 PM: Default status cache entries: 10000
9/16/2009 1:45:26 PM: Default volume cache entries: 3333
9/16/2009 1:45:26 PM: Default cell cache entries: 1024
9/16/2009 1:45:26 PM: Logoff token transfer on
9/16/2009 1:45:26 PM: Logoff token transfer timeout 120 seconds
9/16/2009 1:45:26 PM: Default root volume name root.afs
9/16/2009 1:45:26 PM: Mount root /afs
9/16/2009 1:45:26 PM: Default cache path C:\WINDOWS\TEMP\AFSCache
9/16/2009 1:45:26 PM: Cache type is FILE
9/16/2009 1:45:26 PM: Cache Validation on Startup
9/16/2009 1:45:26 PM: Set to trap on panic
9/16/2009 1:45:26 PM: Sys name x86_win32 i386_w2k i386_nt40
9/16/2009 1:45:26 PM: SecurityLevel is clear
9/16/2009 1:45:26 PM: CM ForceAnonVLDB is off
9/16/2009 1:45:26 PM: DNS will not be used to find AFS cell servers
9/16/2009 1:45:26 PM: Freelance client feature is not activated
9/16/2009 1:45:26 PM: SMB Server Unicode Support is enabled
9/16/2009 1:45:26 PM: Dot files/dirs will be marked hidden
9/16/2009 1:45:26 PM: Maximum number of multiplexed sessions is 50
9/16/2009 1:45:26 PM: Maximum number of VCs per server is 100
9/16/2009 1:45:26 PM: SMB authentication type is EXTENDED
9/16/2009 1:45:26 PM: RX Jumbograms are disabled
9/16/2009 1:45:26 PM: RX extraPackets is 2176
9/16/2009 1:45:26 PM: RX udpbufsize is 262144
9/16/2009 1:45:26 PM: RX Peer Statistics gathering is enabled
9/16/2009 1:45:26 PM: RX Process Statistics gathering is enabled
9/16/2009 1:45:26 PM: RX Hot Thread is enabled
9/16/2009 1:45:26 PM: CM CallBackPort is 7001
9/16/2009 1:45:26 PM: EnableServerLocks: server requested
9/16/2009 1:45:26 PM: CM DeleteReadOnly is 0
9/16/2009 1:45:26 PM: CM BPlusTrees is 1
9/16/2009 1:45:26 PM: No PrefetchExecutableExtensions
9/16/2009 1:45:26 PM: CM OfflineReadOnlyIsValid is 0
9/16/2009 1:45:26 PM: CM GiveUpAllCallBacks is 0
9/16/2009 1:45:26 PM: CM FollowBackupPath is 0
9/16/2009 1:45:26 PM: CM PerFileAccessCheck is 0
9/16/2009 1:45:26 PM: First Network address ac1f0633 SubnetMask ffffe000
9/16/2009 1:45:26 PM: lanmanworkstation : ExtSessTimeout 300
9/16/2009 1:45:26 PM: ConnDeadTimeout is 50
9/16/2009 1:45:26 PM: HardDeadTimeout is 120
9/16/2009 1:45:26 PM: IdleDeadTimeout is 50
9/16/2009 1:45:26 PM: Cache File "C:\WINDOWS\TEMP\AFSCache" already exists
9/16/2009 1:45:26 PM: Existing File Size: 00000000:0731047C
9/16/2009 1:45:26 PM: Granularity - 10000
9/16/2009 1:45:26 PM: Previous session terminated prematurely
9/16/2009 1:45:26 PM: Building AFS Cache from scratch
9/16/2009 1:45:26 PM: Volume Serial Number: 0xc48cfdb7
9/16/2009 1:45:26 PM: Machine SID: S-1-5-21-190924995-1388955969-2638521644
9/16/2009 1:45:26 PM: Initializing Uuid to 
e5934458-7cec-4eaf-a898-913eb9c07cd5
9/16/2009 1:45:26 PM: Initializing Volume Data
9/16/2009 1:45:26 PM: Initializing Cell Data
9/16/2009 1:45:26 PM: Initializing ACL Data
9/16/2009 1:45:26 PM: Initializing Stat Data
9/16/2009 1:45:26 PM: CM UseDNLC = 1
9/16/2009 1:45:26 PM: CM DebugDNLC = 0
9/16/2009 1:45:26 PM: Initializing Data Buffers
9/16/2009 1:45:26 PM: Cache Initialization Complete
9/16/2009 1:45:26 PM: cm_InitMappedMemory code 0
9/16/2009 1:45:26 PM: rx_SetNoJumbo successful
9/16/2009 1:45:26 PM: rx_SetUdpBufSize 262144
9/16/2009 1:45:26 PM: rx_Init code 0
9/16/2009 1:45:26 PM: rx_NewService addr 736660
9/16/2009 1:45:26 PM: rx_NewService addr 7366a8
9/16/2009 1:45:26 PM: rx_StartServer
9/16/2009 1:45:26 PM: cm_GetRootCellName code 0, cm_freelanceEnabled= 0, 
rcn= rcf.our.com
9/16/2009 1:45:26 PM: cm_GetCell addr 2572fc8
9/16/2009 1:45:27 PM: RPC server listening
9/16/2009 1:45:27 PM: cm_FindVolumeByName code 0 root vol 24a0700
9/16/2009 1:45:27 PM: cm_GetSCache code 0 scache 269f408
9/16/2009 1:45:27 PM: StoreAnsiFilenames = 0
9/16/2009 1:45:27 PM: EnableSMBAsyncStore = 1
9/16/2009 1:45:27 PM: SMBAsyncStoreSize = 131072
9/16/2009 1:45:27 PM: LAN adapter number 6
9/16/2009 1:45:27 PM: Using >AFS< as SMB server name
9/16/2009 1:45:27 PM: smb_localNamep is >AFS<
9/16/2009 1:45:27 PM: Netbios NCBRESET lana 6 succeeded
9/16/2009 1:45:27 PM: lana_list.length 1
9/16/2009 1:45:27 PM: Netbios NCBADDNAME lana=6 code=0 retcode=0 complete=0
9/16/2009 1:45:27 PM: Netbios NCBADDNAME added new name >AFS             <
9/16/2009 1:45:27 PM: Netbios NCBADDNAME succeeded on lana 6

9/16/2009 1:45:27 PM: smb_NetbiosInit smb_LANadapter=6
9/16/2009 1:45:27 PM: MsV1_0SetProcessOption success
9/16/2009 1:45:27 PM: Setting SMB server domain name to [MM160913-PC]
9/16/2009 1:45:27 PM: smb_StartListeners
9/16/2009 1:45:27 PM: Microsoft SMB Redirector supports Extended Timeouts
9/16/2009 1:45:27 PM: smb_Init complete
9/16/2009 1:45:27 PM: GlobalAutoMap thread completed
9/16/2009 1:45:27 PM: cm_InitDaemon complete
9/16/2009 1:45:27 PM: MpsSvc Service could not be opened for query: 0x424
9/16/2009 1:45:27 PM: AutoStart 0x2
9/16/2009 1:45:27 PM: daemonCheckDownInterval is 180
9/16/2009 1:45:27 PM: daemonCheckUpInterval is 240
9/16/2009 1:45:27 PM: daemonCheckVolInterval is 3600
9/16/2009 1:45:27 PM: daemonCheckCBInterval is 60
9/16/2009 1:45:27 PM: daemonCheckVolCBInterval is 0
9/16/2009 1:45:27 PM: daemonCheckLockInterval is 60
9/16/2009 1:45:27 PM: daemonCheckTokenInterval is 180
9/16/2009 1:45:27 PM: daemonCheckOfflineVolInterval is 600
9/16/2009 1:45:27 PM: daemonPerformanceTuningInterval is 0
9/16/2009 1:45:27 PM: Windows Firewall Configuration succeeded
9/16/2009 1:46:24 PM: Request S(05)QueryPathInfo_ReceiveTran2QPathInfo 
duration 56140 ms user 0x1 "our\jblaine" pid 0x12c8 mid 0x380 tid 0x2 
"(null)" path? "(null)" afid (0.0.0.0)
9/16/2009 1:47:20 PM: Request S(10)_ReceiveTran2GetDfsReferral duration 
77484 ms user 0x0 "" pid 0x4 mid 0x9c1 tid 0x7 "(null)" path? "(null)" 
afid (0.0.0.0)
9/16/2009 1:48:16 PM: Request (75)ReceiveV3TreeConnectX duration 56031 
ms user 0x1 "our\jblaine" pid 0xfeff mid 0x5ec1 tid 0xc "/r/" path? 
"?????" afid (0.0.0.0)
9/16/2009 1:49:14 PM: Request S(10)_ReceiveTran2GetDfsReferral duration 
56000 ms user 0x0 "" pid 0x4 mid 0x7f82 tid 0xd "(null)" path? "(null)" 
afid (0.0.0.0)
9/16/2009 1:54:01 PM: Request S(01)FindFirst_ReceiveTran2SearchDir 
duration 56000 ms user 0x1 "our\jblaine" pid 0xd84 mid 0x3d42 tid 0x2 
"(null)" path? "(null)" afid (0.0.0.0)
9/16/2009 1:54:57 PM: Request S(01)FindFirst_ReceiveTran2SearchDir 
duration 56000 ms user 0x1 "our\jblaine" pid 0xd84 mid 0x58c2 tid 0x2 
"(null)" path? "(null)" afid (0.0.0.0)
9/16/2009 2:23:24 PM: Request S(10)_ReceiveTran2GetDfsReferral duration 
56000 ms user 0x0 "" pid 0x4 mid 0x9ac1 tid 0x12 "(null)" path? "(null)" 
afid (0.0.0.0)