Xsan Volume Frequently Unmount on day

himanshu's picture

Hi All,

We have this customer who has a 64 TB Xsan Volume, used for Editing. From
last three days they are facing this issue of Volume unmount. This is happening
frequently. We could not resolve this issue even after doing the following
steps.

1. Swapped the FC cables to the metadata Storage Box, Promise. 2. Checked the
Promise Box for any errors or indications of a possible Metadata LUN drive
failure. 3. Ran a Filesystem check, cvfsck -j, cvfsck -vn /vw.

None of the above were a relief to this issue. If the Volume unmounts, then we
need to power cycle the whole setup to bring back the Volume to work again.
From the logs, we can learn that there is an issue in the I/O to the Metadata
LUN. I have searched the discussions forums, but did not find any solid
solution for this issue.

A helping hand in this matter is highly appreciated from the Gurus and admin of
Xsan out there. I have pasted few excerpts from the 'cvlog' for reference.
Please help me resolve this issue. Thanks in advance.

Mac OS X Server (Xserve) 10.5.8 / Xsan 2.2.1
Xsan Volume 64 TB
Available Free space 3 TB
Promise Vtrak 4Gbps / 2 TB HDD

Thanks
Himanshu Baruwala

Xsan log

(1) Xsan Log
n:55998] Administrator Logout.
[1222 04:41:47.221618] 0xa0144720 (Debug) Node [69] [cpod.rudra.xlan:55804] connected.
[1222 04:41:47.221793] 0xa0144720 (Debug) Active service - NSS ping from cpod.rudra.xlan:55803.
[1222 04:41:47] 0xb93c5000 (Info) Node [69] [cpod.rudra.xlan:55804] Administrator Logout.
[1222 04:42:19.546318] 0xa0144720 (Debug) Node [70] [cpmdc.rudra.xlan:56005] connected.
[1222 04:42:19.546563] 0xa0144720 (Debug) Active service - NSS ping from cpmdc.rudra.xlan:56004.
[1222 04:42:19] 0xb93c5000 (Info) Node [70] [cpmdc.rudra.xlan:56005] Administrator Logout.
[1222 04:42:46.844242] 0xa0144720 (Debug) Node [71] [cpod.rudra.xlan:55809] connected.
[1222 04:42:46.844795] 0xa0144720 (Debug) Active service - NSS ping from cpod.rudra.xlan:55808.
[1222 04:42:46] 0xb93c5000 (Info) Node [71] [cpod.rudra.xlan:55809] Administrator Logout.
[1222 04:43:20.163489] 0xa0144720 (Debug) Active service - NSS ping from cpmdc.rudra.xlan:56011.
[1222 04:43:20.164063] 0xa0144720 (Debug) Node [72] [cpmdc.rudra.xlan:56012] connected.
[1222 04:43:20] 0xb93c5000 (Info) Node [72] [cpmdc.rudra.xlan:56012] Administrator Logout.
[1222 04:43:46.844518] 0xa0144720 (Debug) Node [73] [cpod.rudra.xlan:55814] connected.
[1222 04:43:46.844683] 0xa0144720 (Debug) Active service - NSS ping from cpod.rudra.xlan:55813.
[1222 04:43:46] 0xb93c5000 (Info) Node [73] [cpod.rudra.xlan:55814] Administrator Logout.
[1222 04:44:19.546898] 0xa0144720 (Debug) Active service - NSS ping from cpmdc.rudra.xlan:56018.
[1222 04:44:19.547612] 0xa0144720 (Debug) Node [74] [cpmdc.rudra.xlan:56019] connected.
[1222 04:44:19] 0xb93c5000 (Info) Node [74] [cpmdc.rudra.xlan:56019] Administrator Logout.
[1222 04:44:47.264262] 0xa0144720 (Debug) Node [76] [cpod.rudra.xlan:55819] connected.
[1222 04:44:47.264423] 0xa0144720 (Debug) Active service - NSS ping from cpod.rudra.xlan:55818.
[1222 04:44:47] 0xb93c5000 (Info) Node [76] [cpod.rudra.xlan:55819] Administrator Logout.
[1222 04:45:20.328083] 0xa0144720 (Debug) Active service - NSS ping from cpmdc.rudra.xlan:56025.
[1222 04:45:20.328521] 0xa0144720 (Debug) Node [77] [cpmdc.rudra.xlan:56026] connected.
[1222 04:45:20] 0xb93c5000 (Info) Node [77] [cpmdc.rudra.xlan:56026] Administrator Logout.
[1222 04:45:46.845992] 0xa0144720 (Debug) Node [78] [cpod.rudra.xlan:55824] connected.
[1222 04:45:46.846184] 0xa0144720 (Debug) Active service - NSS ping from cpod.rudra.xlan:55823.
[1222 04:45:46] 0xb93c5000 (Info) Node [78] [cpod.rudra.xlan:55824] Administrator Logout.
[1222 04:46:19.546060] 0xa0144720 (Debug) Active service - NSS ping from cpmdc.rudra.xlan:56032.
[1222 04:46:19.546539] 0xa0144720 (Debug) Node [79] [cpmdc.rudra.xlan:56033] connected.
[1222 04:46:19] 0xb93c5000 (Info) Node [79] [cpmdc.rudra.xlan:56033] Administrator Logout.
[1222 04:46:46.845535] 0xa0144720 (Debug) Active service - NSS ping from cpod.rudra.xlan:55828.
[1222 04:46:46.845591] 0xa0144720 (Debug) Node [80] [cpod.rudra.xlan:55829] connected.
[1222 04:46:46] 0xb93c5000 (Info) Node [80] [cpod.rudra.xlan:55829] Administrator Logout.
[1222 04:47:20.494089] 0xa0144720 (Debug) Active service - NSS ping from cpmdc.rudra.xlan:56039.
[1222 04:47:20.494429] 0xa0144720 (Debug) Node [81] [cpmdc.rudra.xlan:56040] connected.
[1222 04:47:20] 0xb93c5000 (Info) Node [81] [cpmdc.rudra.xlan:56040] Administrator Logout.
[1222 04:47:47.205140] 0xa0144720 (Debug) Node [82] [cpod.rudra.xlan:55834] connected.
[1222 04:47:47.205294] 0xa0144720 (Debug) Active service - NSS ping from cpod.rudra.xlan:55833.
[1222 04:47:47] 0xb93c5000 (Info) Node [82] [cpod.rudra.xlan:55834] Administrator Logout.
[1222 04:48:19.548740] 0xa0144720 (Debug) Node [83] [cpmdc.rudra.xlan:56047] connected.
[1222 04:48:19.548904] 0xa0144720 (Debug) Active service - NSS ping from cpmdc.rudra.xlan:56046.
[1222 04:48:19] 0xb93c5000 (Info) Node [83] [cpmdc.rudra.xlan:56047] Administrator Logout.
[1222 04:48:46.843760] 0xa0144720 (Debug) Node [84] [cpod.rudra.xlan:55839] connected.
[1222 04:48:46.843930] 0xa0144720 (Debug) Active service - NSS ping from cpod.rudra.xlan:55838.
[1222 04:48:46] 0xb93c5000 (Info) Node [84] [cpod.rudra.xlan:55839] Administrator Logout.
[1222 04:49:20.700494] 0xa0144720 (Debug) Active service - NSS ping from cpmdc.rudra.xlan:56053.
[1222 04:49:20.700879] 0xa0144720 (Debug) Node [85] [cpmdc.rudra.xlan:56054] connected.
[1222 04:49:20] 0xb93c5000 (Info) Node [85] [cpmdc.rudra.xlan:56054] Administrator Logout.
[1222 04:49:46.844486] 0xa0144720 (Debug) Node [86] [cpod.rudra.xlan:55844] connected.
[1222 04:49:46.844656] 0xa0144720 (Debug) Active service - NSS ping from cpod.rudra.xlan:55843.
[1222 04:49:46] 0xb93c5000 (Info) Node [86] [cpod.rudra.xlan:55844] Administrator Logout.
[1222 04:50:19.548783] 0xa0144720 (Debug) Active service - NSS ping from cpmdc.rudra.xlan:56060.
[1222 04:50:19.549493] 0xa0144720 (Debug) Node [87] [cpmdc.rudra.xlan:56061] connected.
[1222 04:50:19] 0xb93c5000 (Info) Node [87] [cpmdc.rudra.xlan:56061] Administrator Logout.
[1222 07:01:52] 0xa0144720 (Info) Server Revision 3.5.0 Build 7443 Branch branches_35X (411.3)
[1222 07:01:52] 0xa0144720 (Info) Built for Darwin 9.0 i386
[1222 07:01:52] 0xa0144720 (Info) Created on Mon Dec 7 12:35:35 PST 2009
[1222 07:01:52] 0xa0144720 (Info) Built in /SourceCache/XsanFS/XsanFS-411.3
[1222 07:01:52] 0xa0144720 (Info)
Configuration:
DiskTypes-5
Disks-5
StripeGroups-2
MaxConnections-139
ThreadPoolSize-256
StripeAlignSize-16
FsBlockSize-65536
BufferCacheSize-32M
InodeCacheSize-8192
RestoreJournal-Disabled
RestoreJournalDir-None
[1222 07:01:52] 0xa0144720 (Info) Self (192.168.1.254) IP address is 192.168.1.254.
[1222 07:01:52.470873] 0xa0144720 (Debug) No fsports file - port range enforcement disabled.
[1222 07:01:52] 0xa0144720 (Info) Listening on TCP socket 192.168.1.254:49161
[1222 07:01:52] 0xa0144720 (Info) Node [0] [192.168.1.254:49161] File System Manager Login.
[1222 07:01:52] 0xa0144720 (Info) ForceStripeAlignment is enabled.
[1222 07:01:52] 0xa0144720 (Info) Service standing by on host '192.168.1.254:49161'.
[1222 07:01:53] 0xb0185000 (Info) DiskArb: XSAN does not exist
[1222 07:01:53] 0xb0185000 (Info) DiskArb: XSAN appeared ('/Volumes/XSAN', 0x0e000009)
[1222 07:02:03] 0xb8dad000 (Info) DiskArb: won't set Spotlight search level; volume is not hosted locally[1222 13:27:55] 0xa0144720 (Info) Server Revision 3.5.0 Build 7443 Branch branches_35X (411.3)
[1222 13:27:55] 0xa0144720 (Info) Built for Darwin 9.0 i386
[1222 13:27:55] 0xa0144720 (Info) Created on Mon Dec 7 12:35:35 PST 2009
[1222 13:27:55] 0xa0144720 (Info) Built in /SourceCache/XsanFS/XsanFS-411.3
[1222 13:27:55] 0xa0144720 (Info)
Configuration:
DiskTypes-5
Disks-5
StripeGroups-2
MaxConnections-139
ThreadPoolSize-256
StripeAlignSize-16
FsBlockSize-65536
BufferCacheSize-32M
InodeCacheSize-8192
RestoreJournal-Disabled
RestoreJournalDir-None
[1222 13:27:55] 0xa0144720 (Info) Self (192.168.1.254) IP address is 192.168.1.254.
[1222 13:27:55.365814] 0xa0144720 (Debug) No fsports file - port range enforcement disabled.
[1222 13:27:55] 0xa0144720 (Info) Listening on TCP socket 192.168.1.254:49161
[1222 13:27:55] 0xa0144720 (Info) Node [0] [192.168.1.254:49161] File System Manager Login.
[1222 13:27:55] 0xa0144720 (Info) ForceStripeAlignment is enabled.
[1222 13:27:55] 0xa0144720 (Info) Service standing by on host '192.168.1.254:49161'.
[1222 13:27:55] 0xb0185000 (Info) DiskArb: XSAN does not exist
[1222 13:27:56] 0xb0185000 (Info) DiskArb: XSAN appeared ('/Volumes/XSAN', 0x0e000009)
[1222 13:28:06] 0xb8dad000 (Info) DiskArb: won't set Spotlight search level; volume is not hosted locally[1223 07:56:42] 0xa0144720 (Info) Server Revision 3.5.0 Build 7443 Branch branches_35X (411.3)
[1223 07:56:42] 0xa0144720 (Info) Built for Darwin 9.0 i386
[1223 07:56:42] 0xa0144720 (Info) Created on Mon Dec 7 12:35:35 PST 2009
[1223 07:56:42] 0xa0144720 (Info) Built in /SourceCache/XsanFS/XsanFS-411.3
[1223 07:56:42] 0xa0144720 (Info)
Configuration:
DiskTypes-5
Disks-5
StripeGroups-2
MaxConnections-139
ThreadPoolSize-256
StripeAlignSize-16
FsBlockSize-65536
BufferCacheSize-32M
InodeCacheSize-8192
RestoreJournal-Disabled
RestoreJournalDir-None
[1223 07:56:42] 0xa0144720 (Info) Self (192.168.1.254) IP address is 192.168.1.254.
[1223 07:56:42.901779] 0xa0144720 (Debug) No fsports file - port range enforcement disabled.
[1223 07:56:42] 0xa0144720 (Info) Listening on TCP socket 192.168.1.254:49161
[1223 07:56:42] 0xa0144720 (Info) Node [0] [192.168.1.254:49161] File System Manager Login.
[1223 07:56:42] 0xa0144720 (Info) ForceStripeAlignment is enabled.
[1223 07:56:42] 0xa0144720 (Info) Service standing by on host '192.168.1.254:49161'.
[1223 07:56:47] 0xb0185000 (Info) DiskArb: XSAN does not exist
[1223 07:56:47] 0xb0185000 (Info) DiskArb: XSAN appeared ('/Volumes/XSAN', 0x0e000009)
[1223 07:56:57] 0xb8dad000 (Info) DiskArb: won't set Spotlight search level; volume is not hosted locally[1223 08:10:34] 0xa0144720 (Info) Server Revision 3.5.0 Build 7443 Branch branches_35X (411.3)
[1223 08:10:34] 0xa0144720 (Info) Built for Darwin 9.0 i386
[1223 08:10:34] 0xa0144720 (Info) Created on Mon Dec 7 12:35:35 PST 2009
[1223 08:10:34] 0xa0144720 (Info) Built in /SourceCache/XsanFS/XsanFS-411.3
[1223 08:10:34] 0xa0144720 (Info)
Configuration:
DiskTypes-5
Disks-5
StripeGroups-2
MaxConnections-139
ThreadPoolSize-256
StripeAlignSize-16
FsBlockSize-65536
BufferCacheSize-32M
InodeCacheSize-8192
RestoreJournal-Disabled
RestoreJournalDir-None
[1223 08:10:34] 0xa0144720 (Info) Self (192.168.1.254) IP address is 192.168.1.254.
[1223 08:10:34.905631] 0xa0144720 (Debug) No fsports file - port range enforcement disabled.
[1223 08:10:34] 0xa0144720 (Info) Listening on TCP socket 192.168.1.254:49161
[1223 08:10:34] 0xa0144720 (Info) Node [0] [192.168.1.254:49161] File System Manager Login.
[1223 08:10:34] 0xa0144720 (Info) ForceStripeAlignment is enabled.
[1223 08:10:34] 0xa0144720 (Info) Service standing by on host '192.168.1.254:49161'.
[1223 08:10:42] 0xb0185000 (Info) DiskArb: XSAN does not exist
[1223 08:10:42] 0xb0185000 (Info) DiskArb: XSAN appeared ('/Volumes/XSAN', 0x0e000009)
[1223 08:10:52] 0xb8dad000 (Info) DiskArb: won't set Spotlight search level; volume is not hosted locally

