Let the Sunshine In: Software support engineer in Tokyo

I ran into this problem while running this "Stand-alone Eclipse RCP".

SAP Community Network Forums: Unable to open hprof file on Debian ...

on Solaris (and presumably Linux), this is because of an Eclipse bug -- the org.eclipse.core.internal.filesystem.local.LocalFileNatives.internalGetFileInfo() method calls the system lstat() function, which is limited to 2GB files

I couldn't find a patch for this bug but I guess fix is somewhere since this problem has been known for more than a year.
Luckily, for this particular app, 2 work arounds are available which is explained in the SAP forum above.
I tried 1st w/a of giving java heap dump file name on command line but I'm not sure it worked. I'm now testing 2nd w/a of hacking snapshotHistory.ser and it seems to work.
Maybe I should have used jhat or NetBeans to begin with.

Here's info of Eclipse native library called via JNI. The output only has 'lstat' but not 'lstat64'. I don't know if this proves Eclipse bug.

$ pldd $(pgrep MemoryAnalyzer) | grep eclipse | while read line; do nm $line | ggrep -E '\|lstat|internalGetFileInfo\>' && echo $line ;done
[72]    |      4732|     296|FUNC |GLOB |0    |9      |Java_org_eclipse_core_internal_filesystem_local_LocalFileNatives_internalGetFileInfo
[87]    |         0|       0|FUNC |GLOB |0    |UNDEF  |lstat
/mat/configuration/org.eclipse.osgi/bundles/69/1/.cp/os/solaris/sparc/liblocalfile_1_0_0.so

Windows上で作成されたzipをUN*X上でどうしても展開できなかったことはないでしょうか？ざっとググってみましたがUbuntuでの対応が早かったようです。JavaとSolarisでの対応を確認してみました。

Javaでの対応は以下のブログに説明されています。jarコマンドでの対応はまだ確認できてませんが以下ブログ中のソースをJDK7でコンパイル、実行すれば動作確認できます。

Non-UTF-8 encoding in ZIP file : Xueming Shen's Blog

zip is a stripped-down version of the Jar tool with a "-encoding" option to support non-UTF8 encoding for entry name and comment

/usr/bin/unzip での対応はOpenSolarisに入っています。私はOpenSolarisから/usr/bin/unzipファイルをSolaris10にコピーし動作確認してみました。

Bug ID: 6719511 unzip should support non ascii file name

For example, convertiong Japanese sjis, % unzip -O sjis .zip

以下に登録されているテスト用zipファイルでテストしたところ、両方ともSJIS日本語ファイル名のファイルを展開できましたが違う結果となりました。Javaでは抽出されたファイル名のエンコーディングがLANG環境変数の設定に一致しました。一方unzipではシフトJIS固定のようでした。特殊文字が含まれている場合、/usr/bin/unzipを使う方が良いかもしれません。

Unzip 6.0 is missing option -O - Info-ZIP Discussion Forum

Option -O that allows you to set an encoding for filenames is missing in the latest release.
To test I made a small zip file in Windows XP that has filenames encoded in shift-jis and tried to open it in Linux in UTF8 environment.

I wanted to run Wireshark on Solaris10 where I don't have root privelege. Wireshark itself is on blastwave already.

Blastwave.org - An OpenSolaris Community Site

description Wireshark (was Ethereal) is a free network protocol analyzer
vendor url http://www.wireshark.org/

Good! But it has 35 dependencies. How can I extract those dynamic link libraries(*.so files) under my home directory efficiently?

Here, a sh script which I wrote a year ago helps. It doesn't even use pkg-get or pkgutil. But..., my script is for downloading packages only. "*.so.*" files in the packages needs to be extracted somewhere.

I googled and I found a python code fragment to extract files from package and create bunch of symbolic links. So..., I thought if my sh script and this python code are combined, The whole process of downloading dependent packages and extracting to one's virtual root(~/csw) can be fully automated.

utils.py - release/pyutils - Code Search

for line in pkgmap:
 # Matching example:
 #1 s none lib/libglib-2.0.so=libglib-2.0.so.0.200.3
 try:
 (link, target) = re.compile('. . .*? (.*)=(.*)').search(line).groups()
 link = link.replace("/opt/csw/", "") # This is for blastwave packages, since they don't use relative paths
  os.symlink(target, link)

This time, I didn't use this python. Instead I used bash one-liners which roughly looks like this:

