eric kustarz
2005-Dec-03 00:22 UTC
[dtrace-discuss] illegal operation in action #6 : can different providers use the same aggregation name?
so i was running the attatched script, and got many of these errors:
dtrace: error on enabled probe ID 14 (ID 33702:
fbt:zfs:zfs_getattr:return): illegal operation in action #6
dtrace: error on enabled probe ID 26 (ID 34790:
fbt:zfs:zfs_inactive:return): illegal operation in action #6
dtrace: error on enabled probe ID 20 (ID 33708:
fbt:zfs:zfs_lookup:return): illegal operation in action #6
I broke the script once i added these first two clauses for the syscall
provider:
syscall::stat64:entry
{
self->stat64 = timestamp;
}
syscall::stat64:return
/self->stat64/
{
@sum[probefunc] = sum(timestamp - self->stat64);
self->stat64 = 0;
}
Without those two clauses, it runs ok... If i change the
''syscall::stat64:return'' clause to use a different aggregation
name (say
''syscall_sum'' instead of ''sum'' - where
''sum'' is the aggregation name
used by the rest of the script), then it works a-ok.
So i''m guessing the error comes from dtrace_aggregate():
if (action != key->dtak_action) {
/*
* We are aggregating on the same value in the same
* aggregation with two different aggregating
actions.
* (This should have been picked up in the compiler,
* so we may be dealing with errant or devious DIF.)
* This is an error condition; we indicate as much,
* and return.
*/
DTRACE_CPUFLAG_SET(CPU_DTRACE_ILLOP);
return;
}
So is it illegal for different providers to use the same aggregation name?
I can also get the script to successfully run if i remove all the count
aggregates, so i''m guessing its partially a timing thing...
I was doing the simple tar test of /usr/dict/words while the script was
running to induce failure:
#/bin/time /usr/sbin/tar cvf bench.tar .. > /dev/null
This was running:
fsh-suzuki# uname -a
SunOS fsh-suzuki 5.11 onnv-gate:2005-11-28 sun4u sparc SUNW,Sun-Fire-V210
fsh-suzuki#
eric
ps: yeah yeah i know the script is way long and i could just merge
almost all the entry and return clauses for the various vops into two
total clauses each
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: stat64_vops.d
URL:
<http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20051202/e5eed622/attachment.ksh>
Adam Leventhal
2005-Dec-13 04:39 UTC
[dtrace-discuss] illegal operation in action #6 : can different providers use the same aggregation name?
Hi Eric, Sorry for not replying sooner. That definitely sounds like a bug, but I''m unable to reproduce the problem on the latest bits. It would be useful if you could send the output of dtrace -S -s <script.d> which shows the DIF bytecodes used to encode your program. Adam On Fri, Dec 02, 2005 at 04:22:18PM -0800, eric kustarz wrote:> so i was running the attatched script, and got many of these errors: > > dtrace: error on enabled probe ID 14 (ID 33702: > fbt:zfs:zfs_getattr:return): illegal operation in action #6 > dtrace: error on enabled probe ID 26 (ID 34790: > fbt:zfs:zfs_inactive:return): illegal operation in action #6 > dtrace: error on enabled probe ID 20 (ID 33708: > fbt:zfs:zfs_lookup:return): illegal operation in action #6 > > > I broke the script once i added these first two clauses for the syscall > provider: > > syscall::stat64:entry > { > self->stat64 = timestamp; > } > > syscall::stat64:return > /self->stat64/ > { > @sum[probefunc] = sum(timestamp - self->stat64); > self->stat64 = 0; > } > > Without those two clauses, it runs ok... If i change the > ''syscall::stat64:return'' clause to use a different aggregation name (say > ''syscall_sum'' instead of ''sum'' - where ''sum'' is the aggregation name > used by the rest of the script), then it works a-ok. > > So i''m guessing the error comes from dtrace_aggregate(): > if (action != key->dtak_action) { > /* > * We are aggregating on the same value in the same > * aggregation with two different aggregating > actions. > * (This should have been picked up in the compiler, > * so we may be dealing with errant or devious DIF.) > * This is an error condition; we indicate as much, > * and return. > */ > DTRACE_CPUFLAG_SET(CPU_DTRACE_ILLOP); > return; > } > > So is it illegal for different providers to use the same aggregation name? > > I can also get the script to successfully run if i remove all the count > aggregates, so i''m guessing its partially a timing thing... > > I was doing the simple tar test of /usr/dict/words while the script was > running to induce failure: > #/bin/time /usr/sbin/tar cvf bench.tar .. > /dev/null > > This was running: > fsh-suzuki# uname -a > SunOS fsh-suzuki 5.11 onnv-gate:2005-11-28 sun4u sparc SUNW,Sun-Fire-V210 > fsh-suzuki# > > eric > > ps: yeah yeah i know the script is way long and i could just merge > almost all the entry and return clauses for the various vops into two > total clauses each >> #!/usr/sbin/dtrace -FCs > > syscall::stat64:entry > { > self->stat64 = timestamp; > } > > syscall::stat64:return > /self->stat64/ > { > @syscall_sum[probefunc] = sum(timestamp - self->stat64); > self->stat64 = 0; > } > > zfs_open:entry > /self->stat64/ > { > self->open = timestamp; > } > > zfs_open:return > /self->open/ > { > @avg[probefunc] = avg(timestamp - self->open); > @sum[probefunc] = sum(timestamp - self->open); > self->open = 0; > } > > zfs_close:entry > /self->stat64/ > { > self->close = timestamp; > } > > zfs_close:return > /self->close/ > { > @avg[probefunc] = avg(timestamp - self->close); > @sum[probefunc] = sum(timestamp - self->close); > self->close = 0; > } > > zfs_read:entry > /self->stat64/ > { > self->read = timestamp; > } > > zfs_read:return > /self->read/ > { > @avg[probefunc] = avg(timestamp - self->read); > @sum[probefunc] = sum(timestamp - self->read); > self->read = 0; > } > > zfs_write:entry > /self->stat64/ > { > self->write = timestamp; > } > > zfs_write:return > /self->write/ > { > @avg[probefunc] = avg(timestamp - self->write); > @sum[probefunc] = sum(timestamp - self->write); > self->write = 0; > } > > zfs_ioctl:entry > /self->stat64/ > { > self->ioctl = timestamp; > } > > zfs_ioctl:return > /self->ioctl/ > { > @avg[probefunc] = avg(timestamp - self->ioctl); > @sum[probefunc] = sum(timestamp - self->ioctl); > self->ioctl = 0; > } > > zfs_getattr:entry > /self->stat64/ > { > self->getattr = timestamp; > } > > zfs_getattr:return > /self->getattr/ > { > @avg[probefunc] = avg(timestamp - self->getattr); > @sum[probefunc] = sum(timestamp - self->getattr); > self->getattr = 0; > } > > zfs_setattr:entry > /self->stat64/ > { > self->setattr = timestamp; > } > > zfs_setattr:return > /self->setattr/ > { > @avg[probefunc] = avg(timestamp - self->setattr); > @sum[probefunc] = sum(timestamp - self->setattr); > self->setattr = 0; > } > > zfs_access:entry > /self->stat64/ > { > self->access = timestamp; > } > > zfs_access:return > /self->access/ > { > @avg[probefunc] = avg(timestamp - self->access); > @sum[probefunc] = sum(timestamp - self->access); > self->access = 0; > } > > zfs_lookup:entry > /self->stat64/ > { > self->lookup = timestamp; > } > > zfs_lookup:return > /self->lookup/ > { > @avg[probefunc] = avg(timestamp - self->lookup); > @sum[probefunc] = sum(timestamp - self->lookup); > self->lookup = 0; > } > > zfs_rename:entry > /self->stat64/ > { > self->rename = timestamp; > } > > zfs_rename:return > /self->rename/ > { > @avg[probefunc] = avg(timestamp - self->rename); > @sum[probefunc] = sum(timestamp - self->rename); > self->rename = 0; > } > > zfs_fsync:entry > /self->stat64/ > { > self->fsync = timestamp; > } > > zfs_fsync:return > /self->fsync/ > { > @avg[probefunc] = avg(timestamp - self->fsync); > @sum[probefunc] = sum(timestamp - self->fsync); > self->fsync = 0; > } > > zfs_inactive:entry > /self->stat64/ > { > self->inactive = timestamp; > } > > zfs_inactive:return > /self->inactive/ > { > @avg[probefunc] = avg(timestamp - self->inactive); > @sum[probefunc] = sum(timestamp - self->inactive); > self->inactive = 0; > } > > zfs_fid:entry > /self->stat64/ > { > self->fid = timestamp; > } > > zfs_fid:return > /self->fid/ > { > @avg[probefunc] = avg(timestamp - self->fid); > @sum[probefunc] = sum(timestamp - self->fid); > self->fid = 0; > } > > zfs_seek:entry > /self->stat64/ > { > self->seek = timestamp; > } > > zfs_seek:return > /self->seek/ > { > @avg[probefunc] = avg(timestamp - self->seek); > @sum[probefunc] = sum(timestamp - self->seek); > self->seek = 0; > } > > zfs_frlock:entry > /self->stat64/ > { > self->frlock = timestamp; > } > > zfs_frlock:return > /self->frlock/ > { > @avg[probefunc] = avg(timestamp - self->frlock); > @sum[probefunc] = sum(timestamp - self->frlock); > self->frlock = 0; > } > > zfs_space:entry > /self->stat64/ > { > self->space = timestamp; > } > > zfs_space:return > /self->space/ > { > @avg[probefunc] = avg(timestamp - self->space); > @sum[probefunc] = sum(timestamp - self->space); > self->space = 0; > } > > zfs_getpage:entry > /self->stat64/ > { > self->getpage = timestamp; > } > > zfs_getpage:return > /self->getpage/ > { > @avg[probefunc] = avg(timestamp - self->getpage); > @sum[probefunc] = sum(timestamp - self->getpage); > self->getpage = 0; > } > > zfs_putpage:entry > /self->stat64/ > { > self->putpage = timestamp; > } > > zfs_putpage:return > /self->putpage/ > { > @avg[probefunc] = avg(timestamp - self->putpage); > @sum[probefunc] = sum(timestamp - self->putpage); > self->putpage = 0; > } > > zfs_map:entry > /self->stat64/ > { > self->map = timestamp; > } > > zfs_map:return > /self->map/ > { > @avg[probefunc] = avg(timestamp - self->map); > @sum[probefunc] = sum(timestamp - self->map); > self->map = 0; > } > > zfs_addmap:entry > /self->stat64/ > { > self->addmap = timestamp; > } > > zfs_addmap:return > /self->addmap/ > { > @avg[probefunc] = avg(timestamp - self->addmap); > @sum[probefunc] = sum(timestamp - self->addmap); > self->addmap = 0; > } > > zfs_delmap:entry > /self->stat64/ > { > self->delmap = timestamp; > } > > zfs_delmap:return > /self->delmap/ > { > @avg[probefunc] = avg(timestamp - self->delmap); > @sum[probefunc] = sum(timestamp - self->delmap); > self->delmap = 0; > } > > zfs_pathconf:entry > /self->stat64/ > { > self->pathconf = timestamp; > } > > zfs_pathconf:return > /self->pathconf/ > { > @avg[probefunc] = avg(timestamp - self->pathconf); > @sum[probefunc] = sum(timestamp - self->pathconf); > self->pathconf = 0; > } > > zfs_getsecattr:entry > /self->stat64/ > { > self->getsecattr = timestamp; > } > > zfs_getsecattr:return > /self->getsecattr/ > { > @avg[probefunc] = avg(timestamp - self->getsecattr); > @sum[probefunc] = sum(timestamp - self->getsecattr); > self->getsecattr = 0; > } > > zfs_setsecattr:entry > /self->stat64/ > { > self->setsecattr = timestamp; > } > > zfs_setsecattr:return > /self->setsecattr/ > { > @avg[probefunc] = avg(timestamp - self->setsecattr); > @sum[probefunc] = sum(timestamp - self->setsecattr); > self->setsecattr = 0; > } > > fs_vnevent_support:entry > /self->stat64/ > { > self->fs_vnevent_support = timestamp; > } > > fs_vnevent_support:return > /self->fs_vnevent_support/ > { > @avg[probefunc] = avg(timestamp - self->fs_vnevent_support); > @sum[probefunc] = sum(timestamp - self->fs_vnevent_support); > self->fs_vnevent_support = 0; > } > > > /* DIRECTORY VNOPS */ > zfs_isdir:entry > /self->stat64/ > { > self->isdir = timestamp; > } > > zfs_isdir:return > /self->isdir/ > { > @avg[probefunc] = avg(timestamp - self->isdir); > @sum[probefunc] = sum(timestamp - self->isdir); > self->isdir = 0; > } > > zfs_create:entry > /self->stat64/ > { > self->create = timestamp; > } > > zfs_create:return > /self->create/ > { > @avg[probefunc] = avg(timestamp - self->create); > @sum[probefunc] = sum(timestamp - self->create); > self->create = 0; > } > > zfs_remove:entry > /self->stat64/ > { > self->remove = timestamp; > } > > zfs_remove:return > /self->remove/ > { > @avg[probefunc] = avg(timestamp - self->remove); > @sum[probefunc] = sum(timestamp - self->remove); > self->remove = 0; > } > > zfs_mkdir:entry > /self->stat64/ > { > self->mkdir = timestamp; > } > > zfs_mkdir:return > /self->mkdir/ > { > @avg[probefunc] = avg(timestamp - self->mkdir); > @sum[probefunc] = sum(timestamp - self->mkdir); > self->mkdir = 0; > } > > zfs_rmdir:entry > /self->stat64/ > { > self->rmdir = timestamp; > } > > zfs_rmdir:return > /self->rmdir/ > { > @avg[probefunc] = avg(timestamp - self->rmdir); > @sum[probefunc] = sum(timestamp - self->rmdir); > self->rmdir = 0; > } > > zfs_readdir:entry > /self->stat64/ > { > self->readdir = timestamp; > } > > zfs_readdir:return > /self->readdir/ > { > @avg[probefunc] = avg(timestamp - self->readdir); > @sum[probefunc] = sum(timestamp - self->readdir); > self->readdir = 0; > } > > zfs_symlink:entry > /self->stat64/ > { > self->symlink = timestamp; > } > > zfs_symlink:return > /self->symlink/ > { > @avg[probefunc] = avg(timestamp - self->symlink); > @sum[probefunc] = sum(timestamp - self->symlink); > self->symlink = 0; > } > > > /* SYMLINK VNOPS */ > > /* EXT ATTR DIRECOTRY VNOPS */ > > END > { > printf("\nAVG TIME\n"); > printa(@avg); > printf("\n\n\nSUM TIME\n"); > printa(@sum); > } >> _______________________________________________ > dtrace-discuss mailing list > dtrace-discuss at opensolaris.org-- Adam Leventhal, Solaris Kernel Development http://blogs.sun.com/ahl
eric kustarz
2005-Dec-14 08:53 UTC
[dtrace-discuss] illegal operation in action #6 : can different providers use the same aggregation name?
Adam Leventhal wrote:>Hi Eric, > >Sorry for not replying sooner. That definitely sounds like a bug, but I''m >unable to reproduce the problem on the latest bits. It would be useful if >you could send the output of dtrace -S -s <script.d> which shows the DIF >bytecodes used to encode your program. > >Hmm, perhaps i picked the wrong day to BFU... i was on daily.1128-nd bits when i saw the problem and have since moved up. I notice that 11/28 bits are now no longer available from onnv - looks like they were bogus. And yeah, i can''t reproduce it on 11/27, 11/29, nor today''s bits. so nevermind, eric>Adam > >On Fri, Dec 02, 2005 at 04:22:18PM -0800, eric kustarz wrote: > > >>so i was running the attatched script, and got many of these errors: >> >>dtrace: error on enabled probe ID 14 (ID 33702: >>fbt:zfs:zfs_getattr:return): illegal operation in action #6 >>dtrace: error on enabled probe ID 26 (ID 34790: >>fbt:zfs:zfs_inactive:return): illegal operation in action #6 >>dtrace: error on enabled probe ID 20 (ID 33708: >>fbt:zfs:zfs_lookup:return): illegal operation in action #6 >> >> >>I broke the script once i added these first two clauses for the syscall >>provider: >> >>syscall::stat64:entry >>{ >> self->stat64 = timestamp; >>} >> >>syscall::stat64:return >>/self->stat64/ >>{ >> @sum[probefunc] = sum(timestamp - self->stat64); >> self->stat64 = 0; >>} >> >>Without those two clauses, it runs ok... If i change the >>''syscall::stat64:return'' clause to use a different aggregation name (say >>''syscall_sum'' instead of ''sum'' - where ''sum'' is the aggregation name >>used by the rest of the script), then it works a-ok. >> >>So i''m guessing the error comes from dtrace_aggregate(): >>if (action != key->dtak_action) { >> /* >> * We are aggregating on the same value in the same >> * aggregation with two different aggregating >>actions. >> * (This should have been picked up in the compiler, >> * so we may be dealing with errant or devious DIF.) >> * This is an error condition; we indicate as much, >> * and return. >> */ >> DTRACE_CPUFLAG_SET(CPU_DTRACE_ILLOP); >> return; >> } >> >>So is it illegal for different providers to use the same aggregation name? >> >>I can also get the script to successfully run if i remove all the count >>aggregates, so i''m guessing its partially a timing thing... >> >>I was doing the simple tar test of /usr/dict/words while the script was >>running to induce failure: >>#/bin/time /usr/sbin/tar cvf bench.tar .. > /dev/null >> >>This was running: >>fsh-suzuki# uname -a >>SunOS fsh-suzuki 5.11 onnv-gate:2005-11-28 sun4u sparc SUNW,Sun-Fire-V210 >>fsh-suzuki# >> >>eric >> >>