My first stab at using dtrace to figure something out.
First of all, the dstrace script file I created
-- start of umount2.d --
#!/usr/sbin/dtrace -s
syscall::umount2:entry
{
printf("time:%d\t", timestamp);
printf("execname:%s\t",execname);
printf("mountpoint:%s\t", copyinstr(arg0, 240));
printf("flag:%d\t", arg1);
printf("PID:%d\t", pid);
printf("\n");
}
syscall::umount2:return
{
printf("time:%d\t", timestamp);
printf("execname:%s\t",execname);
printf("return arg0:%d\t", arg0);
printf("PID:%d\t", pid);
printf("\n");
}
-- end of umount2.d --
I ran this as follows (on the node where the resource group is currently
running):
dtrace -q -s umount2.d
and then initiated a switch on another node: 'clrg switch -n mltstore0 smb1_rg'
For a failed attempt, I cleaned up (by doing zpool export, clrs clear, clrg
switch back to the node it was on originally), and then ran it again and got a
successful migration.
I included the timestamp because I wasn't certain that if dtrace probes output
in the same order their trigger actions occur, but it appears this may not have
been needed.
Looking at the logs that follow, it appears to me that 'zfs' is sometimes
trying to umount2 the zone's root before zoneadmd is done calling umount2. I
presume that zoneadmd is responding to the stop_sczbt which is part of the
'smb1_zone' resource. I further presume that 'hastorageplus_po' is a truncated
form of the name of the real executable 'hastorageplus_postnet_stop', which is
responsible for stopping the resource 'smb1_zpool'. What I don't understand is
who is calling 'zfs' at all and how the timing for this is determined (the
timing/sequencing for this definitely seems wrong). I understand
hastorageplus_postnet_stop needs to umount2 all the mountpoints that are under
smb1_pool0.
So, first the dtrace output for the failed migration:
-- start of FAIL.log --
time:81317653165914 execname:syslogd mountpoint:/var/run/syslog_door
flag:0 PID:401
time:81317656727485 execname:syslogd return arg0:0 PID:401
time:81318217888051 execname:umount mountpoint:/home flag:0 PID:818
time:81318221571531 execname:umount return arg0:0 PID:818
time:81318217998677 execname:umount mountpoint:/net flag:0 PID:819
time:81318221558069 execname:umount return arg0:0 PID:819
time:81318773405941 execname:kcfd mountpoint:/etc/svc/volatile/kcfd_door
flag:0 PID:232
time:81318776733762 execname:kcfd return arg0:0 PID:232
time:81323492465856 execname:umount mountpoint:/lib/libc.so.1 flag:0
PID:852
time:81323495696843 execname:umount return arg0:0 PID:852
time:81323670232146 execname:umount mountpoint:/usr flag:0 PID:856
time:81323670246733 execname:umount return arg0:-1 PID:856
time:81323670254188 execname:umount mountpoint:/usr flag:0 PID:856
time:81323670260945 execname:umount return arg0:-1 PID:856
time:81324927558568 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/var/run/name_service_door flag:0 PID:86
time:81324930826999 execname:zoneadmd return arg0:0 PID:86
time:81324930840281 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/var/run/ldap_cache_door flag:0 PID:86
time:81324933609233 execname:zoneadmd return arg0:0 PID:86
time:81324933619861 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/var/run flag:0 PID:86
time:81324936260424 execname:zoneadmd return arg0:0 PID:86
time:81324936271119 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/tmp flag:0 PID:86
time:81324938939368 execname:zoneadmd return arg0:0 PID:86
time:81324938950239 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/dev/fd flag:0 PID:86
time:81324941496873 execname:zoneadmd return arg0:0 PID:86
time:81324941507586 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/etc/svc/volatile/repository_door flag:0
PID:86
time:81324943991871 execname:zoneadmd return arg0:0 PID:86
time:81324944001875 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/etc/svc/volatile flag:0 PID:86
time:81324946581706 execname:zoneadmd return arg0:0 PID:86
time:81324946592490 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/system/object flag:0 PID:86
time:81324949089847 execname:zoneadmd return arg0:0 PID:86
time:81324949100002 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/etc/mnttab flag:0 PID:86
time:81325038747430 execname:zfs mountpoint:/smb1_pool0/smb1_zone/root
flag:0 PID:892
time:81324951856084 execname:zoneadmd return arg0:0 PID:86
time:81324951910502 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/system/contract flag:0 PID:86
time:81324954592338 execname:zoneadmd return arg0:0 PID:86
time:81324954602845 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/proc flag:0 PID:86
time:81324957107873 execname:zoneadmd return arg0:0 PID:86
time:81324957118283 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/dev flag:0 PID:86
time:81324959628415 execname:zoneadmd return arg0:0 PID:86
time:81325478095434 execname:hastorageplus_po
mountpoint:/smb1_pool0/smb1_zone/root flag:1024 PID:905
time:81325478107989 execname:hastorageplus_po return arg0:-1 PID:905
time:81327204073037 execname:zfs return arg0:0 PID:892
time:81327208669581 execname:zoneadmd
mountpoint:/var/run/zones/smb1.zoneadmd_door flag:0 PID:86
time:81327212327392 execname:zoneadmd return arg0:0 PID:86
-- end of FAIL.log --
And then the dtrace log for when it succeeds:
-- start of SUCCESS.log --
time:81435262388640 execname:syslogd mountpoint:/var/run/syslog_door
flag:0 PID:1502
time:81435266048810 execname:syslogd return arg0:0 PID:1502
time:81435914751569 execname:umount mountpoint:/home flag:0
PID:1657
time:81435918363189 execname:umount return arg0:0 PID:1657
time:81435914936865 execname:umount mountpoint:/net flag:0 PID:1658
time:81435919573910 execname:umount return arg0:0 PID:1658
time:81436587686476 execname:kcfd mountpoint:/etc/svc/volatile/kcfd_door
flag:0 PID:1287
time:81436591221746 execname:kcfd return arg0:0 PID:1287
time:81441301660986 execname:umount mountpoint:/lib/libc.so.1 flag:0
PID:1697
time:81441304881617 execname:umount return arg0:0 PID:1697
time:81441479738380 execname:umount mountpoint:/usr flag:0 PID:1699
time:81441479752738 execname:umount return arg0:-1 PID:1699
time:81441479760046 execname:umount mountpoint:/usr flag:0 PID:1699
time:81441479766628 execname:umount return arg0:-1 PID:1699
time:81442665546961 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/var/run/name_service_door flag:0
PID:1140
time:81442668789598 execname:zoneadmd return arg0:0 PID:1140
time:81442668803334 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/var/run/ldap_cache_door flag:0
PID:1140
time:81442671605309 execname:zoneadmd return arg0:0 PID:1140
time:81442671616829 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/var/run flag:0 PID:1140
time:81442674270114 execname:zoneadmd return arg0:0 PID:1140
time:81442674280955 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/tmp flag:0 PID:1140
time:81442676873354 execname:zoneadmd return arg0:0 PID:1140
time:81442676884067 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/dev/fd flag:0 PID:1140
time:81442679377023 execname:zoneadmd return arg0:0 PID:1140
time:81442679387837 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/etc/svc/volatile/repository_door flag:0
PID:1140
time:81442681906124 execname:zoneadmd return arg0:0 PID:1140
time:81442681916691 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/etc/svc/volatile flag:0 PID:1140
time:81442684532650 execname:zoneadmd return arg0:0 PID:1140
time:81442684543401 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/system/object flag:0 PID:1140
time:81442687080347 execname:zoneadmd return arg0:0 PID:1140
time:81442687090314 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/etc/mnttab flag:0 PID:1140
time:81442689544665 execname:zoneadmd return arg0:0 PID:1140
time:81442689554602 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/system/contract flag:0 PID:1140
time:81442692027816 execname:zoneadmd return arg0:0 PID:1140
time:81442692037715 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/proc flag:0 PID:1140
time:81442694508472 execname:zoneadmd return arg0:0 PID:1140
time:81442694517974 execname:zoneadmd
mountpoint:/smb1_pool0/smb1_zone/root/dev flag:0 PID:1140
time:81442697032882 execname:zoneadmd return arg0:0 PID:1140
time:81442769405120 execname:zfs mountpoint:/smb1_pool0/smb1_zone/root
flag:0 PID:1731
time:81445650144773 execname:zoneadmd
mountpoint:/var/run/zones/smb1.zoneadmd_door flag:0 PID:1140
time:81445653806133 execname:zoneadmd return arg0:0 PID:1140
time:81445645327783 execname:zfs return arg0:0 PID:1731
time:81446875296840 execname:hastorageplus_po
mountpoint:/smb1_pool0/smb1_zone flag:1024 PID:1745
time:81448383192577 execname:hastorageplus_po return arg0:0
PID:1745
time:81448383206061 execname:hastorageplus_po mountpoint:/smb1_pool0
flag:1024 PID:1745
time:81448388802294 execname:hastorageplus_po return arg0:0
PID:1745
-- end of SUCCESS.log --
--
This message posted from opensolaris.org