for i in *.pkg.gz
do
  gzcat $i | pkgtrans /dev/stdin . all
done
mkdir lib
mv CSW*/root/opt/csw/X11/lib/lib* CSW*/root/opt/csw/lib/lib* lib
cd lib
for i in *
do
  ln -s $i $(echo $i | gnused 's/\.[0-9]\+\.[0-9]\+$//')
done

BTW, this search result got me interested. Why the heck does Mono have to deal with Solaris package? I thought Mono is .net framework for Linux. So, I checked project's home page and learned I was wrong!

Mono:Solaris - Mono

Mono supports Solaris on SPARC, x86 and x86-64 architectures.

Packages for Mono on Solaris/SPARC are available from our Download page.

Mono is also available as part of Nexenta (http://www.nexenta.com), the Debian-based OpenSolaris (http://www.opensolaris.org) distribution.

I don't think there are lot of applications that writes out gethrtime() return value in trace or log files. Oracle is one of them. So, I wrote a perl to convert those values in my previous blog. There are very visible caveats.

1. It doesn't run on other platforms.
2. Run it on the same machine you took the trace.
3. Run it before you reboot. Because gethrtime() counter starts on boot time.
4. You want to run it right after taking Oracle sql trace. Because:
1. gethrtime() counter rolls over to 0 after 497 days.
2. OS timestamp will drift for several reasons. e.g.) ntp kicking in.

Let's see how the perl works on one of my SPARC server.

1. oracle sql trace output fragment today

   *** SESSION ID:(491.26184) 2009-07-23 23:25:45.437
   =====================
   PARSING IN CURSOR #1 len=109 dep=0 uid=65 oct=3 lid=65 tim=3113736335727 hv=2518377154 ad='b9ccd050'
   SELECT timestamp, id, version, changeType FROM objchange WHERE timestamp > :1  AND type=:2 ORDER BY timestamp
   END OF STMT
   *** 2009-07-23 23:25:55.456
   WAIT #0: nam='SQL*Net message from client' ela= 8 driver id=1297371904 #bytes=1 p3=0 obj#=-1 tim=3113746119816
   

   Run it throught the perl.

   $ perl ~kinoue/oracle.Trace.Tim.pl /tmp/orcl_s000_11620.trc.2
   *** SESSION ID:(491.26184) 2009-07-23 23:25:45.437
   =====================
   PARSING IN CURSOR #1 len=109 dep=0 uid=65 oct=3 lid=65 tim=2009-07-23 23:25:45.43776  hv=2518377154 ad='b9ccd050'
   SELECT timestamp, id, version, changeType FROM objchange WHERE timestamp > :1  AND type=:2 ORDER BY timestamp
   END OF STMT
   *** 2009-07-23 23:25:55.456
   WAIT #0: nam='SQL*Net message from client' ela= 8 driver id=1297371904 #bytes=1 p3=0 obj#=-1 tim=2009-07-23 23:25:55.45667
   

2. oracle sql trace output fragment from 11 days ago

   *** SESSION ID:(481.17143) 2009-07-12 04:22:39.236
   =====================
   PARSING IN CURSOR #6 len=144 dep=0 uid=65 oct=3 lid=65 tim=2118622857650 hv=41747736 ad='b9cb2e10'
   SELECT task.id, task.type, name, '', '', summary, '', '', xmlSize  FROM task WHERE task.type='TaskInstance'
   and task.attr1='READY' order by name
   

   Run it throught the perl.

   *** SESSION ID:(481.17143) 2009-07-12 04:22:39.236
   =====================
   PARSING IN CURSOR #6 len=144 dep=0 uid=65 oct=3 lid=65 tim=2009-07-12 04:22:29.23621  hv=41747736 ad='b9cb2e10'
   SELECT task.id, task.type, name, '', '', summary, '', '', xmlSize  FROM task WHERE task.type='TaskInstance'
   and task.attr1='READY' order by name
   

3. oracle sql trace output fragment from 21 days ago

   *** SESSION ID:(492.30132) 2009-07-02 14:26:52.437
   =====================
   PARSING IN CURSOR #1 len=109 dep=0 uid=65 oct=3 lid=65 tim=1310268562358 hv=2518377154 ad='b9ccd050'
   SELECT timestamp, id, version, changeType FROM objchange WHERE timestamp > :1  AND type=:2 ORDER BY timestamp
   

   Run it throught the perl.

   *** SESSION ID:(492.30132) 2009-07-02 14:26:52.437
   =====================
   PARSING IN CURSOR #1 len=109 dep=0 uid=65 oct=3 lid=65 tim=2009-07-02 14:26:34.43783  hv=2518377154 ad='b9ccd050'
   SELECT timestamp, id, version, changeType FROM objchange WHERE timestamp > :1  AND type=:2 ORDER BY timestamp
   

