Q: XSAN cannot add backup controller and client
Hi,
The XSAN's primary controller was accidentally restarted by our client without the backup controller which resulted in the SAN to be useless. When I tried to uninstall and reinstall the XSAN filesystem to the main, everything went well. But by the time I add my two servers (one backup server, one file server). The XSAN wouldn't want to accept it. One error says that the backup controller cannot mount the Xsan volume while the other server is saying fsmpm not running and its not visible in XSAN admin.
here are sample logs from the setup:
BDC controller fsmpm log:
[0506 15:48:47] 0xb0513000 NOTICE NSS: Cannot acquire port for 10.0.0.101
[0506 15:48:56] 0xb0513000 NOTICE NSS: Cannot acquire port for 10.0.0.101
[0506 15:49:02] 0xa01fd720 (debug) Name Server 10.0.0.101 heartbeat absent for 30.0 seconds.
[0506 15:49:16] 0xb0513000 NOTICE NSS: Cannot acquire port for 10.0.0.101
[0506 15:49:25] 0xb0513000 NOTICE NSS: Cannot acquire port for 10.0.0.101
[0506 15:49:32] 0xa01fd720 (debug) Name Server 10.0.0.101 heartbeat absent for 30.5
BDC controller system log:
May 6 16:01:49 hct-bdc com.apple.launchd[1] (org.openldap.slapd[727]): Exited with exit code: 1
May 6 16:01:49 hct-bdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 16:01:59 hct-bdc com.apple.launchd[1] (org.openldap.slapd[728]): Exited with exit code: 1
May 6 16:01:59 hct-bdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 16:02:02 hct-bdc fsmpm[352]: NSS: Cannot acquire port for 10.0.0.101
May 6 16:02:09 hct-bdc com.apple.launchd[1] (org.openldap.slapd[729]): Exited with exit code: 1
May 6 16:02:09 hct-bdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 16:02:18 hct-bdc fsmpm[352]: NSS: Cannot acquire port for 10.0.0.101
May 6 16:02:19 hct-bdc com.apple.launchd[1] (org.openldap.slapd[730]): Exited with exit code: 1
May 6 16:02:19 hct-bdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 16:02:29 hct-bdc com.apple.launchd[1] (org.openldap.slapd[731]): Exited with exit code: 1
May 6 16:02:29 hct-bdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 16:02:30 hct-bdc servermgrd[616]: xsan: [616/103B80] ERROR: getfsm_processstats(XSAN): Unable to find pid of fsm
May 6 16:02:32 hct-bdc fsmpm[352]: NSS: Cannot acquire port for 10.0.0.101
MDC controller system log:
[0506 15:55:20] 0xa08fd720 (debug) find_fsm: start
[0506 15:55:28] 0xb0699000 NOTICE NSS: Cannot acquire port for 10.0.0.102
[0506 15:55:35] 0xa08fd720 (debug) Name Server 10.0.0.102 heartbeat absent for 30.1 seconds.
[0506 15:55:38] 0xa08fd720 (debug) PORTMAPINQUIRY_NAV2
[0506 15:55:38] 0xa08fd720 (debug) find_fsm: start
[0506 15:55:39] 0xa08fd720 (debug) PORTMAPINQUIRY_NAV2
[0506 15:55:39] 0xa08fd720 (debug) find_fsm: start
[0506 15:55:39] 0xa08fd720 (debug) PORTMAPINQUIRY_NAV2
[0506 15:55:39] 0xa08fd720 (debug) find_fsm: start
[0506 15:55:50] 0xb0699000 NOTICE NSS: Cannot acquire port for 10.0.0.102
[0506 15:55:59] 0xb0699000 NOTICE NSS: Cannot acquire port for 10.0.0.102
[0506 15:56:05] 0xa08fd720 (debug) Name Server 10.0.0.102 heartbeat absent for 30.5 seconds.
MDC controller system log:
May 6 15:58:51 hct-mdc fsmpm[1107]: NSS: Cannot acquire port for 10.0.0.102
May 6 15:58:51 hct-mdc com.apple.launchd[1] (org.openldap.slapd[3293]): Exited with exit code: 1
May 6 15:58:51 hct-mdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 15:58:51 hct-mdc kernel[0]: Limiting icmp ping response from 446 to 250 packets per second
May 6 15:58:52 hct-mdc kernel[0]: Limiting icmp ping response from 347 to 250 packets per second
May 6 15:58:54 hct-mdc kernel[0]: Limiting icmp ping response from 446 to 250 packets per second
May 6 15:59:00: --- last message repeated 1 time ---
May 6 15:59:00 hct-mdc fsmpm[1107]: NSS: Cannot acquire port for 10.0.0.102
May 6 15:59:01 hct-mdc com.apple.launchd[1] (org.openldap.slapd[3294]): Exited with exit code: 1
May 6 15:59:01 hct-mdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 15:59:11 hct-mdc com.apple.launchd[1] (org.openldap.slapd[3296]): Exited with exit code: 1
May 6 15:59:11 hct-mdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 15:59:16 hct-mdc fsmpm[1107]: NSS: Cannot acquire port for 10.0.0.102
May 6 15:59:21 hct-mdc com.apple.launchd[1] (org.openldap.slapd[3298]): Exited with exit code: 1
May 6 15:59:21 hct-mdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 15:59:25 hct-mdc fsmpm[1107]: NSS: Cannot acquire port for 10.0.0.102
MDC Xsan Volume log:
[0506 16:05:20.893449] 0xb08a1000 (Debug) FSM wait SUMMARY revokes/0 avg/0 min/0 max/0.
[0506 16:05:20.893453] 0xb08a1000 (Debug) FSM threads SUMMARY max busy hi-prio/6 lo-prio/1.
[0506 16:05:20.893456] 0xb08a1000 (Debug) FSM threads SUMMARY max busy dmig/0 events/0.
[0506 16:05:20.893460] 0xb08a1000 (Debug) FSM msg queue SUMMARY hi-prio now/0 min/0 max/4.
[0506 16:05:20.893463] 0xb08a1000 (Debug) FSM msg queue SUMMARY lo-prio now/0 min/0 max/1.
[0506 16:05:20.893467] 0xb08a1000 (Debug) FSM msg queue SUMMARY dmig now/0 min/0 max/0.
[0506 16:05:20.893471] 0xb08a1000 (Debug) FSM msg queue SUMMARY events now/0 min/0 max/0.
[0506 16:05:20.893475] 0xb08a1000 (Debug) FSM cache SUMMARY inode lookups/30066 misses/3651 hits/87.86%.
[0506 16:05:20.893479] 0xb08a1000 (Debug) FSM cache SUMMARY free incore inodes now/8192 min/8130 max/8192.
[0506 16:05:20.893483] 0xb08a1000 (Debug) FSM cache SUMMARY buffer lookups/48293 misses/308 hits/99.36%.
[0506 16:05:20.893487] 0xb08a1000 (Debug) FSM cache SUMMARY free buffers now/2048 min/1 max/2048.
[0506 16:05:20.893490] 0xb08a1000 (Debug) FSM cache SUMMARY attrs now/3629 min/0 max/3629.
[0506 16:05:20.893494] 0xb08a1000 (Debug) FSM extent SUMMARY extent lookups/7393 misses/89 hits/98.80%.
[0506 16:05:20.893499] 0xb08a1000 (Debug) FSM extent SUMMARY hint tries/0 misses/0 hits/0.00%.
[0506 16:05:20.893505] 0xb08a1000 (Debug) VOP SUMMARY Mkdir cnt/1 avg/10053 min/10053 max/10053.
[0506 16:05:20.893510] 0xb08a1000 (Debug) VOP SUMMARY Setattr cnt/3650 avg/414 min/17 max/332124.
[0506 16:05:20.893515] 0xb08a1000 (Debug) VOP SUMMARY Remove cnt/2 avg/901 min/652 max/1151.
[0506 16:05:20.893520] 0xb08a1000 (Debug) VOP SUMMARY Open cnt/3590 avg/31 min/16 max/185.
[0506 16:05:20.893524] 0xb08a1000 (Debug) VOP SUMMARY Close cnt/3581 avg/30 min/13 max/609.
[0506 16:05:20.893529] 0xb08a1000 (Debug) VOP SUMMARY PunchHoleApi cnt/29 avg/459 min/65 max/1431.
[0506 16:05:20.893534] 0xb08a1000 (Debug) VOP SUMMARY GetNTSecurity cnt/1 avg/6090 min/6090 max/6090.
[0506 16:05:20.893539] 0xb08a1000 (Debug) VOP SUMMARY Flush2pc cnt/32 avg/24 min/15 max/49.
[0506 16:05:20.893543] 0xb08a1000 (Debug) VOP SUMMARY Getquota cnt/1 avg/84 min/84 max/84.
[0506 16:05:20.893548] 0xb08a1000 (Debug) VOP SUMMARY CreateV3 cnt/2 avg/643 min/169 max/1118.
[0506 16:05:20.893553] 0xb08a1000 (Debug) VOP SUMMARY VopGetattrV4 cnt/1934 avg/237 min/19 max/330006.
[0506 16:05:20.893558] 0xb08a1000 (Debug) VOP SUMMARY VopLookupV4 cnt/5836 avg/213 min/16 max/329707.
[0506 16:05:20.893563] 0xb08a1000 (Debug) VOP SUMMARY VopCapNegotiate cnt/2 avg/22 min/15 max/30.
[0506 16:05:20.893567] 0xb08a1000 (Debug) VOP SUMMARY VopReaddir2 cnt/8 avg/1813 min/30 max/14223.
[0506 16:05:20.893586] 0xb08a1000 (Debug) VOP SUMMARY VopClientId cnt/2 avg/19 min/16 max/22.
[0506 16:05:20.893591] 0xb08a1000 (Debug) VOP SUMMARY GetResyncAttr cnt/9 avg/439 min/37 max/3113.
[0506 16:05:20.893596] 0xb08a1000 (Debug) VOP SUMMARY GetLinkInfo cnt/1937 avg/28 min/14 max/116.
[0506 16:05:20.893602] 0xb08a1000 (Debug) TKN SUMMARY TokenRequestV2 cnt/4 avg/43 min/30 max/48.
[0506 16:05:20.893607] 0xb08a1000 (Debug) TKN SUMMARY TokenRequestV3 cnt/1075 avg/27 min/13 max/669.
[0506 16:05:20.893612] 0xb08a1000 (Debug) TKN SUMMARY TokenChangeV4 cnt/3686 avg/182 min/2 max/295792.
[0506 16:05:20.893617] 0xb08a1000 (Debug) TKN SUMMARY TokenReqAlloc cnt/75 avg/1431 min/36 max/18054.
[0506 16:05:20.893627] 0xb08a1000 (Debug) BRL SUMMARY SetLock cnt/8252 avg/24 min/9 max/170.
[0506 16:05:20.893631] 0xb08a1000 (Debug) BRL SUMMARY ClearLock cnt/11719 avg/24 min/8 max/143.
[0506 16:05:20.893636] 0xb08a1000 (Debug) BRL SUMMARY ClearAll cnt/10 avg/39 min/25 max/50.
[0506 16:05:20.893641] 0xb08a1000 (Debug) BRL SUMMARY ReconDone cnt/2 avg/32 min/26 max/39.
[0506 16:05:20.893645] 0xb08a1000 (Debug) BRL SUMMARY RestoreLock cnt/1 avg/45 min/45 max/45.
[0506 16:05:20.893653] 0xb08a1000 (Debug) SG SUMMARY MetadataAndJournal space total/931.31 GB free/931.17 GB (99.98%)
[0506 16:05:20.893667] 0xb08a1000 (Debug) SG SUMMARY MetadataAndJournal space minfree/931.17 GB (99.98%) maxfree/931.17 GB (99.98%)
[0506 16:05:20.893672] 0xb08a1000 (Debug) SG SUMMARY MetadataAndJournal alloc extent cnt/0 avgsize/0.00 B.
[0506 16:05:20.893676] 0xb08a1000 (Debug) SG SUMMARY 2 btree free space fragments 2 splay tree fragments
[0506 16:05:20.893681] 0xb08a1000 (Debug) SG SUMMARY Video space total/9.09 TB free/9.08 TB (99.81%)
[0506 16:05:20.893687] 0xb08a1000 (Debug) SG SUMMARY Video space minfree/9.08 TB (99.81%) maxfree/9.08 TB (99.81%)
[0506 16:05:20.893692] 0xb08a1000 (Debug) SG SUMMARY Video alloc extent cnt/71 avgsize/111.55 KB.
[0506 16:05:20.893695] 0xb08a1000 (Debug) SG SUMMARY 8 btree free space fragments 12 splay tree fragments
[0506 16:05:20.893701] 0xb08a1000 (Debug) PIO HiPriWr SUMMARY MD cnt/1584 maxq/0.
[0506 16:05:20.893705] 0xb08a1000 (Debug) PIO HiPriWr SUMMARY MD avg/1676 min/368 max/338234.
[0506 16:05:20.893710] 0xb08a1000 (Debug) PIO HiPriWr SUMMARY MD sysavg/1675 sysmin/367 sysmax/338232.
[0506 16:05:20.893715] 0xb08a1000 (Debug) PIO HiPriWr SUMMARY MD avglen/1786 minlen/512 maxlen/32768.
[0506 16:05:20.893719] 0xb08a1000 (Debug) PIO Read SUMMARY MD cnt/3834 maxq/3.
[0506 16:05:20.893724] 0xb08a1000 (Debug) PIO Read SUMMARY MD avg/982 min/150 max/320037.
[0506 16:05:20.893728] 0xb08a1000 (Debug) PIO Read SUMMARY MD sysavg/526 sysmin/133 sysmax/25964.
[0506 16:05:20.893733] 0xb08a1000 (Debug) PIO Read SUMMARY MD avglen/30992 minlen/512 maxlen/4194304.
[0506 16:05:20.893737] 0xb08a1000 (Debug) PIO Write SUMMARY MD cnt/5392 maxq/2.
[0506 16:05:20.893741] 0xb08a1000 (Debug) PIO Write SUMMARY MD avg/1175 min/374 max/340425.
[0506 16:05:20.893746] 0xb08a1000 (Debug) PIO Write SUMMARY MD sysavg/1092 sysmin/357 sysmax/340403.
[0506 16:05:20.893750] 0xb08a1000 (Debug) PIO Write SUMMARY MD avglen/6257 minlen/512 maxlen/16384.
[0506 16:05:20.893755] 0xb08a1000 (Debug) Cache SUMMARY [10.0.0.101] attrs now/3629 min/1 max/3629.
[0506 16:05:20.893761] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Mkdir cnt/1 avg/10053 min/10053 max/10053.
[0506 16:05:20.893766] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Setattr cnt/3641 avg/415 min/17 max/332124.
[0506 16:05:20.893770] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Remove cnt/2 avg/901 min/652 max/1151.
[0506 16:05:20.893775] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Open cnt/3581 avg/31 min/16 max/163.
[0506 16:05:20.893780] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Close cnt/3573 avg/30 min/13 max/609.
[0506 16:05:20.893785] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] PunchHoleApi cnt/29 avg/459 min/65 max/1431.
[0506 16:05:20.893789] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] GetNTSecurity cnt/1 avg/6090 min/6090 max/6090.
[0506 16:05:20.893794] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Getquota cnt/1 avg/84 min/84 max/84.
[0506 16:05:20.893805] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] CreateV3 cnt/2 avg/643 min/169 max/1118.
[0506 16:05:20.893810] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] VopGetattrV4 cnt/1934 avg/237 min/19 max/330006.
[0506 16:05:20.893818] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] VopLookupV4 cnt/5836 avg/213 min/16 max/329707.
[0506 16:05:20.893823] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] VopCapNegotiate cnt/1 avg/15 min/15 max/15.
[0506 16:05:20.893827] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] VopReaddir2 cnt/8 avg/1813 min/30 max/14223.
[0506 16:05:20.893832] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] VopClientId cnt/1 avg/22 min/22 max/22.
[0506 16:05:20.893836] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] GetLinkInfo cnt/1937 avg/28 min/14 max/116.
[0506 16:05:20.893844] 0xb08a1000 (Debug) TKN SUMMARY [10.0.0.101] TokenRequestV2 cnt/2 avg/47 min/47 max/48.
[0506 16:05:20.893849] 0xb08a1000 (Debug) TKN SUMMARY [10.0.0.101] TokenRequestV3 cnt/1075 avg/27 min/13 max/669.
[0506 16:05:20.893854] 0xb08a1000 (Debug) TKN SUMMARY [10.0.0.101] TokenChangeV4 cnt/3684 avg/181 min/2 max/295792.
[0506 16:05:20.893858] 0xb08a1000 (Debug) TKN SUMMARY [10.0.0.101] TokenReqAlloc cnt/69 avg/1233 min/555 max/3960.
[0506 16:05:20.893872] 0xb08a1000 (Debug) BRL SUMMARY [10.0.0.101] SetLock cnt/8252 avg/24 min/9 max/170.
[0506 16:05:20.893877] 0xb08a1000 (Debug) BRL SUMMARY [10.0.0.101] ClearLock cnt/11719 avg/24 min/8 max/143.
[0506 16:05:20.893881] 0xb08a1000 (Debug) BRL SUMMARY [10.0.0.101] ReconDone cnt/1 avg/39 min/39 max/39.
[0506 16:05:38.875742] 0xa08fd720 (Debug) Node [122] [10.0.0.101:60531] connected.
[0506 16:05:38.875966] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60530.
[0506 16:05:38] 0xb9037000 (Info) Node [122] [10.0.0.101:60531] Administrator Logout.
[0506 16:05:38.933577] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60540.
[0506 16:05:38.933942] 0xa08fd720 (Debug) Node [123] [10.0.0.101:60541] connected.
[0506 16:05:38] 0xb9037000 (Info) Node [123] [10.0.0.101:60541] Administrator Logout.
[0506 16:05:38.984952] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60546.
[0506 16:05:38.985222] 0xa08fd720 (Debug) Node [124] [10.0.0.101:60547] connected.
[0506 16:05:39] 0xb9037000 (Info) Node [124] [10.0.0.101:60547] Administrator Logout.
[0506 16:06:20.107886] 0xa08fd720 (Debug) Node [125] [10.0.0.101:60629] connected.
[0506 16:06:20.108165] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60628.
[0506 16:06:20] 0xb9037000 (Info) Node [125] [10.0.0.101:60629] Administrator Logout.
[0506 16:06:38.861259] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60683.
[0506 16:06:38.861518] 0xa08fd720 (Debug) Node [126] [10.0.0.101:60684] connected.
[0506 16:06:38] 0xb9037000 (Info) Node [126] [10.0.0.101:60684] Administrator Logout.
[0506 16:06:38.924421] 0xa08fd720 (Debug) Node [127] [10.0.0.101:60695] connected.
[0506 16:06:38.924620] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60694.
[0506 16:06:38] 0xb9037000 (Info) Node [127] [10.0.0.101:60695] Administrator Logout.
As I said, with the other server (File Server), its saying fsmpm not running and its not visible in computers option in XSAN admin.
Please help me with the solution as I am really clueless of what's happening
The XSAN's primary controller was accidentally restarted by our client without the backup controller which resulted in the SAN to be useless. When I tried to uninstall and reinstall the XSAN filesystem to the main, everything went well. But by the time I add my two servers (one backup server, one file server). The XSAN wouldn't want to accept it. One error says that the backup controller cannot mount the Xsan volume while the other server is saying fsmpm not running and its not visible in XSAN admin.
here are sample logs from the setup:
BDC controller fsmpm log:
[0506 15:48:47] 0xb0513000 NOTICE NSS: Cannot acquire port for 10.0.0.101
[0506 15:48:56] 0xb0513000 NOTICE NSS: Cannot acquire port for 10.0.0.101
[0506 15:49:02] 0xa01fd720 (debug) Name Server 10.0.0.101 heartbeat absent for 30.0 seconds.
[0506 15:49:16] 0xb0513000 NOTICE NSS: Cannot acquire port for 10.0.0.101
[0506 15:49:25] 0xb0513000 NOTICE NSS: Cannot acquire port for 10.0.0.101
[0506 15:49:32] 0xa01fd720 (debug) Name Server 10.0.0.101 heartbeat absent for 30.5
BDC controller system log:
May 6 16:01:49 hct-bdc com.apple.launchd[1] (org.openldap.slapd[727]): Exited with exit code: 1
May 6 16:01:49 hct-bdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 16:01:59 hct-bdc com.apple.launchd[1] (org.openldap.slapd[728]): Exited with exit code: 1
May 6 16:01:59 hct-bdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 16:02:02 hct-bdc fsmpm[352]: NSS: Cannot acquire port for 10.0.0.101
May 6 16:02:09 hct-bdc com.apple.launchd[1] (org.openldap.slapd[729]): Exited with exit code: 1
May 6 16:02:09 hct-bdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 16:02:18 hct-bdc fsmpm[352]: NSS: Cannot acquire port for 10.0.0.101
May 6 16:02:19 hct-bdc com.apple.launchd[1] (org.openldap.slapd[730]): Exited with exit code: 1
May 6 16:02:19 hct-bdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 16:02:29 hct-bdc com.apple.launchd[1] (org.openldap.slapd[731]): Exited with exit code: 1
May 6 16:02:29 hct-bdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 16:02:30 hct-bdc servermgrd[616]: xsan: [616/103B80] ERROR: getfsm_processstats(XSAN): Unable to find pid of fsm
May 6 16:02:32 hct-bdc fsmpm[352]: NSS: Cannot acquire port for 10.0.0.101
MDC controller system log:
[0506 15:55:20] 0xa08fd720 (debug) find_fsm: start
[0506 15:55:28] 0xb0699000 NOTICE NSS: Cannot acquire port for 10.0.0.102
[0506 15:55:35] 0xa08fd720 (debug) Name Server 10.0.0.102 heartbeat absent for 30.1 seconds.
[0506 15:55:38] 0xa08fd720 (debug) PORTMAPINQUIRY_NAV2
[0506 15:55:38] 0xa08fd720 (debug) find_fsm: start
[0506 15:55:39] 0xa08fd720 (debug) PORTMAPINQUIRY_NAV2
[0506 15:55:39] 0xa08fd720 (debug) find_fsm: start
[0506 15:55:39] 0xa08fd720 (debug) PORTMAPINQUIRY_NAV2
[0506 15:55:39] 0xa08fd720 (debug) find_fsm: start
[0506 15:55:50] 0xb0699000 NOTICE NSS: Cannot acquire port for 10.0.0.102
[0506 15:55:59] 0xb0699000 NOTICE NSS: Cannot acquire port for 10.0.0.102
[0506 15:56:05] 0xa08fd720 (debug) Name Server 10.0.0.102 heartbeat absent for 30.5 seconds.
MDC controller system log:
May 6 15:58:51 hct-mdc fsmpm[1107]: NSS: Cannot acquire port for 10.0.0.102
May 6 15:58:51 hct-mdc com.apple.launchd[1] (org.openldap.slapd[3293]): Exited with exit code: 1
May 6 15:58:51 hct-mdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 15:58:51 hct-mdc kernel[0]: Limiting icmp ping response from 446 to 250 packets per second
May 6 15:58:52 hct-mdc kernel[0]: Limiting icmp ping response from 347 to 250 packets per second
May 6 15:58:54 hct-mdc kernel[0]: Limiting icmp ping response from 446 to 250 packets per second
May 6 15:59:00: --- last message repeated 1 time ---
May 6 15:59:00 hct-mdc fsmpm[1107]: NSS: Cannot acquire port for 10.0.0.102
May 6 15:59:01 hct-mdc com.apple.launchd[1] (org.openldap.slapd[3294]): Exited with exit code: 1
May 6 15:59:01 hct-mdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 15:59:11 hct-mdc com.apple.launchd[1] (org.openldap.slapd[3296]): Exited with exit code: 1
May 6 15:59:11 hct-mdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 15:59:16 hct-mdc fsmpm[1107]: NSS: Cannot acquire port for 10.0.0.102
May 6 15:59:21 hct-mdc com.apple.launchd[1] (org.openldap.slapd[3298]): Exited with exit code: 1
May 6 15:59:21 hct-mdc com.apple.launchd[1] (org.openldap.slapd): Throttling respawn: Will start in 10 seconds
May 6 15:59:25 hct-mdc fsmpm[1107]: NSS: Cannot acquire port for 10.0.0.102
MDC Xsan Volume log:
[0506 16:05:20.893449] 0xb08a1000 (Debug) FSM wait SUMMARY revokes/0 avg/0 min/0 max/0.
[0506 16:05:20.893453] 0xb08a1000 (Debug) FSM threads SUMMARY max busy hi-prio/6 lo-prio/1.
[0506 16:05:20.893456] 0xb08a1000 (Debug) FSM threads SUMMARY max busy dmig/0 events/0.
[0506 16:05:20.893460] 0xb08a1000 (Debug) FSM msg queue SUMMARY hi-prio now/0 min/0 max/4.
[0506 16:05:20.893463] 0xb08a1000 (Debug) FSM msg queue SUMMARY lo-prio now/0 min/0 max/1.
[0506 16:05:20.893467] 0xb08a1000 (Debug) FSM msg queue SUMMARY dmig now/0 min/0 max/0.
[0506 16:05:20.893471] 0xb08a1000 (Debug) FSM msg queue SUMMARY events now/0 min/0 max/0.
[0506 16:05:20.893475] 0xb08a1000 (Debug) FSM cache SUMMARY inode lookups/30066 misses/3651 hits/87.86%.
[0506 16:05:20.893479] 0xb08a1000 (Debug) FSM cache SUMMARY free incore inodes now/8192 min/8130 max/8192.
[0506 16:05:20.893483] 0xb08a1000 (Debug) FSM cache SUMMARY buffer lookups/48293 misses/308 hits/99.36%.
[0506 16:05:20.893487] 0xb08a1000 (Debug) FSM cache SUMMARY free buffers now/2048 min/1 max/2048.
[0506 16:05:20.893490] 0xb08a1000 (Debug) FSM cache SUMMARY attrs now/3629 min/0 max/3629.
[0506 16:05:20.893494] 0xb08a1000 (Debug) FSM extent SUMMARY extent lookups/7393 misses/89 hits/98.80%.
[0506 16:05:20.893499] 0xb08a1000 (Debug) FSM extent SUMMARY hint tries/0 misses/0 hits/0.00%.
[0506 16:05:20.893505] 0xb08a1000 (Debug) VOP SUMMARY Mkdir cnt/1 avg/10053 min/10053 max/10053.
[0506 16:05:20.893510] 0xb08a1000 (Debug) VOP SUMMARY Setattr cnt/3650 avg/414 min/17 max/332124.
[0506 16:05:20.893515] 0xb08a1000 (Debug) VOP SUMMARY Remove cnt/2 avg/901 min/652 max/1151.
[0506 16:05:20.893520] 0xb08a1000 (Debug) VOP SUMMARY Open cnt/3590 avg/31 min/16 max/185.
[0506 16:05:20.893524] 0xb08a1000 (Debug) VOP SUMMARY Close cnt/3581 avg/30 min/13 max/609.
[0506 16:05:20.893529] 0xb08a1000 (Debug) VOP SUMMARY PunchHoleApi cnt/29 avg/459 min/65 max/1431.
[0506 16:05:20.893534] 0xb08a1000 (Debug) VOP SUMMARY GetNTSecurity cnt/1 avg/6090 min/6090 max/6090.
[0506 16:05:20.893539] 0xb08a1000 (Debug) VOP SUMMARY Flush2pc cnt/32 avg/24 min/15 max/49.
[0506 16:05:20.893543] 0xb08a1000 (Debug) VOP SUMMARY Getquota cnt/1 avg/84 min/84 max/84.
[0506 16:05:20.893548] 0xb08a1000 (Debug) VOP SUMMARY CreateV3 cnt/2 avg/643 min/169 max/1118.
[0506 16:05:20.893553] 0xb08a1000 (Debug) VOP SUMMARY VopGetattrV4 cnt/1934 avg/237 min/19 max/330006.
[0506 16:05:20.893558] 0xb08a1000 (Debug) VOP SUMMARY VopLookupV4 cnt/5836 avg/213 min/16 max/329707.
[0506 16:05:20.893563] 0xb08a1000 (Debug) VOP SUMMARY VopCapNegotiate cnt/2 avg/22 min/15 max/30.
[0506 16:05:20.893567] 0xb08a1000 (Debug) VOP SUMMARY VopReaddir2 cnt/8 avg/1813 min/30 max/14223.
[0506 16:05:20.893586] 0xb08a1000 (Debug) VOP SUMMARY VopClientId cnt/2 avg/19 min/16 max/22.
[0506 16:05:20.893591] 0xb08a1000 (Debug) VOP SUMMARY GetResyncAttr cnt/9 avg/439 min/37 max/3113.
[0506 16:05:20.893596] 0xb08a1000 (Debug) VOP SUMMARY GetLinkInfo cnt/1937 avg/28 min/14 max/116.
[0506 16:05:20.893602] 0xb08a1000 (Debug) TKN SUMMARY TokenRequestV2 cnt/4 avg/43 min/30 max/48.
[0506 16:05:20.893607] 0xb08a1000 (Debug) TKN SUMMARY TokenRequestV3 cnt/1075 avg/27 min/13 max/669.
[0506 16:05:20.893612] 0xb08a1000 (Debug) TKN SUMMARY TokenChangeV4 cnt/3686 avg/182 min/2 max/295792.
[0506 16:05:20.893617] 0xb08a1000 (Debug) TKN SUMMARY TokenReqAlloc cnt/75 avg/1431 min/36 max/18054.
[0506 16:05:20.893627] 0xb08a1000 (Debug) BRL SUMMARY SetLock cnt/8252 avg/24 min/9 max/170.
[0506 16:05:20.893631] 0xb08a1000 (Debug) BRL SUMMARY ClearLock cnt/11719 avg/24 min/8 max/143.
[0506 16:05:20.893636] 0xb08a1000 (Debug) BRL SUMMARY ClearAll cnt/10 avg/39 min/25 max/50.
[0506 16:05:20.893641] 0xb08a1000 (Debug) BRL SUMMARY ReconDone cnt/2 avg/32 min/26 max/39.
[0506 16:05:20.893645] 0xb08a1000 (Debug) BRL SUMMARY RestoreLock cnt/1 avg/45 min/45 max/45.
[0506 16:05:20.893653] 0xb08a1000 (Debug) SG SUMMARY MetadataAndJournal space total/931.31 GB free/931.17 GB (99.98%)
[0506 16:05:20.893667] 0xb08a1000 (Debug) SG SUMMARY MetadataAndJournal space minfree/931.17 GB (99.98%) maxfree/931.17 GB (99.98%)
[0506 16:05:20.893672] 0xb08a1000 (Debug) SG SUMMARY MetadataAndJournal alloc extent cnt/0 avgsize/0.00 B.
[0506 16:05:20.893676] 0xb08a1000 (Debug) SG SUMMARY 2 btree free space fragments 2 splay tree fragments
[0506 16:05:20.893681] 0xb08a1000 (Debug) SG SUMMARY Video space total/9.09 TB free/9.08 TB (99.81%)
[0506 16:05:20.893687] 0xb08a1000 (Debug) SG SUMMARY Video space minfree/9.08 TB (99.81%) maxfree/9.08 TB (99.81%)
[0506 16:05:20.893692] 0xb08a1000 (Debug) SG SUMMARY Video alloc extent cnt/71 avgsize/111.55 KB.
[0506 16:05:20.893695] 0xb08a1000 (Debug) SG SUMMARY 8 btree free space fragments 12 splay tree fragments
[0506 16:05:20.893701] 0xb08a1000 (Debug) PIO HiPriWr SUMMARY MD cnt/1584 maxq/0.
[0506 16:05:20.893705] 0xb08a1000 (Debug) PIO HiPriWr SUMMARY MD avg/1676 min/368 max/338234.
[0506 16:05:20.893710] 0xb08a1000 (Debug) PIO HiPriWr SUMMARY MD sysavg/1675 sysmin/367 sysmax/338232.
[0506 16:05:20.893715] 0xb08a1000 (Debug) PIO HiPriWr SUMMARY MD avglen/1786 minlen/512 maxlen/32768.
[0506 16:05:20.893719] 0xb08a1000 (Debug) PIO Read SUMMARY MD cnt/3834 maxq/3.
[0506 16:05:20.893724] 0xb08a1000 (Debug) PIO Read SUMMARY MD avg/982 min/150 max/320037.
[0506 16:05:20.893728] 0xb08a1000 (Debug) PIO Read SUMMARY MD sysavg/526 sysmin/133 sysmax/25964.
[0506 16:05:20.893733] 0xb08a1000 (Debug) PIO Read SUMMARY MD avglen/30992 minlen/512 maxlen/4194304.
[0506 16:05:20.893737] 0xb08a1000 (Debug) PIO Write SUMMARY MD cnt/5392 maxq/2.
[0506 16:05:20.893741] 0xb08a1000 (Debug) PIO Write SUMMARY MD avg/1175 min/374 max/340425.
[0506 16:05:20.893746] 0xb08a1000 (Debug) PIO Write SUMMARY MD sysavg/1092 sysmin/357 sysmax/340403.
[0506 16:05:20.893750] 0xb08a1000 (Debug) PIO Write SUMMARY MD avglen/6257 minlen/512 maxlen/16384.
[0506 16:05:20.893755] 0xb08a1000 (Debug) Cache SUMMARY [10.0.0.101] attrs now/3629 min/1 max/3629.
[0506 16:05:20.893761] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Mkdir cnt/1 avg/10053 min/10053 max/10053.
[0506 16:05:20.893766] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Setattr cnt/3641 avg/415 min/17 max/332124.
[0506 16:05:20.893770] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Remove cnt/2 avg/901 min/652 max/1151.
[0506 16:05:20.893775] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Open cnt/3581 avg/31 min/16 max/163.
[0506 16:05:20.893780] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Close cnt/3573 avg/30 min/13 max/609.
[0506 16:05:20.893785] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] PunchHoleApi cnt/29 avg/459 min/65 max/1431.
[0506 16:05:20.893789] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] GetNTSecurity cnt/1 avg/6090 min/6090 max/6090.
[0506 16:05:20.893794] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] Getquota cnt/1 avg/84 min/84 max/84.
[0506 16:05:20.893805] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] CreateV3 cnt/2 avg/643 min/169 max/1118.
[0506 16:05:20.893810] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] VopGetattrV4 cnt/1934 avg/237 min/19 max/330006.
[0506 16:05:20.893818] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] VopLookupV4 cnt/5836 avg/213 min/16 max/329707.
[0506 16:05:20.893823] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] VopCapNegotiate cnt/1 avg/15 min/15 max/15.
[0506 16:05:20.893827] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] VopReaddir2 cnt/8 avg/1813 min/30 max/14223.
[0506 16:05:20.893832] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] VopClientId cnt/1 avg/22 min/22 max/22.
[0506 16:05:20.893836] 0xb08a1000 (Debug) VOP SUMMARY [10.0.0.101] GetLinkInfo cnt/1937 avg/28 min/14 max/116.
[0506 16:05:20.893844] 0xb08a1000 (Debug) TKN SUMMARY [10.0.0.101] TokenRequestV2 cnt/2 avg/47 min/47 max/48.
[0506 16:05:20.893849] 0xb08a1000 (Debug) TKN SUMMARY [10.0.0.101] TokenRequestV3 cnt/1075 avg/27 min/13 max/669.
[0506 16:05:20.893854] 0xb08a1000 (Debug) TKN SUMMARY [10.0.0.101] TokenChangeV4 cnt/3684 avg/181 min/2 max/295792.
[0506 16:05:20.893858] 0xb08a1000 (Debug) TKN SUMMARY [10.0.0.101] TokenReqAlloc cnt/69 avg/1233 min/555 max/3960.
[0506 16:05:20.893872] 0xb08a1000 (Debug) BRL SUMMARY [10.0.0.101] SetLock cnt/8252 avg/24 min/9 max/170.
[0506 16:05:20.893877] 0xb08a1000 (Debug) BRL SUMMARY [10.0.0.101] ClearLock cnt/11719 avg/24 min/8 max/143.
[0506 16:05:20.893881] 0xb08a1000 (Debug) BRL SUMMARY [10.0.0.101] ReconDone cnt/1 avg/39 min/39 max/39.
[0506 16:05:38.875742] 0xa08fd720 (Debug) Node [122] [10.0.0.101:60531] connected.
[0506 16:05:38.875966] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60530.
[0506 16:05:38] 0xb9037000 (Info) Node [122] [10.0.0.101:60531] Administrator Logout.
[0506 16:05:38.933577] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60540.
[0506 16:05:38.933942] 0xa08fd720 (Debug) Node [123] [10.0.0.101:60541] connected.
[0506 16:05:38] 0xb9037000 (Info) Node [123] [10.0.0.101:60541] Administrator Logout.
[0506 16:05:38.984952] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60546.
[0506 16:05:38.985222] 0xa08fd720 (Debug) Node [124] [10.0.0.101:60547] connected.
[0506 16:05:39] 0xb9037000 (Info) Node [124] [10.0.0.101:60547] Administrator Logout.
[0506 16:06:20.107886] 0xa08fd720 (Debug) Node [125] [10.0.0.101:60629] connected.
[0506 16:06:20.108165] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60628.
[0506 16:06:20] 0xb9037000 (Info) Node [125] [10.0.0.101:60629] Administrator Logout.
[0506 16:06:38.861259] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60683.
[0506 16:06:38.861518] 0xa08fd720 (Debug) Node [126] [10.0.0.101:60684] connected.
[0506 16:06:38] 0xb9037000 (Info) Node [126] [10.0.0.101:60684] Administrator Logout.
[0506 16:06:38.924421] 0xa08fd720 (Debug) Node [127] [10.0.0.101:60695] connected.
[0506 16:06:38.924620] 0xa08fd720 (Debug) Active service - NSS ping from 10.0.0.101:60694.
[0506 16:06:38] 0xb9037000 (Info) Node [127] [10.0.0.101:60695] Administrator Logout.
As I said, with the other server (File Server), its saying fsmpm not running and its not visible in computers option in XSAN admin.
Please help me with the solution as I am really clueless of what's happening
Intel Xserve 2.26 Xeon, Mac OS X (10.5.6), 3GB ram each
Posted on May 6, 2010 2:19 PM