Bug #4242
file rename event fires before the rename happens
Status:
Closed
Priority:
High
Assignee:
-
Category:
kernel
Start date:
2013-10-19
Due date:
% Done:
100%
Estimated time:
Difficulty:
Medium
Tags:
Gerrit CR:
Description
From Joyent's OS-2557:
So we're basically just doing a check here that after we got a 'rename' event for our file, the file has actually been moved out of the way.
What I've seen in bh1-stage2 is that this happens as you'd expect for all zones but many times over the last week it's failed because when we do the fs.exists() check here, the file that we got the rename event for, still exists.
I've confirmed what's happening using the following dtrace script:
#!/usr/sbin/dtrace -s
#pragma D option quiet
#pragma D option bufsize=256k
syscall::open:entry,
syscall::open64:entry
/copyinstr(arg0) == "/var/svc/provisioning" || (strlen(copyinstr(arg0)) == 69 && substr(copyinstr(arg0), 48) == "/var/svc/provisioning")/
{
this->watching_open = 1;
printf("%d zone %s process %s(%d) [%s] open(%s)\\n",
timestamp,
zonename,
execname,
pid,
curpsinfo->pr_psargs,
copyinstr(arg0));
}
syscall::open:return,
syscall::open64:return
/this->watching_open == 1/
{
this->watching_open = 0;
printf("%d zone %s process %s(%d) [%s] open() returned\\n",
timestamp,
zonename,
execname,
pid,
curpsinfo->pr_psargs);
}
syscall::openat:entry,
syscall::openat64:entry
/copyinstr(arg1) == "/var/svc/provisioning" || (strlen(copyinstr(arg1)) == 69 && substr(copyinstr(arg1), 48) == "/var/svc/provisioning")/
{
this->watching_openat = 1;
printf("%d zone %s process %s(%d) [%s] openat(%s)\\n",
timestamp,
zonename,
execname,
pid,
curpsinfo->pr_psargs,
copyinstr(arg1));
}
syscall::openat:return,
syscall::openat64:return
/this->watching_openat == 1/
{
this->watching_openat = 0;
printf("%d zone %s process %s(%d) [%s] openat() returned\\n",
timestamp,
zonename,
execname,
pid,
curpsinfo->pr_psargs);
}
syscall::rename:entry
/copyinstr(arg0) == "/var/svc/provisioning" || (strlen(copyinstr(arg0)) == 69 && substr(copyinstr(arg0), 48) == "/var/svc/provisioning")/
{
this->watching_rename = 1;
printf("%d zone %s process %s(%d) [%s] rename(%s, %s)\\n",
timestamp,
zonename,
execname,
pid,
curpsinfo->pr_psargs,
copyinstr(arg0),
copyinstr(arg1));
}
syscall::rename:return
/this->watching_rename == 1/
{
this->watching_rename = 0;
printf("%d zone %s process %s(%d) [%s] rename() returned\\n",
timestamp,
zonename,
execname,
pid,
curpsinfo->pr_psargs);
}
syscall::renameat:entry
/copyinstr(arg1) == "/var/svc/provisioning" || (strlen(copyinstr(arg1)) == 69 && substr(copyinstr(arg1), 48) == "/var/svc/provisioning")/
{
this->watching_renameat = 1;
printf("%d zone %s process %s(%d) [%s] renameat(%s, %s)\\n",
timestamp,
zonename,
execname,
pid,
curpsinfo->pr_psargs,
copyinstr(arg1),
copyinstr(arg3));
}
syscall::renameat:return
/this->watching_renameat == 1/
{
this->watching_renameat = 0;
printf("%d zone %s process %s(%d) [%s] renameat() returned\\n",
timestamp,
zonename,
execname,
pid,
curpsinfo->pr_psargs);
}
syscall::stat*:entry,
syscall::lstat*:entry
/copyinstr(arg0) == "/var/svc/provisioning" || (strlen(copyinstr(arg0)) == 69 && substr(copyinstr(arg0), 48) == "/var/svc/provisioning")/
{
this->watching_stat = 1;
printf("%d zone %s process %s(%d) [%s] stat(%s)\\n",
timestamp,
zonename,
execname,
pid,
curpsinfo->pr_psargs,
copyinstr(arg0));
}
syscall::stat*:return,
syscall::lstat*:return
/this->watching_stat == 1/
{
this->watching_stat = 0;
printf("%d zone %s process %s(%d) [%s] stat() returned\\n",
timestamp,
zonename,
execname,
pid,
curpsinfo->pr_psargs);
}
which I ran immediately after boot (before any zones got created) and through the whole VM boot process. The zones here for reference are:
UUID TYPE RAM STATE ALIAS bd4311b7-6eac-4a62-900f-e8b90d493a7d OS 128 running dhcpd0 efe2bf6c-4f5b-48e9-92c8-ae30b8b8ea46 OS 128 running assets0 3f58d3d3-6f81-4fa9-8050-3db8fc4508c8 OS 256 running sdc0 622f4a7b-6c93-476c-b282-e5a0dca72d46 OS 256 running dapi0 82f431b7-555a-49e3-9810-47884fa3ef05 OS 256 running napi0 923b8c9c-7b24-4c3f-8b26-5e687ac09e63 OS 256 running binder0 a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d OS 256 running amon0 9c4248f8-4728-4401-845e-3c6c4a203811 OS 512 running sapi0 41b22043-9c6b-48a8-a2bf-5db51f85bfc1 OS 768 running imgapi0 19c8c449-7b60-438e-b3ba-f32a02d0aca1 OS 1024 running fwapi0 277c18a3-b79f-4e3e-a410-de5accd48918 OS 1024 running papi0 2fae2004-63b6-4d6c-a64b-26617ace55da OS 1024 running amonredis0 759eff66-be08-4fdb-a442-cd068e568f0a OS 1024 failed vmapi0 ad1564ed-881a-46f2-8ada-65c8aa7f4db4 OS 1024 running cnapi0 d0300fef-2e27-4043-a4e4-4e6a529ff0fb OS 1024 running redis0 db38d6f9-489a-477f-a27c-6e4c674e5894 OS 1024 running rabbitmq0 6cd4d655-103b-49dd-a866-49e30cd7780e OS 2048 running manatee0 ac8635ad-0daf-44da-ab03-52b9cae6e17c OS 8192 running workflow0 b4b9814c-17b5-4ccd-be70-b77995d0077f OS 8192 running moray0 e2025801-a429-42dd-b5dc-840ede84cbc7 OS 8192 running ufds0
and the output from this was:
283298356481 zone global process vmadm(10414) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/efe2bf6c-4f5b-48e9-92c8-ae30b8b8ea46/root/var/svc/provisioning) 283790648379 zone global process picld(2815) [/usr/lib/picl/picld] open() returned 287184535186 zone efe2bf6c-4f5b-48e9-92c8-ae30b8b8ea46 process mdata-execute(10998) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 287184554386 zone efe2bf6c-4f5b-48e9-92c8-ae30b8b8ea46 process mdata-execute(10998) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 287186858401 zone efe2bf6c-4f5b-48e9-92c8-ae30b8b8ea46 process mv(11000) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 287186871658 zone efe2bf6c-4f5b-48e9-92c8-ae30b8b8ea46 process mv(11000) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 287187025683 zone efe2bf6c-4f5b-48e9-92c8-ae30b8b8ea46 process mv(11000) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 287187035605 zone efe2bf6c-4f5b-48e9-92c8-ae30b8b8ea46 process mv(11000) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 287187062579 zone efe2bf6c-4f5b-48e9-92c8-ae30b8b8ea46 process mv(11000) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 287187111337 zone efe2bf6c-4f5b-48e9-92c8-ae30b8b8ea46 process mv(11000) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 287187376175 zone global process vmadm(10414) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/efe2bf6c-4f5b-48e9-92c8-ae30b8b8ea46/root/var/svc/provisioning) 287187400922 zone global process vmadm(10414) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 305339012320 zone global process vmadm(11172) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/9c4248f8-4728-4401-845e-3c6c4a203811/root/var/svc/provisioning) 305931873104 zone global process sed(11226) [sed -e s/^/SYSINFO_/] open() returned 308643705621 zone 9c4248f8-4728-4401-845e-3c6c4a203811 process mdata-execute(11740) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 308643719862 zone 9c4248f8-4728-4401-845e-3c6c4a203811 process mdata-execute(11740) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 308645812118 zone 9c4248f8-4728-4401-845e-3c6c4a203811 process mv(11743) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 308645824637 zone 9c4248f8-4728-4401-845e-3c6c4a203811 process mv(11743) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 308645976976 zone 9c4248f8-4728-4401-845e-3c6c4a203811 process mv(11743) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 308645986734 zone 9c4248f8-4728-4401-845e-3c6c4a203811 process mv(11743) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 308646011421 zone 9c4248f8-4728-4401-845e-3c6c4a203811 process mv(11743) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 308646060632 zone 9c4248f8-4728-4401-845e-3c6c4a203811 process mv(11743) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 308646306804 zone global process vmadm(11172) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/9c4248f8-4728-4401-845e-3c6c4a203811/root/var/svc/provisioning) 308646339658 zone global process vmadm(11172) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 330878489026 zone global process vmadm(12006) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/923b8c9c-7b24-4c3f-8b26-5e687ac09e63/root/var/svc/provisioning) 330911322642 zone global process svc.configd(12040) [/lib/svc/bin/svc.configd -p -d /var/run/scfdrAAA8Ham4f -r /zones/923b8c9c-7b24-] open() returned 334098021832 zone 923b8c9c-7b24-4c3f-8b26-5e687ac09e63 process mdata-execute(12600) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 334098036457 zone 923b8c9c-7b24-4c3f-8b26-5e687ac09e63 process mdata-execute(12600) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 334100162411 zone 923b8c9c-7b24-4c3f-8b26-5e687ac09e63 process mv(12603) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 334100175319 zone 923b8c9c-7b24-4c3f-8b26-5e687ac09e63 process mv(12603) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 334100328278 zone 923b8c9c-7b24-4c3f-8b26-5e687ac09e63 process mv(12603) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 334100338210 zone 923b8c9c-7b24-4c3f-8b26-5e687ac09e63 process mv(12603) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 334100363234 zone 923b8c9c-7b24-4c3f-8b26-5e687ac09e63 process mv(12603) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 334100411200 zone 923b8c9c-7b24-4c3f-8b26-5e687ac09e63 process mv(12603) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 334100663309 zone global process vmadm(12006) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/923b8c9c-7b24-4c3f-8b26-5e687ac09e63/root/var/svc/provisioning) 334100692800 zone global process vmadm(12006) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 366636049885 zone global process vmadm(13054) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/6cd4d655-103b-49dd-a866-49e30cd7780e/root/var/svc/provisioning) 367051164639 zone global process zonename(13105) [zonename] open() returned 370014855268 zone 6cd4d655-103b-49dd-a866-49e30cd7780e process mdata-execute(13637) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 370014873583 zone 6cd4d655-103b-49dd-a866-49e30cd7780e process mdata-execute(13637) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 370016523187 zone 6cd4d655-103b-49dd-a866-49e30cd7780e process mv(13639) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 370016537055 zone 6cd4d655-103b-49dd-a866-49e30cd7780e process mv(13639) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 370016696925 zone 6cd4d655-103b-49dd-a866-49e30cd7780e process mv(13639) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 370016706760 zone 6cd4d655-103b-49dd-a866-49e30cd7780e process mv(13639) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 370016731958 zone 6cd4d655-103b-49dd-a866-49e30cd7780e process mv(13639) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 370016780582 zone 6cd4d655-103b-49dd-a866-49e30cd7780e process mv(13639) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 370017035780 zone global process vmadm(13054) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/6cd4d655-103b-49dd-a866-49e30cd7780e/root/var/svc/provisioning) 370017065049 zone global process vmadm(13054) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 396587554396 zone global process vmadm(14002) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/b4b9814c-17b5-4ccd-be70-b77995d0077f/root/var/svc/provisioning) 397218018244 zone global process sed(14074) [sed -e s/^/CONFIG_/] open() returned 399973260945 zone b4b9814c-17b5-4ccd-be70-b77995d0077f process mdata-execute(14569) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 399973275346 zone b4b9814c-17b5-4ccd-be70-b77995d0077f process mdata-execute(14569) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 399976406168 zone b4b9814c-17b5-4ccd-be70-b77995d0077f process mv(14572) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 399976423904 zone b4b9814c-17b5-4ccd-be70-b77995d0077f process mv(14572) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 399976653458 zone b4b9814c-17b5-4ccd-be70-b77995d0077f process mv(14572) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 399976668464 zone b4b9814c-17b5-4ccd-be70-b77995d0077f process mv(14572) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 399976704575 zone b4b9814c-17b5-4ccd-be70-b77995d0077f process mv(14572) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 399976772838 zone b4b9814c-17b5-4ccd-be70-b77995d0077f process mv(14572) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 399977004054 zone global process vmadm(14002) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/b4b9814c-17b5-4ccd-be70-b77995d0077f/root/var/svc/provisioning) 399977035185 zone global process vmadm(14002) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 427243739806 zone global process vmadm(14975) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/2fae2004-63b6-4d6c-a64b-26617ace55da/root/var/svc/provisioning) 427279639799 zone global process svc.configd(15011) [/lib/svc/bin/svc.configd -p -d /var/run/scfdrAAASdacvh -r /zones/2fae2004-63b6-] open() returned 430739453116 zone 2fae2004-63b6-4d6c-a64b-26617ace55da process mdata-execute(15541) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 430739467475 zone 2fae2004-63b6-4d6c-a64b-26617ace55da process mdata-execute(15541) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 430741683478 zone 2fae2004-63b6-4d6c-a64b-26617ace55da process mv(15544) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 430741696432 zone 2fae2004-63b6-4d6c-a64b-26617ace55da process mv(15544) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 430741853389 zone 2fae2004-63b6-4d6c-a64b-26617ace55da process mv(15544) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 430741863290 zone 2fae2004-63b6-4d6c-a64b-26617ace55da process mv(15544) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 430741888256 zone 2fae2004-63b6-4d6c-a64b-26617ace55da process mv(15544) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 430741936257 zone 2fae2004-63b6-4d6c-a64b-26617ace55da process mv(15544) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 430742183054 zone global process vmadm(14975) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/2fae2004-63b6-4d6c-a64b-26617ace55da/root/var/svc/provisioning) 430742213917 zone global process vmadm(14975) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 455930285204 zone global process vmadm(15859) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/d0300fef-2e27-4043-a4e4-4e6a529ff0fb/root/var/svc/provisioning) 456450481141 zone global process svccfg(15912) [svccfg -s smartdc/init listprop */zpool] open() returned 459537330297 zone d0300fef-2e27-4043-a4e4-4e6a529ff0fb process mdata-execute(16462) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 459537344233 zone d0300fef-2e27-4043-a4e4-4e6a529ff0fb process mdata-execute(16462) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 459539497770 zone d0300fef-2e27-4043-a4e4-4e6a529ff0fb process mv(16465) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 459539510477 zone d0300fef-2e27-4043-a4e4-4e6a529ff0fb process mv(16465) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 459539661841 zone d0300fef-2e27-4043-a4e4-4e6a529ff0fb process mv(16465) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 459539671594 zone d0300fef-2e27-4043-a4e4-4e6a529ff0fb process mv(16465) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 459539695845 zone d0300fef-2e27-4043-a4e4-4e6a529ff0fb process mv(16465) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 459539744413 zone d0300fef-2e27-4043-a4e4-4e6a529ff0fb process mv(16465) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 459539977657 zone global process vmadm(15859) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/d0300fef-2e27-4043-a4e4-4e6a529ff0fb/root/var/svc/provisioning) 459540016978 zone global process vmadm(15859) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 485252898874 zone global process vmadm(16794) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/e2025801-a429-42dd-b5dc-840ede84cbc7/root/var/svc/provisioning) 485304924418 zone global process svc.configd(16827) [/lib/svc/bin/svc.configd -p -d /var/run/scfdrAAAzoa0ni -r /zones/e2025801-a429-] open() returned 488617570776 zone e2025801-a429-42dd-b5dc-840ede84cbc7 process mdata-execute(17362) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 488617585321 zone e2025801-a429-42dd-b5dc-840ede84cbc7 process mdata-execute(17362) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 488619757546 zone e2025801-a429-42dd-b5dc-840ede84cbc7 process mv(17365) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 488619770313 zone e2025801-a429-42dd-b5dc-840ede84cbc7 process mv(17365) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 488619924935 zone e2025801-a429-42dd-b5dc-840ede84cbc7 process mv(17365) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 488619934581 zone e2025801-a429-42dd-b5dc-840ede84cbc7 process mv(17365) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 488619959823 zone e2025801-a429-42dd-b5dc-840ede84cbc7 process mv(17365) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 488620007747 zone e2025801-a429-42dd-b5dc-840ede84cbc7 process mv(17365) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 488620259633 zone global process vmadm(16794) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/e2025801-a429-42dd-b5dc-840ede84cbc7/root/var/svc/provisioning) 488620297408 zone global process vmadm(16794) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 526804066320 zone global process vmadm(18040) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/ac8635ad-0daf-44da-ab03-52b9cae6e17c/root/var/svc/provisioning) 526836349795 zone global process svc.configd(18092) [/lib/svc/bin/svc.configd -p -d /var/run/scfdrAAAuxaw1i -r /zones/ac8635ad-0daf-] open() returned 530320058797 zone ac8635ad-0daf-44da-ab03-52b9cae6e17c process mdata-execute(18638) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 530320077434 zone ac8635ad-0daf-44da-ab03-52b9cae6e17c process mdata-execute(18638) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 530322347870 zone ac8635ad-0daf-44da-ab03-52b9cae6e17c process mv(18641) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 530322360387 zone ac8635ad-0daf-44da-ab03-52b9cae6e17c process mv(18641) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 530322515600 zone ac8635ad-0daf-44da-ab03-52b9cae6e17c process mv(18641) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 530322525577 zone ac8635ad-0daf-44da-ab03-52b9cae6e17c process mv(18641) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 530322551410 zone ac8635ad-0daf-44da-ab03-52b9cae6e17c process mv(18641) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 530322600950 zone ac8635ad-0daf-44da-ab03-52b9cae6e17c process mv(18641) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 530323042217 zone global process vmadm(18040) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/ac8635ad-0daf-44da-ab03-52b9cae6e17c/root/var/svc/provisioning) 530323073956 zone global process vmadm(18040) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 553612196533 zone global process vmadm(18959) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d/root/var/svc/provisioning) 553869155803 zone global process ksh93(18994) [/bin/sh -c rm -f /zones/a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d/root/var/adm/utmpx] open() returned 557200316589 zone a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d process mdata-execute(19522) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 557200331369 zone a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d process mdata-execute(19522) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 557202562138 zone a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d process mv(19525) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 557202575277 zone a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d process mv(19525) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 557202733321 zone a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d process mv(19525) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 557202743154 zone a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d process mv(19525) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 557202768306 zone a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d process mv(19525) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 557202816853 zone a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d process mv(19525) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 557203075074 zone global process vmadm(18959) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/a7cbbfb2-5111-4b2b-8fa5-9d2f3296b05d/root/var/svc/provisioning) 557203099694 zone global process vmadm(18959) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 579423972924 zone global process vmadm(19920) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/3f58d3d3-6f81-4fa9-8050-3db8fc4508c8/root/var/svc/provisioning) 579454594935 zone global process svc.configd(19953) [/lib/svc/bin/svc.configd -p -d /var/run/scfdrAAAEnaGVj -r /zones/3f58d3d3-6f81-] open() returned 583054830254 zone 3f58d3d3-6f81-4fa9-8050-3db8fc4508c8 process mdata-execute(20487) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 583054844779 zone 3f58d3d3-6f81-4fa9-8050-3db8fc4508c8 process mdata-execute(20487) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 583057062028 zone 3f58d3d3-6f81-4fa9-8050-3db8fc4508c8 process mv(20490) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 583057074869 zone 3f58d3d3-6f81-4fa9-8050-3db8fc4508c8 process mv(20490) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 583057229957 zone 3f58d3d3-6f81-4fa9-8050-3db8fc4508c8 process mv(20490) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 583057239909 zone 3f58d3d3-6f81-4fa9-8050-3db8fc4508c8 process mv(20490) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 583057265301 zone 3f58d3d3-6f81-4fa9-8050-3db8fc4508c8 process mv(20490) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 583057315661 zone 3f58d3d3-6f81-4fa9-8050-3db8fc4508c8 process mv(20490) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 583057544129 zone global process vmadm(19920) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/3f58d3d3-6f81-4fa9-8050-3db8fc4508c8/root/var/svc/provisioning) 583057584564 zone global process vmadm(19920) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 610762407561 zone global process vmadm(21063) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/277c18a3-b79f-4e3e-a410-de5accd48918/root/var/svc/provisioning) 611778099194 zone global process grep(21163) [grep ^headnode=true] open() returned 614376211351 zone 277c18a3-b79f-4e3e-a410-de5accd48918 process mdata-execute(21648) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 614376225986 zone 277c18a3-b79f-4e3e-a410-de5accd48918 process mdata-execute(21648) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 614378421321 zone 277c18a3-b79f-4e3e-a410-de5accd48918 process mv(21651) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 614378434289 zone 277c18a3-b79f-4e3e-a410-de5accd48918 process mv(21651) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 614378589519 zone 277c18a3-b79f-4e3e-a410-de5accd48918 process mv(21651) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 614378599472 zone 277c18a3-b79f-4e3e-a410-de5accd48918 process mv(21651) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 614378624634 zone 277c18a3-b79f-4e3e-a410-de5accd48918 process mv(21651) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 614378673401 zone 277c18a3-b79f-4e3e-a410-de5accd48918 process mv(21651) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 614378919793 zone global process vmadm(21063) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/277c18a3-b79f-4e3e-a410-de5accd48918/root/var/svc/provisioning) 614378951917 zone global process vmadm(21063) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 637558728257 zone global process vmadm(22237) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/82f431b7-555a-49e3-9810-47884fa3ef05/root/var/svc/provisioning) 637588914564 zone global process svc.configd(22282) [/lib/svc/bin/svc.configd -p -d /var/run/scfdrAAA1zas4k -r /zones/82f431b7-555a-] open() returned 641267452728 zone 82f431b7-555a-49e3-9810-47884fa3ef05 process mdata-execute(22831) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 641267471976 zone 82f431b7-555a-49e3-9810-47884fa3ef05 process mdata-execute(22831) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 641269838973 zone 82f431b7-555a-49e3-9810-47884fa3ef05 process mv(22834) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 641269851882 zone 82f431b7-555a-49e3-9810-47884fa3ef05 process mv(22834) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 641270019888 zone 82f431b7-555a-49e3-9810-47884fa3ef05 process mv(22834) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 641270032849 zone 82f431b7-555a-49e3-9810-47884fa3ef05 process mv(22834) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 641270059559 zone 82f431b7-555a-49e3-9810-47884fa3ef05 process mv(22834) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 641270108325 zone 82f431b7-555a-49e3-9810-47884fa3ef05 process mv(22834) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 641270348588 zone global process vmadm(22237) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/82f431b7-555a-49e3-9810-47884fa3ef05/root/var/svc/provisioning) 641270380375 zone global process vmadm(22237) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 665207368746 zone global process vmadm(23133) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/db38d6f9-489a-477f-a27c-6e4c674e5894/root/var/svc/provisioning) 665393059130 zone global process init(1) [/sbin/init] open() returned 668947725355 zone db38d6f9-489a-477f-a27c-6e4c674e5894 process mdata-execute(23733) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 668947739375 zone db38d6f9-489a-477f-a27c-6e4c674e5894 process mdata-execute(23733) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 668949998525 zone db38d6f9-489a-477f-a27c-6e4c674e5894 process mv(23736) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 668950019342 zone db38d6f9-489a-477f-a27c-6e4c674e5894 process mv(23736) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 668950179520 zone db38d6f9-489a-477f-a27c-6e4c674e5894 process mv(23736) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 668950189179 zone db38d6f9-489a-477f-a27c-6e4c674e5894 process mv(23736) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 668950214279 zone db38d6f9-489a-477f-a27c-6e4c674e5894 process mv(23736) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 668950263321 zone db38d6f9-489a-477f-a27c-6e4c674e5894 process mv(23736) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 668950507023 zone global process vmadm(23133) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/db38d6f9-489a-477f-a27c-6e4c674e5894/root/var/svc/provisioning) 668950538090 zone global process vmadm(23133) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 696163923456 zone global process vmadm(24326) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/41b22043-9c6b-48a8-a2bf-5db51f85bfc1/root/var/svc/provisioning) 696476017047 zone global process vmadm(24326) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open() returned 700226511555 zone 41b22043-9c6b-48a8-a2bf-5db51f85bfc1 process mdata-execute(24954) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 700226526302 zone 41b22043-9c6b-48a8-a2bf-5db51f85bfc1 process mdata-execute(24954) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 700228833598 zone 41b22043-9c6b-48a8-a2bf-5db51f85bfc1 process mv(24956) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 700228846365 zone 41b22043-9c6b-48a8-a2bf-5db51f85bfc1 process mv(24956) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 700229003806 zone 41b22043-9c6b-48a8-a2bf-5db51f85bfc1 process mv(24956) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 700229013684 zone 41b22043-9c6b-48a8-a2bf-5db51f85bfc1 process mv(24956) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 700229039770 zone 41b22043-9c6b-48a8-a2bf-5db51f85bfc1 process mv(24956) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 700229089244 zone 41b22043-9c6b-48a8-a2bf-5db51f85bfc1 process mv(24956) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 700229338830 zone global process vmadm(24326) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/41b22043-9c6b-48a8-a2bf-5db51f85bfc1/root/var/svc/provisioning) 700229366617 zone global process vmadm(24326) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 726908935043 zone global process vmadm(25452) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/ad1564ed-881a-46f2-8ada-65c8aa7f4db4/root/var/svc/provisioning) 726934278318 zone global process svc.configd(25485) [/lib/svc/bin/svc.configd -p -d /var/run/scfdrAAA2nayCm -r /zones/ad1564ed-881a-] open() returned 730848163228 zone ad1564ed-881a-46f2-8ada-65c8aa7f4db4 process mdata-execute(26032) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 730848182612 zone ad1564ed-881a-46f2-8ada-65c8aa7f4db4 process mdata-execute(26032) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 730850603192 zone ad1564ed-881a-46f2-8ada-65c8aa7f4db4 process mv(26035) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 730850615954 zone ad1564ed-881a-46f2-8ada-65c8aa7f4db4 process mv(26035) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 730850771429 zone ad1564ed-881a-46f2-8ada-65c8aa7f4db4 process mv(26035) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 730850781255 zone ad1564ed-881a-46f2-8ada-65c8aa7f4db4 process mv(26035) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 730850806166 zone ad1564ed-881a-46f2-8ada-65c8aa7f4db4 process mv(26035) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 730850855350 zone ad1564ed-881a-46f2-8ada-65c8aa7f4db4 process mv(26035) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 730851097437 zone global process vmadm(25452) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/ad1564ed-881a-46f2-8ada-65c8aa7f4db4/root/var/svc/provisioning) 730851128595 zone global process vmadm(25452) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 752687779551 zone global process vmadm(26357) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/bd4311b7-6eac-4a62-900f-e8b90d493a7d/root/var/svc/provisioning) 752719386876 zone global process svc.configd(26390) [/lib/svc/bin/svc.configd -p -d /var/run/scfdrAAAVGaQ4m -r /zones/bd4311b7-6eac-] open() returned 756863651679 zone bd4311b7-6eac-4a62-900f-e8b90d493a7d process mdata-execute(26990) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 756863666589 zone bd4311b7-6eac-4a62-900f-e8b90d493a7d process mdata-execute(26990) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 756866190605 zone bd4311b7-6eac-4a62-900f-e8b90d493a7d process mv(26993) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 756866203666 zone bd4311b7-6eac-4a62-900f-e8b90d493a7d process mv(26993) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 756866362170 zone bd4311b7-6eac-4a62-900f-e8b90d493a7d process mv(26993) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 756866371852 zone bd4311b7-6eac-4a62-900f-e8b90d493a7d process mv(26993) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 756866398625 zone bd4311b7-6eac-4a62-900f-e8b90d493a7d process mv(26993) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 756866448642 zone bd4311b7-6eac-4a62-900f-e8b90d493a7d process mv(26993) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 756866737974 zone global process vmadm(26357) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/bd4311b7-6eac-4a62-900f-e8b90d493a7d/root/var/svc/provisioning) 756866785982 zone global process vmadm(26357) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 779245517256 zone global process vmadm(27258) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/622f4a7b-6c93-476c-b282-e5a0dca72d46/root/var/svc/provisioning) 779277410422 zone global process zpool(27313) [/sbin/zpool list -H -o name,size,allocated,free,cap,health,altroot] open() returned 783150727306 zone 622f4a7b-6c93-476c-b282-e5a0dca72d46 process mdata-execute(27866) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 783150741796 zone 622f4a7b-6c93-476c-b282-e5a0dca72d46 process mdata-execute(27866) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 783153568168 zone 622f4a7b-6c93-476c-b282-e5a0dca72d46 process mv(27869) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 783153581267 zone 622f4a7b-6c93-476c-b282-e5a0dca72d46 process mv(27869) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 783153736451 zone 622f4a7b-6c93-476c-b282-e5a0dca72d46 process mv(27869) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 783153746306 zone 622f4a7b-6c93-476c-b282-e5a0dca72d46 process mv(27869) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 783153771422 zone 622f4a7b-6c93-476c-b282-e5a0dca72d46 process mv(27869) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 783153819359 zone 622f4a7b-6c93-476c-b282-e5a0dca72d46 process mv(27869) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 783154047398 zone global process vmadm(27258) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/622f4a7b-6c93-476c-b282-e5a0dca72d46/root/var/svc/provisioning) 783154077630 zone global process vmadm(27258) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 808447570267 zone global process vmadm(28339) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/19c8c449-7b60-438e-b3ba-f32a02d0aca1/root/var/svc/provisioning) 808516179957 zone global process svc.configd(28375) [/lib/svc/bin/svc.configd -p -d /var/run/scfdrAAA.haQ2n -r /zones/19c8c449-7b60-] open() returned 812600162015 zone 19c8c449-7b60-438e-b3ba-f32a02d0aca1 process mdata-execute(28929) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 812600176346 zone 19c8c449-7b60-438e-b3ba-f32a02d0aca1 process mdata-execute(28929) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 812602423803 zone 19c8c449-7b60-438e-b3ba-f32a02d0aca1 process mv(28932) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 812602436742 zone 19c8c449-7b60-438e-b3ba-f32a02d0aca1 process mv(28932) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 812602599058 zone 19c8c449-7b60-438e-b3ba-f32a02d0aca1 process mv(28932) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 812602608766 zone 19c8c449-7b60-438e-b3ba-f32a02d0aca1 process mv(28932) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 812602633694 zone 19c8c449-7b60-438e-b3ba-f32a02d0aca1 process mv(28932) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 812602682237 zone 19c8c449-7b60-438e-b3ba-f32a02d0aca1 process mv(28932) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned 812602934504 zone global process vmadm(28339) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/19c8c449-7b60-438e-b3ba-f32a02d0aca1/root/var/svc/provisioning) 812602969308 zone global process vmadm(28339) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 835983255550 zone global process vmadm(30313) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] open(/zones/759eff66-be08-4fdb-a442-cd068e568f0a/root/var/svc/provisioning) 836156595739 zone global process init(1) [/sbin/init] open() returned 839992122904 zone 759eff66-be08-4fdb-a442-cd068e568f0a process mdata-execute(30923) [/usr/bin/bash /lib/svc/method/mdata-execute] stat(/var/svc/provisioning) 839992138062 zone 759eff66-be08-4fdb-a442-cd068e568f0a process mdata-execute(30923) [/usr/bin/bash /lib/svc/method/mdata-execute] stat() returned 839994399444 zone 759eff66-be08-4fdb-a442-cd068e568f0a process mv(30926) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 839994412087 zone 759eff66-be08-4fdb-a442-cd068e568f0a process mv(30926) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 839994565481 zone 759eff66-be08-4fdb-a442-cd068e568f0a process mv(30926) [mv /var/svc/provisioning /var/svc/provision_success] stat(/var/svc/provisioning) 839994575205 zone 759eff66-be08-4fdb-a442-cd068e568f0a process mv(30926) [mv /var/svc/provisioning /var/svc/provision_success] stat() returned 839994599933 zone 759eff66-be08-4fdb-a442-cd068e568f0a process mv(30926) [mv /var/svc/provisioning /var/svc/provision_success] rename(/var/svc/provisioning, /var/svc/provision_success) 839994889568 zone global process vmadm(30313) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat(/zones/759eff66-be08-4fdb-a442-cd068e568f0a/root/var/svc/provisioning) 839994915584 zone global process vmadm(30313) [/usr/node/bin/node --abort_on_uncaught_exception /usr/sbin/vmadm create] stat() returned 839995112876 zone 759eff66-be08-4fdb-a442-cd068e568f0a process mv(30926) [mv /var/svc/provisioning /var/svc/provision_success] rename() returned
As you can see here, for the vmapi zone we end up with:
1) rename:entry
2) stat:entry
3) stat:return
4) rename:return
so the rename is still in progress when we do our stat from fs.exists() and this is why it's saying the file exists. On all the other zones the pattern looks like:
1) rename:entry
2) rename:return
3) stat:entry
4) stat:return
which is what I'd have expected.
This behavior is surprising and I'd expect that if I get a 'rename' event the file would have already been renamed. I'll be looking into this further to see if I can figure out who's doing this and if it's what we should be expecting while also trying to think of a workaround to get staging back to running.
It turns out that the problem here is related to when we fire the events. We fire them before the actual rename operation is completed.
History
Updated by Jerry Jelinek about 4 years ago
Updated by The VE_PRE_RENAME_* events fire before the rename operation and are primarily used for specialized applications, such as NFSv4 delegation, which need to know about rename before it occurs. Most consumers want the event after the rename has happened.
Updated by Electric Monk about 4 years ago
Updated by - Status changed from New to Closed
- % Done changed from 90 to 100
git commit 54207fd2e1e7ed01d0416da8cf296dbef920fbfc
commit 54207fd2e1e7ed01d0416da8cf296dbef920fbfc
Author: Jerry Jelinek <jerry.jelinek@joyent.com>
Date: 2016-03-23T21:18:49.000Z
4242 file rename event fires before the rename happens
Reviewed by: Robert Mustacchi <rm@joyent.com>
Reviewed by: Marcel Telka <marcel@telka.sk>
Approved by: Dan McDonald <danmcd@omniti.com>