My machine is not set up for ntp client. Yet, OS timestamp seems to constantly drift for certain seconds. Probably, the drift is caused by machine's internal hardware clock.

ORACLE 10.2 is one of supported RDBMS for Sun Java System Identity Manager. I was comparing oracle's sql trace with Sun IdM's log and noticed sql trace doesn't show user friendly timestamp. So, I googled.

OTN Discussion Forums : Event 10046 and timestamp ...

When setting event 10046 for tuning purpose, I'd like to get the timestamp to compare with other logs (application, OS, ...)
Is it possible ?
How to convert "tim=8317892534" in readable date/time ?

Oracle 10046 tim, e and ela Values use Nanoseconds/1024 not Microseconds, on some Platforms - oracle-l - FreeLists

In recent attempts to correlate 10046 extended trace data from Oracle 10.2, with DTrace data collected under Sun Solaris, I discovered that the tim, ela and e fields in Oracle trace data are not measured in microseconds.

I got hints from above and created this quick & dirty perl. I tested this only on SPARC Solaris10. I think I can elaborate some more in my next blog entry.

#!/usr/bin/env perl
use Time::HR;
use Time::HiRes;

my $diff = Time::HiRes::time() - gethrtime()/1000000000;

line: while (<>) {
    if (m/^([EFPW].*tim=)([0-9]*)(.*)$/o) {
        my $seconds = $2*1024/1000000000 + $diff;
        my ($sec,$min,$hour,$mday,$mon,$year,$wday,$yday,$isdst) = localtime($seconds);
        my $subsec = substr($seconds, index($seconds, '.'));
        printf ("%s%4d-%02d-%02d %02d:%02d:%02d%s %s\n",$1,$year+1900,$mon+1,$mday,$hour,$min,$sec,$subsec,$3);
        next line;
    }
    else {
      print $_;
      next line;
    }
}

It is possible on Solaris with the help from dtrace(with a caveat). On Linux/Windows, I don't think this is possible with off-the-shelf kernel. That's why I wrote perl in my previous entry. It can't associate short-lived socket to the owning process. So, I'm still not sure if it was worth my time.

Here's a man page from DTraceToolkit. Notice the caveat, i.e.) this only captures new connections.

$ man -M ~root/DTraceToolkit-0.99/Man tcpsnoop_snv
[...]
DESCRIPTION
     This analyses TCP network packets and prints the responsible
     PID  and  UID,  plus standard details such as IP address and
     port. This captures traffic of newly created TCP connections
     that were established while this program was running. It can
     help identify which processes is causing TCP traffic.

Here's how I show network traffic and owner process on Windows using the perl in my previous entry. This can't show sockets already closed and dis-owned. Also, I sorted by # of bytes rather than by # of packets.

$ perl /c/d/bin/active-port.pl 5 200 | sort -t $'\t' -k 3nr \
> | while read line; do
>   echo $line
>   pid=$(netstat -ano | awk '$2 == "'$(echo $line|cut -d' ' -f3)'" {print substr($0,72)}')
>   [ "$pid" != "" ] && tasklist /v /fi "PID eq $pid" | tail -1 | cut -c1-18,67-76,93-120,150-
> done
50 packets 220.16.82.26:2187 75700 bytes.
wmplayer.exe        10,828 K MY_W2K3\Administrator      0:00:20 Windows Media Player   
                                                 
81 packets other, e.g.) arp 68460 bytes.
41 packets 220.16.82.26:2255 29658 bytes.
firefox.exe        161,272 K MY_W2K3\Administrator      0:34:03 Let the Sunshine In - Mozilla Firefox   
                                
16 packets 220.16.82.26:2256 8475 bytes.
6 packets 220.16.82.26:137 660 bytes.
System                 264 K NT AUTHORITY\SYSTEM        0:36:29 N/A           
                                                          
4 packets 220.16.82.26:2144 364 bytes.
thunderbird.exe    111,220 K MY_W2K3\Administrator      0:16:12 Inbox : MyName@MyMail.COM - Thunderbird    
                    