(2) System Log

ate: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [481] [0x15790000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [482] [0x1581a000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [483] [0x15791000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [484] [0x15887000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [485] [0x15792000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [486] [0x1581f000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [487] [0x15789000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [488] [0x15864000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [489] [0x15794000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [490] [0x15820000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [491] [0x15795000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [492] [0x158a1000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [493] [0x15796000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [494] [0x15821000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [495] [0x15797000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [496] [0x15865000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [497] [0x1578e000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [498] [0x15822000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: [499] [0x15799000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:04:58 cpod kernel[0]: Wait queue requests: 0
Dec 23 11:04:58 cpod kernel[0]: Notification ports:
Dec 23 11:04:58 cpod kernel[0]: Port[0x0]: 0x149394ec, RefCon: 0x4e4c69a5
Dec 23 11:04:58 cpod kernel[0]: Port[0x1]: 0x14db0dac, RefCon: 0x4e4c69da
Dec 23 11:04:58 cpod kernel[0]: === [DumpStatsEnd] ===
Dec 23 11:05:22 cpod authorizationhost[119]: MechanismInvoke 0x115040 retainCount 2
Dec 23 11:05:22 cpod SecurityAgent[121]: MechanismInvoke 0x13c1c0 retainCount 1
Dec 23 11:05:22 cpod SecurityAgent[121]: NSSecureTextFieldCell detected a field editor ((null)) that is not a NSTextView subclass designed to work with the cell. Ignoring...
Dec 23 11:05:22 cpod SecurityAgent[121]: NSExceptionHandler has recorded the following exception:\nNSRangeException -- *** -[NSCFArray objectAtIndex:]: index (0) beyond bounds (0)\nStack trace: 0x3719a 0x90c04e3b 0x90197dcb 0x90197e0a 0x90759fcf 0x906d7788 0x7089b 0x710da 0x5a46d 0x6eb58 0x6267b 0x65a4e 0x67781 0x77760 0xd648 0x12c40 0x129f3 0xd18a 0x90716d93 0x900f9ff5 0x9011e6b8 0x9011eaa8 0x94fd82ac 0x94fd80c5 0x94fd7f39 0x93adf6d5 0x93adef88 0x93ad7f9f 0x10fc7 0x202a 0x1
Dec 23 11:05:23 cpod loginwindow[51]: Login Window - Returned from Security Agent
Dec 23 11:05:23 cpod SecurityAgent[121]: MechanismDestroy 0x13c1c0 retainCount 1
Dec 23 11:05:23 cpod authorizationhost[119]: MechanismDestroy 0x115040 retainCount 2
Dec 23 11:05:23 cpod loginwindow[51]: USER_PROCESS: 51 console
Dec 23 11:05:23 cpod com.apple.launchd[1] (com.apple.UserEventAgent-LoginWindow[114]): Exited: Terminated
Dec 23 11:05:23 cpod com.apple.launchd[488] (0x103850.AppleVNCServer[117]): Failed to add kevent for PID 117. Will unload at MIG return
Dec 23 11:05:23 cpod com.apple.launchd[488] (org.x.startx): Unknown key for boolean: EnableTransactions
Dec 23 11:05:23 cpod kernel[0]: de 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod ARDAgent [497]: ********ARDAgent Launched********
Dec 23 11:05:23 cpod kernel[0]: [470] [0x1581b000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod kernel[0]: [471] [0x1578b000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod kernel[0]: [472] [0x15862000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod kernel[0]: [473] [0x1578c000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod kernel[0]: [474] [0x1581c000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod kernel[0]: [475] [0x1578d000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod ARDAgent [497]: ********ARDAgent Ready********
Dec 23 11:05:23 cpod kernel[0]: [476] [0x15898000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod kernel[0]: [477] [0x15784000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod kernel[0]: [478] [0x1581d000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod kernel[0]: [479] [0x1578f000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod kernel[0]: [480] [0x15859000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:23 cpod kernel[0]: [481] [0x15790000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [482] [0x1581a000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [483] [0x15791000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [484] [0x15887000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [485] [0x15792000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [486] [0x1581f000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [487] [0x15789000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [488] [0x15864000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [489] [0x15794000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [490] [0x15820000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [491] [0x15795000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [492] [0x158a1000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [493] [0x15796000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [494] [0x15821000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [495] [0x15797000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [496] [0x15865000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [497] [0x1578e000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [498] [0x15822000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: [499] [0x15799000] Req OpCode 0402 from: blued (67) status: 12 state: 0 timeout: 30000
Dec 23 11:05:24 cpod kernel[0]: Wait queue requests: 0
Dec 23 11:05:24 cpod kernel[0]: Notification ports:
Dec 23 11:05:24 cpod kernel[0]: Port[0x0]: 0x149394ec, RefCon: 0x4e4c69a5
Dec 23 11:05:25 cpod kernel[0]: === [DumpStatsEnd] ===
Dec 23 11:05:25 cpod /System/Library/CoreServices/coreservicesd[83]: SFLSharePointsEntry::CreateDSRecord: dsCreateRecordAndOpen(admin's Public Folder) returned -14135
Dec 23 11:05:25 cpod /System/Library/CoreServices/coreservicesd[83]: SFLSharePointsEntry::CreateDSRecord: dsCreateRecordAndOpen(Public) returned -14135
Dec 23 11:05:25 cpod /System/Library/CoreServices/coreservicesd[83]: SFLSharePointsEntry::CreateDSRecord: dsCreateRecordAndOpen(Groups) returned -14135
Dec 23 11:05:25 cpod /System/Library/CoreServices/coreservicesd[83]: SFLSharePointsEntry::CreateDSRecord: dsCreateRecordAndOpen(Users) returned -14135
Dec 23 11:05:36 cpod Xsan Admin[522]: ERROR: No session for computer cpmdc (386D51D6-4264-4609-A8E5-EF02D8F7D36F)
Dec 23 11:05:36: --- last message repeated 1 time ---
Dec 23 11:05:36 cpod Xsan Admin[522]: ERROR: No session for computer cpod (4876ACFF-986A-49E1-919F-DC9C6B2115B1)
Dec 23 11:05:36 cpod Xsan Admin[522]: ERROR: -[SANKeychainAccess userNameAndPasswordForServiceName:outUserName:allowInteraction:outModDate:]: Unknown error -25293
Dec 23 11:05:37: --- last message repeated 1 time ---
Dec 23 11:05:37 cpod /usr/sbin/ocspd[523]: starting
Dec 23 11:05:37 cpod Xsan Admin[522]: ERROR: Error reading volume statistics for xsan: kOfflineError (0)
Dec 23 11:05:37 cpod Xsan Admin[522]: ERROR: Error getting list of volumes: kOfflineError (0)
Dec 23 11:06:07: --- last message repeated 1 time ---
Dec 23 11:06:27 cpod mDNSResponder[31]: mDNSPlatformSendUDP sendto failed to send packet on InterfaceID 00811000 en0/4 to 224.0.0.251:5353 skt 7 error -1 errno 65 (No route to host) 2958524514
Dec 23 11:06:27 cpod mDNSResponder[31]: mDNSPlatformSendUDP sendto failed to send packet on InterfaceID 00813000 en1/4 to 224.0.0.251:5353 skt 7 error -1 errno 65 (No route to host) 2958524514
Dec 23 11:06:28 cpod /usr/sbin/serialnumberd[108]: _MulticastMessage(): sendto failed, errno = 65 (No route to host)
Dec 23 11:06:50: --- last message repeated 1 time ---
Dec 23 11:06:50 cpod login[594]: USER_PROCESS: 594 ttys000
Dec 23 11:07:24 cpod login[594]: DEAD_PROCESS: 594 ttys000

(3) Xsan Fsmpm Log

client is registered, on port 49153.
[1223 08:10:35] 0xa0144720 (debug) NSS: New mount registered for 'XSAN'.
[1223 08:10:35] 0xa0144720 (debug) NSS: FSS mount list for client 10.1.1.254 (id 192.168.1.254) - XSAN
[1223 08:10:35] 0xb038d000 INFO Starting Disk rescan
[1223 08:10:35] 0xb038d000 INFO Disk rescan delay completed
[1223 08:10:35] 0xb038d000 INFO Disk rescan found 6 disks
[1223 08:10:36] 0xb038d000 INFO Starting Disk rescan
[1223 08:10:42] 0xb0595000 NOTICE PortMapper: Mount Event for /Volumes/XSAN on /dev/disk7
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-4096-2147483671-4060217830-1001
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (1001)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying GID (0)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Found record for "wheel"
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID S-1-5-21-4096-2147483671-4060217830-1001 maps to GUID ABCDEFAB-CDEF-ABCD-EFAB-CDEF00000000
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-4096-2147483671-4060217830-1001
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (1001)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying GID (0)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Found record for "wheel"
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID S-1-5-21-4096-2147483671-4060217830-1001 maps to GUID ABCDEFAB-CDEF-ABCD-EFAB-CDEF00000000
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-4096-2147483671-4060217830-2004
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (2004)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying UID (502)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by UID failed, generating fake GUID for UID 502
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID S-1-5-21-4096-2147483671-4060217830-2004 maps to GUID FFFFEEEE-DDDD-CCCC-BBBB-AAAA000001F6
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-4096-2147483671-4060217830-2004
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (2004)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying UID (502)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by UID failed, generating fake GUID for UID 502
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID S-1-5-21-4096-2147483671-4060217830-2004 maps to GUID FFFFEEEE-DDDD-CCCC-BBBB-AAAA000001F6
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-2163564381-2853518302-908416156-2002
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (2002)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying UID (501)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Found record for "admin"
[1223 08:10:42] 0xa0144720 (debug) PortMapper: user record has no SID, generating from UID (501)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: GenerateSIDFromRID: rid (2002) sid(S-1-5-21-0987654321-0987654321-0987654321-2002)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID S-1-5-21-2163564381-2853518302-908416156-2002 maps to GUID 09B880D7-1253-48CA-B604-7D741A83DAD3
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-2163564381-2853518302-908416156-2002
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (2002)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying UID (501)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: Found record for "admin"
[1223 08:10:42] 0xa0144720 (debug) PortMapper: user record has no SID, generating from UID (501)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: GenerateSIDFromRID: rid (2002) sid(S-1-5-21-0987654321-0987654321-0987654321-2002)
[1223 08:10:42] 0xa0144720 (debug) PortMapper: SID S-1-5-21-2163564381-2853518302-908416156-2002 maps to GUID 09B880D7-1253-48CA-B604-7D741A83DAD3
[1223 08:10:42] 0xb0595000 NOTICE PortMapper: Setting permissions on trash directory: /Volumes/XSAN/.Trashes
[1223 08:11:54] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-916150099-3086506465-3046403826-1001
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (1001)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying GID (0)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Found record for "wheel"
[1223 08:11:54] 0xa0144720 (debug) PortMapper: SID S-1-5-21-916150099-3086506465-3046403826-1001 maps to GUID ABCDEFAB-CDEF-ABCD-EFAB-CDEF00000000
[1223 08:11:54] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-3153091171-2383245309-20323066-2002
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (2002)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying UID (501)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Found record for "admin"
[1223 08:11:54] 0xa0144720 (debug) PortMapper: user record has no SID, generating from UID (501)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: GenerateSIDFromRID: rid (2002) sid(S-1-5-21-0987654321-0987654321-0987654321-2002)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: SID S-1-5-21-3153091171-2383245309-20323066-2002 maps to GUID 09B880D7-1253-48CA-B604-7D741A83DAD3
[1223 08:11:54] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-4026487120-2986823710-557323838-1001
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (1001)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying GID (0)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Found record for "wheel"
[1223 08:11:54] 0xa0144720 (debug) PortMapper: SID S-1-5-21-4026487120-2986823710-557323838-1001 maps to GUID ABCDEFAB-CDEF-ABCD-EFAB-CDEF00000000
[1223 08:11:54] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-4026487120-2986823710-557323838-2004
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (2004)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying UID (502)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Lookup by UID failed, generating fake GUID for UID 502
[1223 08:11:54] 0xa0144720 (debug) PortMapper: SID S-1-5-21-4026487120-2986823710-557323838-2004 maps to GUID FFFFEEEE-DDDD-CCCC-BBBB-AAAA000001F6
[1223 08:11:54] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-3153091171-2383245309-20323066-1001
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (1001)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying GID (0)
[1223 08:11:54] 0xa0144720 (debug) PortMapper: Found record for "wheel"
[1223 08:11:54] 0xa0144720 (debug) PortMapper: SID S-1-5-21-3153091171-2383245309-20323066-1001 maps to GUID ABCDEFAB-CDEF-ABCD-EFAB-CDEF00000000
[1223 08:12:36] 0xb038d000 INFO Disk rescan delay completed
[1223 08:12:36] 0xb038d000 INFO Disk rescan found 6 disks
[1223 08:13:08] 0xa0144720 INFO PortMapper: Added mapping from id 192.168.1.103 to addr 10.1.1.103
[1223 08:13:08] 0xa0144720 (debug) NSS: FSS mount list for client 10.1.1.103 (id 192.168.1.103) - empty
[1223 08:13:15] 0xa0144720 (debug) NSS: FSS mount list for client 10.1.1.103 (id 192.168.1.103) - XSAN
[1223 08:40:30] 0xb038d000 INFO Starting Disk rescan
[1223 08:40:30] 0xb038d000 INFO Disk rescan delay completed
[1223 08:40:30] 0xb038d000 INFO Disk rescan found 6 disks
[1223 09:10:31] 0xb038d000 INFO Starting Disk rescan
[1223 09:10:31] 0xb038d000 INFO Disk rescan delay completed
[1223 09:10:31] 0xb038d000 INFO Disk rescan found 6 disks
[1223 09:40:32] 0xb038d000 INFO Starting Disk rescan
[1223 09:40:32] 0xb038d000 INFO Disk rescan delay completed
[1223 09:40:32] 0xb038d000 INFO Disk rescan found 6 disks
[1223 09:57:05] 0xa0144720 INFO PortMapper: Added mapping from id 192.168.1.104 to addr 10.1.1.104
[1223 09:57:05] 0xa0144720 (debug) NSS: FSS mount list for client 10.1.1.104 (id 192.168.1.104) - empty
[1223 09:57:12] 0xa0144720 (debug) NSS: FSS mount list for client 10.1.1.104 (id 192.168.1.104) - XSAN
[1223 10:01:16] 0xa0144720 INFO PortMapper: Added mapping from id 192.168.1.102 to addr 10.1.1.102
[1223 10:01:16] 0xa0144720 (debug) NSS: FSS mount list for client 10.1.1.102 (id 192.168.1.102) - empty
[1223 10:01:23] 0xa0144720 (debug) NSS: FSS mount list for client 10.1.1.102 (id 192.168.1.102) - XSAN
[1223 10:10:33] 0xb038d000 INFO Starting Disk rescan
[1223 10:10:33] 0xb038d000 INFO Disk rescan delay completed
[1223 10:10:34] 0xb038d000 INFO Disk rescan found 6 disks
[1223 10:12:46] 0xa0144720 INFO PortMapper: Added mapping from id 192.168.1.101 to addr 10.1.1.101
[1223 10:12:46] 0xa0144720 (debug) NSS: FSS mount list for client 10.1.1.101 (id 192.168.1.101) - empty
[1223 10:12:52] 0xa0144720 (debug) NSS: FSS mount list for client 10.1.1.101 (id 192.168.1.101) - XSAN
[1223 10:27:57] 0xa0144720 INFO PortMapper: Deleting stale mapping for id 192.168.1.102
[1223 10:28:34] 0xa0144720 INFO PortMapper: Added mapping from id 192.168.1.102 to addr 10.1.1.102
[1223 10:28:34] 0xa0144720 (debug) NSS: FSS mount list for client 10.1.1.102 (id 192.168.1.102) - empty
[1223 10:28:40] 0xa0144720 (debug) NSS: FSS mount list for client 10.1.1.102 (id 192.168.1.102) - XSAN
[1223 10:40:34] 0xb038d000 INFO Starting Disk rescan
[1223 10:40:34] 0xb038d000 INFO Disk rescan delay completed
[1223 10:40:34] 0xb038d000 INFO Disk rescan found 6 disks
[1223 11:05:25] 0xa0144720 (debug) PortMapper: SID2GUID request for S-1-5-21-987654321-987654321-987654321-2002
[1223 11:05:25] 0xa0144720 (debug) PortMapper: Lookup by SID failed, trying RID (2002)
[1223 11:05:25] 0xa0144720 (debug) PortMapper: Lookup by RID failed, trying UID (501)
[1223 11:05:25] 0xa0144720 (debug) PortMapper: Found record for "admin"
[1223 11:05:25] 0xa0144720 (debug) PortMapper: user record has no SID, generating from UID (501)
[1223 11:05:25] 0xa0144720 (debug) PortMapper: GenerateSIDFromRID: rid (2002) sid(S-1-5-21-0987654321-0987654321-0987654321-2002)
[1223 11:05:25] 0xa0144720 (debug) PortMapper: SID S-1-5-21-987654321-987654321-987654321-2002 maps to GUID 09B880D7-1253-48CA-B604-7D741A83DAD3
[1223 11:10:35] 0xb038d000 INFO Starting Disk rescan
[1223 11:10:35] 0xb038d000 INFO Disk rescan delay completed
[1223 11:10:35] 0xb038d000 INFO Disk rescan found 6 disks

csanchez's picture

What log message led you to believe there is a metadata LUN issue? You should definitely take care of that first.

This looks odd:

Dec 23 11:06:28 cpod /usr/sbin/serialnumberd[108]: _MulticastMessage(): sendto failed, errno = 65 (No route to host)

Does /var/log/serialnumberd.log show any "Could be a SPAM attack" messages? This old thread has some info about that problem which affected 10.5.8 and older systems. Upgrading fixes that problem. BTW, have you noticed that Mavericks is free? :)