[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: autoconf hangs due to autom4te.cache and NFS problem on AIX
|
From: |
Chris Pickett |
|
Subject: |
Re: autoconf hangs due to autom4te.cache and NFS problem on AIX |
|
Date: |
Sun, 24 Feb 2008 13:06:27 -0500 |
|
User-agent: |
Thunderbird 1.5.0.14 (Macintosh/20071210) |
Trying to tie everything in to one response here... if there's something
I missed, just let me know.
Bob Proulx wrote:
> Chris Pickett wrote:
>> ~/test $ fuser autom4te.cache/.nfsE1831
>> autom4te.cache/.nfsE1831:
>> ~/test $ fuser autom4te.cache/
>> autom4te.cache/:
>> ~/test $ fuser -d -u -V autom4te.cache/.nfsE1831
>> autom4te.cache/.nfsE1831:
>
> I have seen that too. I don't know why one behavior indicates an open
> file with an active process and another one refuses to show anything
> for it showing that there aren't any.
As noted in a followup message, fuser -c says stuff that fuser -d
doesn't, even though man fuser says fuser -d "implies" -c. But it's
still not that interesting what I get from it.
If you can deduce what process is hanging that would be useful
information. ps *should* show you what processes are running and one
of those would be the culprit.
Okay, so there are two cases.
First, automake-10.1 configure hangs checking whether autoconf works:
pickett 782550 0.0 0.0 712 328 pts/2 A 11:11:24 0:00 /bin/sh
./configure --prefix=$HOME/$MACHTYPE
pickett 1060900 0.0 0.0 864 480 pts/2 A 11:11:28 0:00 /bin/sh
./configure --prefix=$HOME/$MACHTYPE
pickett 1388674 0.0 0.0 5012 5216 pts/2 A 11:11:28 0:00
/bin/perl -w $HOME/$MACHTYPE/bin/autom4te --language=autoconf
--output=/dev/null conftest.ac
Second, autoreconf (--install) hangs for my own project:
pickett 745694 0.0 0.0 4452 4656 pts/2 A 11:25:14 0:00
/bin/perl -w $HOME/$MACHTYPE/bin/autoreconf --install
pickett 684244 0.7 0.0 6628 6832 pts/2 A 11:25:17 0:01
/bin/perl -w $HOME/$MACHTYPE/bin/aclocal -I m4
pickett 1364160 0.0 0.0 5040 5244 pts/2 A 11:25:22 0:00
/bin/perl -w $HOME/$MACHTYPE/bin/autom4te --language
Autoconf-without-aclocal-m4
$HOME/$MACHTYPE/share/aclocal/libtool.m4
$HOME/$MACHTYPE/share/aclocal/pkg.m4
$HOME/$MACHTYPE/share/aclocal-1.10/amversion.m4
$HOME/$MACHTYPE/share/aclocal-1.10/auxdir.m4
$HOME/$MACHTYPE/share/aclocal-1.10/cond.m4
$HOME/$MACHTYPE/share/aclocal-1.10/depend.m4
$HOME/$MACHTYPE/share/aclocal-1.10/depout.m4
$HOME/$MACHTYPE/share/aclocal-1.10/init.m4
$HOME/$MACHTYPE/share/aclocal-1.10/install-sh.m4
$HOME/$MACHTYPE/share/aclocal-1.10/lead-dot.m4
$HOME/$MACHTYPE/share/aclocal-1.10/make.m4
$HOME/$MACHTYPE/share/aclocal-1.10/missing.m4
$HOME/$MACHTYPE/share/aclocal-1.10/mkdirp.m4
$HOME/$MACHTYPE/share/aclocal-1.10/options.m4
$HOME/$MACHTYPE/share/aclocal-1.10/runlog.m4
$HOME/$MACHTYPE/share/aclocal-1.10/sanity.m4
$HOME/$MACHTYPE/share/aclocal-1.10/strip.m4
$HOME/$MACHTYPE/share/aclocal-1.10/substnot.m4
$HOME/$MACHTYPE/share/aclocal-1.10/tar.m4 m4/acx_pthread.m4
m4/ax_check_compiler_flags.m4 m4/ax_gcc_archflag.m4
m4/ax_gcc_x86_cpuid.m4 --trace=AC_DEFUN:$f::$n::$1
--trace=AC_DEFUN_ONCE:$f::$n::$1 --trace=AU_DEFUN:$f::$n::$1
--trace=_AM_AUTOCONF_VERSION:$f::$n::$1 --trace=_LT_AC_TAGCONFIG:$f::$n
--trace=AM_ENABLE_STATIC:$f::$n --trace=AC_LIBTOOL_LANG_RC_CONFIG:$f::$n
--trace=AC_LIBTOOL_COMPILER_OPTION:$f::$n
--trace=_LT_AC_SHELL_INIT:$f::$n --trace=AC_DISABLE_SHARED:$f::$n
--trace=_LT_COMPILER_BOILERPLATE:$f::$n
--trace=_LT_AC_LANG_CXX_CONFIG:$f::$n --trac
(and then ps cuts off but I'm pretty sure you can figure out the rest.)
So, combined with the NFS weirdness over the autom4te.cache directory
and the fact that autom4te is stuck each time I think that's where the
problem is. Unless the problem is perl: I have Perl 5.8.0 for AIX,
dating back to 2002. I could install the latest 5.8 series release
(5.8.8.something), but it looked a little tricky and I don't know if it
goes in my home directory easily.
On the other hand, when I try to run autoreconf --install on my actual
project, it hangs running aclocal and autom4te, although aclocal does
respond to SIGINT.
You might also try a job control sigstop with ^Z. I have experienced
times when jobs could not be interrupted but could be stopped. (shrug)
Indeed, the first one responds to Ctrl-z and kill -9 but not Ctrl-c.
I'm not sure it really matters. Note that after Ctrl-z and then fg, the
autom4te process is gone.
Note that I've had autoconf working on this system for about a year,
this only started happening recently... something changed, somewhere.
If you tell me how to turn on verbose logging I can find the exact part
where it's hung.
If ./configure hangs then trace through it with 'sh -x ./configure'
and also look in the config.log file.
config.log has this at the end:
configure:2327: checking whether autoconf is installed
configure:2332: eval autoconf --version
autoconf (GNU Autoconf) 2.61
Copyright (C) 2006 Free Software Foundation, Inc.
This is free software. You may redistribute copies of it under the terms of
the GNU General Public License <http://www.gnu.org/licenses/gpl.html>.
There is NO WARRANTY, to the extent permitted by law.
Written by David J. MacKenzie and Akim Demaille.
configure:2335: $? = 0
configure:2343: result: yes
configure:2353: checking whether autoconf works
configure:2360: cd conftest && eval autoconf -o /dev/null conftest.ac
sh -x ./configure doesn't produce any extra info. Neither does
/usr/local/bin/bash -x ./configure, except for one "set +x" line, and
neither does changing the shell inside configure or adding set +x inside
configure. I read somewhere that /bin/sh is ksh on AIX, I don't know if
this has anything to do with it.
Unfortunately if autoreconf hangs I don't know how to suggest an easy
way to track down what happens there. I would start by running
'autoreconf --verbose'.
autoreconf --verbose
$ autoreconf --verbose
autoreconf: Entering directory `.'
autoreconf: configure.ac: not using Gettext
autoreconf: running: aclocal -I m4
Then depending upon the results there I would reach in deeper and turn
on perl debugging. Try this and see if this helps.
PERLDB_OPTS="NonStop=1 AutoTrace=1 frame=2" perl -dS autoreconf --verbose
That will produce a *lot* of output. Hopefully the output near the
hang will be useful information. It would be useful to see the last
part of that output if it shows something useful about what is
hanging.
Note that I haven't actually tried that on autoreconf before but it is
one way how I debug other perl programs.
It hangs like this:
411: if (!$uses_aclocal)
412: {
425: sleep 1;
427: run_aclocal ($aclocal, $aclocal_flags);
entering main::run_aclocal
253: my ($aclocal, $flags) = @_;
257: if ($aclocal_supports_force)
258: {
259: xsystem ("$aclocal $flags");
entering Autom4te::FileUtils::xsystem
285: my (@command) = @_;
287: verb "running: @command";
entering Autom4te::ChannelDefs::verb
235: my ($msg, %opts) = @_;
236: msg 'verb', '', $msg, %opts;
entering Autom4te::Channels::msg
538: my ($channel, $location, $message, %options) = @_;
540: if (! defined $message)
541: {
546: confess "unknown channel $channel" unless exists
$channels{$channel};
548: my %opts = %{$channels{$channel}};
548: my %opts = %{$channels{$channel}};
549: _merge_options (%opts, %options);
entering Autom4te::Channels::_merge_options
314: my ($hash, %options) = @_;
315: local $_;
317: foreach (keys %options)
318: {
exited Autom4te::Channels::_merge_options
551: if (exists $buffering{$opts{'type'}})
552: {
558: if (_print_message ($location, $message, %opts))
559: {
entering Autom4te::Channels::_print_message
417: my ($location, $message, %opts) = @_;
419: return 0 if ($opts{'silent'});
421: my $msg = _format_message ($location, $message, %opts);
entering Autom4te::Channels::_format_message
385: my ($location, $message, %opts) = @_;
386: my $msg = '';
387: if (ref $location)
388: {
401: $location ||= $me;
402: $msg = _format_sub_message ("$location: ",
$opts{'header'}
403: . $message .
$opts{'footer'});
entering Autom4te::Channels::_format_sub_message
376: my ($leader, $message) = @_;
377: return $leader . join ("\n" . $leader, split ("\n",
$message)) . "\n";
exited Autom4te::Channels::_format_sub_message
405: return $msg;
exited Autom4te::Channels::_format_message
422: if ($opts{'partial'})
423: {
431: $msg = $partial . $msg;
432: $partial = '';
436: if ($opts{'uniq_part'} ne UP_NONE)
437: {
439: my $to_filter;
440: if ($opts{'uniq_part'} eq UP_TEXT)
441: {
446: $to_filter = $msg;
454: my $dups;
455: if ($opts{'uniq_scope'} == US_LOCAL)
456: {
457: $dups = \%_local_duplicate_messages;
469: if (exists $dups->{$to_filter})
470: {
476: $dups->{$to_filter} = 0;
479: my $file = $opts{'file'};
480: print $file $msg;
autoreconf: running: aclocal -I m4
481: return 1;
exited Autom4te::Channels::_print_message
561: if ($opts{'type'} eq 'error'
562: || $opts{'type'} eq 'fatal'
563: || ($opts{'type'} eq 'warning' &&
$warnings_are_errors))
564: {
570: confess if $opts{'backtrace'};
571: exit $exit_code if $opts{'type'} eq 'fatal';
exited Autom4te::Channels::msg
exited Autom4te::ChannelDefs::verb
289: $! = 0;
290: handle_exec_errors "@command"
291: if system @command;
If you want me to go back further I can. On the other hand, the first
case (automake-1.10) hangs like this when from inside conftest/ I run:
PERLDB_OPTS="NonStop=1 AutoTrace=1 frame=2" /bin/perl -dS -w
$HOME/$MACHTYPE/bin/autom4te --language=autoconf --output=/dev/null
conftest.ac
exited main::parse_args
949: if ($freeze)
950: {
956: if (! -d "$cache")
957: {
958: mkdir "$cache", 0755
959: or fatal "cannot create $cache: $!";
965: $icache_file = new Autom4te::XFile $icache, O_RDWR|O_CREAT;
entering Fcntl::AUTOLOAD for Fcntl::O_RDWR
203: (my $constname = $AUTOLOAD) =~ s/.*:://;
204: die "&Fcntl::constant not defined" if $constname eq 'constant';
205: my ($error, $val) = constant($constname);
entering Fcntl::constant
exited Fcntl::constant
206: if ($error) {
210: *$AUTOLOAD = sub { $val };
211: goto &$AUTOLOAD;
210: *$AUTOLOAD = sub { $val };
exited Fcntl::AUTOLOAD for Fcntl::O_RDWR
entering Fcntl::AUTOLOAD for Fcntl::O_CREAT
203: (my $constname = $AUTOLOAD) =~ s/.*:://;
204: die "&Fcntl::constant not defined" if $constname eq 'constant';
205: my ($error, $val) = constant($constname);
entering Fcntl::constant
exited Fcntl::constant
206: if ($error) {
210: *$AUTOLOAD = sub { $val };
211: goto &$AUTOLOAD;
210: *$AUTOLOAD = sub { $val };
exited Fcntl::AUTOLOAD for Fcntl::O_CREAT
entering Autom4te::XFile::new
123: my $type = shift;
124: my $class = ref $type || $type || "Autom4te::XFile";
125: my $fh = $class->SUPER::new ();
entering IO::File::new
136: my $type = shift;
137: my $class = ref($type) || $type || "IO::File";
138: @_ >= 0 && @_ <= 3
139: or croak "usage: new $class [FILENAME [,MODE [,PERMS]]]";
140: my $fh = $class->SUPER::new();
entering IO::Handle::new
300: my $class = ref($_[0]) || $_[0] || "IO::Handle";
301: @_ == 1 or croak "usage: new $class";
302: my $io = gensym;
entering Symbol::gensym
93: my $name = "GEN" . $genseq++;
94: my $ref = \*{$genpkg . $name};
94: my $ref = \*{$genpkg . $name};
95: delete $$genpkg{$name};
96: $ref;
exited Symbol::gensym
303: bless $io, $class;
exited IO::Handle::new
141: if (@_) {
145: $fh;
exited IO::File::new
126: if (@_)
127: {
128: $fh->open (@_);
entering Autom4te::XFile::open
139: my $fh = shift;
140: my ($file) = @_;
146: ${*$fh}{'autom4te_xfile_file'} = "$file";
146: ${*$fh}{'autom4te_xfile_file'} = "$file";
148: if (!$fh->SUPER::open (@_))
149: {
entering IO::File::open
153: @_ >= 2 && @_ <= 4 or croak 'usage: $fh->open(FILENAME
[,MODE [,PERMS]])';
154: my ($fh, $file) = @_;
155: if (@_ > 2) {
156: my ($mode, $perms) = @_[2, 3];
157: if ($mode =~ /^\d+$/) {
158: defined $perms or $perms = 0666;
159: return sysopen($fh, $file, $mode, $perms);
exited IO::File::open
157: binmode $fh if $file =~ /^\s*>/;
exited Autom4te::XFile::open
130: $fh;
exited Autom4te::XFile::new
966: $icache_file->lock (LOCK_EX);
entering Fcntl::AUTOLOAD for Fcntl::LOCK_EX
203: (my $constname = $AUTOLOAD) =~ s/.*:://;
204: die "&Fcntl::constant not defined" if $constname eq 'constant';
205: my ($error, $val) = constant($constname);
entering Fcntl::constant
exited Fcntl::constant
206: if ($error) {
210: *$AUTOLOAD = sub { $val };
211: goto &$AUTOLOAD;
210: *$AUTOLOAD = sub { $val };
exited Fcntl::AUTOLOAD for Fcntl::LOCK_EX
entering Autom4te::XFile::lock
219: my ($fh, $mode) = @_;
232: if (!flock ($fh, $mode))
233: {
which looks a little more promising.
-rw-r--r-- 1 pickett xxx 0 Feb 23 00:27 .nfsCC131
Ralf suggests:
I suppose you can rename the directory (and delete it as soon as you've
reset the NFS connection).
It doesn't work. I have a ~/deleteme directory where I dump stale NFS
things and periodically attempt to rm -rf, but it can take days for
things to get released.
Well, That is basically what Ralf suggested. Moving the file to
another place such as your deleteme frees up the auto4te.cache. So
actually the workaround does work. In this context "reseting the nfs
connection" I read as "rebooting the system".
All I meant was "it doesn't work" is that it doesn't make it so I can
run autom4te without setting .autom4te.cfg as described.
Ralf Wildenhues wrote:
> * Bob Proulx wrote on Sat, Feb 23, 2008 at 07:42:54PM CET:
>> Chris Pickett wrote:
>>> ~/test $ lsof
>>> -bash: lsof: command not found
>> Well, I did say "or equivalents".
>
> While it doesn't have an exact answer here, the Rosetta Stone for Unix
> <http://rudiment.dk/~incore/UnixFlavours.html>
> is always helpful if one forgets such things. trace should, if perl
> tracing does not help, enable you to find out which syscall is hanging.
I looked into trace. It does system wide profiling. If you want a
specific process traced, I think you have to figure out what it is
independently. I tried to do this with ps while things were hung, but
trace couldn't always capture any or all of the PIDs properly. One time
I was able to find the PID of the autoreconf process I observed with ps,
but not the aclocal or autom4te child processes (and I didn't get
anything when I tried running those alone). Anyway, the end of the log
looked like this after filtering, with several columns removed.
chmod chmod LR = 100A76B4
chmod lookuppn: /tmp/ar2365.667664/am4t7389.1212438
chmod vnop_hold(vp = F10000E3089A2D50, getcaller = 633EEC)
= 0000
chmod name cache good hit: vfsp = F10000E345C54470, dp =
F10000E3089A2DA8, np = F10000E30DC69AF8, nid = 01D9, hash = F10000E3454F00A0
chmod vnop_lookup(dvp = F10000E3089A2D50, flag = 0006) =
0000, *vpp = F10000E30DC69AA0
chmod vfs_root(vfsp = F10000E345C54410) = 0000, *vpp =
F10000E312F2FAA0
chmod vnop_rele(vp = F10000E30DC69AA0, getcaller = 6342E8)
chmod vnop_rele(vp = F10000E3089A2D50, getcaller = 634094)
chmod name cache good hit: vfsp = F10000E345C54410, dp =
F10000E312F2FAF8, np = F10000E30ECCACD0, nid = 2CA60D, hash =
F10000E345568C40
chmod vnop_lookup(dvp = F10000E312F2FAA0, flag = 0006) =
0000, *vpp = F10000E30ECCAC78
chmod vnop_rele(vp = F10000E312F2FAA0, getcaller = 634094)
chmod name cache good hit: vfsp = F10000E345C54410, dp =
F10000E30ECCACD0, np = F10000E30CBA1A08, nid = 2CA60E, hash =
F10000E345768050
chmod vnop_lookup(dvp = F10000E30ECCAC78, flag = 0006) =
0000, *vpp = F10000E30CBA19B0
chmod vnop_rele(vp = F10000E30ECCAC78, getcaller = 6344F8)
chmod lookuppn exit: '/tmp/ar2365.667664/am4t7389.1212438'
= vnode F10000E30CBA19B0
chmod vnop_setattr unknown subhook: subhook=00F1 D1=0000
D2=F10000E30CBA19B0 D3=01FF D4=0000 D5=0000
chmod vnop_rele(vp = F10000E30CBA19B0, getcaller = 730E98)
chmod return from chmod [31 usec]
statx statx LR = D01F6714
statx lookuppn: /tmp/ar2365.667664/am4t7389.1212438
statx vnop_hold(vp = F10000E3089A2D50, getcaller = 633EEC)
= 0000
statx name cache good hit: vfsp = F10000E345C54470, dp =
F10000E3089A2DA8, np = F10000E30DC69AF8, nid = 01D9, hash = F10000E3454F00A0
statx vnop_lookup(dvp = F10000E3089A2D50, flag = 0002) =
0000, *vpp = F10000E30DC69AA0
statx vfs_root(vfsp = F10000E345C54410) = 0000, *vpp =
F10000E312F2FAA0
statx vnop_rele(vp = F10000E30DC69AA0, getcaller = 6342E8)
statx vnop_rele(vp = F10000E3089A2D50, getcaller = 634094)
statx name cache good hit: vfsp = F10000E345C54410, dp =
F10000E312F2FAF8, np = F10000E30ECCACD0, nid = 2CA60D, hash =
F10000E345568C40
statx vnop_lookup(dvp = F10000E312F2FAA0, flag = 0002) =
0000, *vpp = F10000E30ECCAC78
statx vnop_rele(vp = F10000E312F2FAA0, getcaller = 634094)
statx name cache good hit: vfsp = F10000E345C54410, dp =
F10000E30ECCACD0, np = F10000E30CBA1A08, nid = 2CA60E, hash =
F10000E345768050
statx vnop_lookup(dvp = F10000E30ECCAC78, flag = 0002) =
0000, *vpp = F10000E30CBA19B0
statx vnop_rele(vp = F10000E30ECCAC78, getcaller = 6344F8)
statx lookuppn exit: '/tmp/ar2365.667664/am4t7389.1212438'
= vnode F10000E30CBA19B0
statx vnop_getattr(vp = F10000E30CBA19B0) = 0000
statx vnop_rele(vp = F10000E30CBA19B0, getcaller = 67BA0C)
statx return from statx [23 usec]
open open LR = D02BF048
open lookuppn: /tmp/ar2365.667664/am4t7389.1212438
open vnop_hold(vp = F10000E3089A2D50, getcaller = 633EEC)
= 0000
open name cache good hit: vfsp = F10000E345C54470, dp =
F10000E3089A2DA8, np = F10000E30DC69AF8, nid = 01D9, hash = F10000E3454F00A0
open vnop_lookup(dvp = F10000E3089A2D50, flag = 000A) =
0000, *vpp = F10000E30DC69AA0
open vfs_root(vfsp = F10000E345C54410) = 0000, *vpp =
F10000E312F2FAA0
open vnop_rele(vp = F10000E30DC69AA0, getcaller = 6342E8)
open vnop_rele(vp = F10000E3089A2D50, getcaller = 634094)
open name cache good hit: vfsp = F10000E345C54410, dp =
F10000E312F2FAF8, np = F10000E30ECCACD0, nid = 2CA60D, hash =
F10000E345568C40
open vnop_lookup(dvp = F10000E312F2FAA0, flag = 000A) =
0000, *vpp = F10000E30ECCAC78
open vnop_rele(vp = F10000E312F2FAA0, getcaller = 634094)
open name cache good hit: vfsp = F10000E345C54410, dp =
F10000E30ECCACD0, np = F10000E30CBA1A08, nid = 2CA60E, hash =
F10000E345768050
open vnop_lookup(dvp = F10000E30ECCAC78, flag = 000A) =
0000, *vpp = F10000E30CBA19B0
open lookuppn exit: '/tmp/ar2365.667664/am4t7389.1212438'
= vnode F10000E30CBA19B0
open vnop_rele(vp = F10000E30ECCAC78, getcaller = 67DBD4)
open vfs number=0005, inode number=2052
open vnop_open(vp = F10000E30CBA19B0, flags = 0001, ext =
0000) = 0000
open open fd=3
open return from open [19 usec]
DATA ACCESS PAGE FAULT iar=D01FFB1C cpuid=06
VMM pagefault: V.S=0311.3914F4
VMM page assign: V.S=0311.3914F4 ppage=5A8752
VMM zero filled page: V.S=0311.3914F4 ppage=5A8752
resume -667664- iar=D01FFB1C cpuid=06
getdirent getdirent LR = D02BF374
getdirent xmalloc fastpath: size=1000 align=0002
heap=F10000E3000000D8
getdirent xmalloc return: result=F10000E355183000 size=1000
getdirent PFS readi VA.S=0000 0000.31C4E6 bcount=0200
ip=F10000E30CBA1A08 /tmp/ar2365.667664/am4t7389.1212438
getdirent vnop_readdir(vp = F10000E30CBA19B0, offset = 0000,
length = 1000) = 0000, offset = 0200
getdirent xmalloc fastpath: size=0030 align=0002
heap=F10000E3000000D8
getdirent xmalloc back end: size=0040 align=0002
heap=F10000E3000000D8
getdirent xmalloc return: result=F10000E3550EFC00 size=0040
getdirent xmfree fastpath: address=F10000E3550EFC00
heap=F10000E3000000D8
getdirent xmfree fastpath: address=F10000E355183000
heap=F10000E3000000D8
getdirent return from getdirent [15 usec]
lseek lseek LR = D02BFC14
lseek lseek fd=3 to 0000 0000
lseek vnop_seek(vp = F10000E30CBA19B0, offset =
0000000000000000) = 0000
lseek lseek fd=3 to 0000 0000 errno=0000
lseek return from lseek [2 usec]
kfcntl kfcntl LR = D01F8FEC
kfcntl fcntl F_GETFD return value 0000
kfcntl return from kfcntl [1 usec]
kfcntl kfcntl LR = D01F8FEC
kfcntl fcntl F_SETFD return value 0000
kfcntl return from kfcntl [1 usec]
getdirent getdirent LR = D02BF374
getdirent xmalloc fastpath: size=1000 align=0002
heap=F10000E3000000D8
getdirent xmalloc return: result=F10000E355183000 size=1000
getdirent PFS readi VA.S=0000 0000.31C4E6 bcount=0200
ip=F10000E30CBA1A08 /tmp/ar2365.667664/am4t7389.1212438
getdirent vnop_readdir(vp = F10000E30CBA19B0, offset = 0000,
length = 1000) = 0000, offset = 0200
getdirent xmalloc fastpath: size=0030 align=0002
heap=F10000E3000000D8
getdirent xmalloc return: result=F10000E3550EFC00 size=0030
getdirent xmfree fastpath: address=F10000E3550EFC00
heap=F10000E3000000D8
getdirent xmfree fastpath: address=F10000E355183000
heap=F10000E3000000D8
getdirent return from getdirent [7 usec]
getdirent getdirent LR = D02BF374
getdirent xmalloc fastpath: size=1000 align=0002
heap=F10000E3000000D8
getdirent xmalloc return: result=F10000E355183000 size=1000
getdirent vnop_readdir(vp = F10000E30CBA19B0, offset = 0200,
length = 1000) = 0000, offset = 0200
getdirent xmfree fastpath: address=F10000E355183000
heap=F10000E3000000D8
getdirent return from getdirent [3 usec]
close close LR = D02BF934
close close fd=3
close vnop_close(vp = F10000E30CBA19B0, flags = 0001) = 0000
close vnop_rele(vp = F10000E30CBA19B0, getcaller = 67E664)
close return from close [5 usec]
DATA ACCESS PAGE FAULT iar=1008F644 cpuid=06
VMM pagefault: V.S=025B.3914F4
VMM reclaim: V.S=025B.3914F4 ppage=692269
resume -667664- iar=1008F644 cpuid=06
rmdir rmdir LR = 10094568
rmdir lookuppn: /tmp/ar2365.667664/am4t7389.1212438
rmdir vnop_hold(vp = F10000E3089A2D50, getcaller = 633EEC)
= 0000
rmdir name cache good hit: vfsp = F10000E345C54470, dp =
F10000E3089A2DA8, np = F10000E30DC69AF8, nid = 01D9, hash = F10000E3454F00A0
rmdir vnop_lookup(dvp = F10000E3089A2D50, flag = 0086) =
0000, *vpp = F10000E30DC69AA0
rmdir vfs_root(vfsp = F10000E345C54410) = 0000, *vpp =
F10000E312F2FAA0
rmdir vnop_rele(vp = F10000E30DC69AA0, getcaller = 6342E8)
rmdir vnop_rele(vp = F10000E3089A2D50, getcaller = 634094)
rmdir name cache good hit: vfsp = F10000E345C54410, dp =
F10000E312F2FAF8, np = F10000E30ECCACD0, nid = 2CA60D, hash =
F10000E345568C40
rmdir vnop_lookup(dvp = F10000E312F2FAA0, flag = 0086) =
0000, *vpp = F10000E30ECCAC78
rmdir vnop_rele(vp = F10000E312F2FAA0, getcaller = 634094)
rmdir name cache good hit: vfsp = F10000E345C54410, dp =
F10000E30ECCACD0, np = F10000E30CBA1A08, nid = 2CA60E, hash =
F10000E345768050
rmdir vnop_lookup(dvp = F10000E30ECCAC78, flag = 0086) =
0000, *vpp = F10000E30CBA19B0
rmdir lookuppn exit: '/tmp/ar2365.667664/am4t7389.1212438'
= vnode F10000E30CBA19B0
rmdir vnode cache remove: vp = 0000, dev =
8000000A00000007, ino = 2052, gen = AD1D679F, hash = F10000E354B744E8
rmdir xmalloc fastpath: size=0088 align=0000
heap=F10000E3000000D8
rmdir xmalloc back end: size=0100 align=0000
heap=F10000E3000000D8
rmdir xmalloc return: result=F10000E3589AF000 size=0100
rmdir xmalloc fastpath: size=0088 align=0000
heap=F10000E3000000D8
rmdir xmalloc back end: size=0100 align=0000
heap=F10000E3000000D8
rmdir xmalloc return: result=F10000E3589AFB00 size=0100
rmdir xmfree fastpath: address=F10000E3589AFB00
heap=F10000E3000000D8
rmdir VMM start io: V.S=6AF7.81110 ppage=331272
rmdir LVM mode=00C9
rmdir LVM lstart: rhd8 lbp=F10000E346222000 lblock=357C0
bcount=1000 B_WRITE opts:
rmdir LVM mode=00C6
rmdir LVM mode=00C6
rmdir LVM mode=00C6
rmdir LVM pstart: ipldevice pblock=36F68C0
(lbp,pbp)=(F10000E346222000,F100009380044100) B_WRITE opts:
rmdir LVM mode=00C6
rmdir LVM mode=00C6
rmdir LVM mode=00C6
rmdir LVM pstart: rhdisk2 pblock=36F68C0
(lbp,pbp)=(F10000E346222000,F100009380049980) B_WRITE opts:
rmdir LVM mode=00C8
rmdir SCDISKDD strategy: bp=F100009380049980 b_flags=C8010
b_blkno=36F68C0 b_bcount=1000
rmdir LVM mode=00C8
rmdir SCDISKDD strategy: bp=F100009380044100 b_flags=C8010
b_blkno=36F68C0 b_bcount=1000
rmdir VMM WAIT: Link Register=D3840
I don't think I had an autom4te.cache directory from a previous try
there, but if I did, that might explain the rmdir.
I was running trace like this:
trace -a -o /tmp/trace.log; autoreconf; trcstop
and trcrpt, which formats the log file, like this:
trcrpt -O svc=on,cpuid=on,exec=on,pid=on /tmp/trace.log | grep -E
"$PID1|$PID2|$PID3"
Anyway, trace seems less easy to use than strace, but it probably could
provide more data than this if I knew how to manipulate it better.
Chris