2 packets 220.16.82.26:61466 298 bytes.

Here's how I show network traffic and owning process on Linux. I only show top 4. One restriction on Linux is that you can't use 'any' interface. Please specify real interface like 'eth0'.

$ sudo perl active-port.pl 1 1000 | head -4 \
> | while read line; do
>   echo $line;
>   echo $line|awk '$3 !~ "^o" {system("lsof -i@" _ $3)}' | tail -1
>   echo
> done
901 packets 129.158.21.152:32772 68016 bytes.
synergyc 3789 kinoue    4u  IPv4   9356       TCP myserver.jp.sun.com:32772->dhcp-jp-20-88.Jpn.Sun.COM:24800 (ESTABLISHED)

77 packets 129.158.21.152:32783 82222 bytes.
ftp     4109 kinoue    4u  IPv4  12469       TCP myserver.jp.sun.com:32783->labserv.Jpn.Sun.COM:53456 (ESTABLISHED)

8 packets other, e.g.) arp 480 bytes.

8 packets other, e.g.)UDP broadcast 1027 bytes.

There seems to be 4 profilers that's known to work with Java CAPS 5.

1. NetBeans Profiler
   
2. JProfiler
3. OptimizeIt
4. Wily
   

I have only seen NetBeans Profiler profiling Java CAPS 5.1.3. It takes a little while to setup but its interface is intuitive and it's versatile.

Yesterday, I found a 'lighter' profiler(sort of) while browsing blogs.sun.com so I tried it on my Java CAPS 5.1.3.

An application profiler using an embedded AspectJ based Java agent - Adventures in Java

Some applications of this facility that immediately come to mind are method tracing, method logging, heap tracing (dynamically tracing the amount of heap space used by an application as it runs), application health monitoring (trends of method invocations resulting in uncaught exceptions vs. “normal” execution), etc.. At development time, this framework can provide lightweight profiling capabilities.

I edited domain.xml file to change java options and restarted. And..., it worked! I could measure time spent in methods in particular classes.

Once Subhajit posts the source code, you can write your own 'lightweight' profiler.

Maybe I reinvented the wheel. Here's quick&dirty perl to convert 'truss -df' output. Unfortunately, this doesn't work if only "-d" is given. Here's how this works:

$ truss -df cat
Base time stamp:  1238745134.0279  [ Fri Apr  3 16:52:14 JST 2009 ]
16881:   0.0000 execve("/usr/bin/cat", 0xFFBFFDC4, 0xFFBFFDCC)  argc = 1
16881:   0.0051 resolvepath("/usr/lib/ld.so.1", "/lib/ld.so.1", 1023) = 12
16881:   0.0055 resolvepath("/usr/bin/cat", "/usr/bin/cat", 1023) = 12
16881:   0.0058 stat("/usr/bin/cat", 0xFFBFFBA0)                = 0
[...]

$ truss -d -f cat 2>&1 | ~kinoue/trusstimestamp.pl
Base time stamp:  1238745453.9931  [ Fri Apr  3 16:57:33 JST 2009 ]
16895:   16:57:33.9931  execve("/usr/bin/cat", 0xFFBFFDC4, 0xFFBFFDCC)  argc = 1
16895:   16:57:33.9996  resolvepath("/usr/lib/ld.so.1", "/lib/ld.so.1", 1023) = 12
16895:   16:57:34.0018  resolvepath("/usr/bin/cat", "/usr/bin/cat", 1023) = 12
16895:   16:57:34.0024  stat("/usr/bin/cat", 0xFFBFFBA0)                = 0
[...]

I hope this isn't necessary with truss on OpenSolaris. Linux's strace can do this. So, I think this has been on enhancement list. Here's perl.

#!/usr/bin/env perl
line: while (<>) {
    if ($. == 1) {
        @Fld = split(' ', $_, -1);
        $base = $Fld[3];
        print $_;
        next line;
    }
    if (m/^([0-9\/]*:[\t ]*)([0-9.]*)([\t ].*)$/o) {
        unless ($2) {
            print $_;
            next line;
        }
        my $seconds = $base + $2;
        ($sec,$min,$hour,$mday,$mon,$year,$wday,$yday,$isdst) = localtime($seconds);
        $subsec = substr($seconds, index($seconds, '.'));
        printf ("%s%02d:%02d:%02d%s %s\n",$1,$hour,$min,$sec,$subsec,$3);
        next line;
    }
}