on i64, can't create the symbol vector options

[hb--]

TECO on i64 seems to be sub-optimal, it seems to be at least very slow, or it is simply looping:

$ mmk SYS$DISK:[]SYMBOL_VECTOR.TXT
NODE::USER 09:54:12   (DCL)   CPU=00:00:01.36 PF=9576 IO=17406 MEM=232
$ mmk SYS$DISK:[]SYMBOL_VECTOR.TXT
LIBRARY/LIST=SYS$DISK:[.ETC-I64]SQLITE3.LIS/NAMES SYS$DISK:[.BIN-I64]SQLITE3.OLB/OBJECT
EDIT/TECO/EXECUTE= MAKE_SYMBOL_VECTOR.TEC       "SYS$DISK[]SYMBOL_VECTOR.TXT=SYS$DISK:[.ETC-I64]SQLITE3.LIS"
MAKE_SYMBOL_VECTOR  V2.0
NODE::USER 09:54:18 MMK       CPU=00:00:01.38 PF=9820 IO=17874 MEM=550
<<NODE::USER_7464 09:54:18 TECO32_TV CPU=00:00:00.54 PF=744 IO=600 MEM=36944>
>
NODE::USER 09:54:25 MMK       CPU=00:00:01.38 PF=9820 IO=17876 MEM=550
<<NODE::USER_7464 09:54:25 TECO32_TV CPU=00:00:01.21 PF=745 IO=600 MEM=36944>
>
NODE::USER 09:54:30 MMK       CPU=00:00:01.38 PF=9820 IO=17878 MEM=550
<<NODE::USER_7464 09:54:30 TECO32_TV CPU=00:00:01.74 PF=745 IO=600 MEM=36944>
>
NODE::USER 10:19:59 MMK       CPU=00:00:01.40 PF=9820 IO=17920 MEM=550
<<NODE::USER_7464 10:19:59 TECO32_TV CPU=00:02:34.33 PF=759 IO=600 MEM=36944>
>
NODE::USER 10:19:59 MMK       CPU=00:00:01.40 PF=9820 IO=17922 MEM=550
<<NODE::USER_7464 10:19:59 TECO32_TV CPU=00:02:34.34 PF=759 IO=600 MEM=36944>
>
NODE::USER 10:19:59 MMK       CPU=00:00:01.40 PF=9820 IO=17924 MEM=550
<<NODE::USER_7464 10:19:59 TECO32_TV CPU=00:02:34.36 PF=759 IO=600 MEM=36944>
>
 Interrupt 

$ stop
$

$ EDIT/TECO/EXECUTE= MAKE_SYMBOL_VECTOR.TEC       "SYS$DISK:[]SYMBOL_VECTOR.TXT=
SYS$DISK:[.ETC-I64]SQLITE3.LIS"
MAKE_SYMBOL_VECTOR  V2.0
...Reading symbol vector table from library listing...
NODE::USER 10:23:01 TECO32_TV CPU=00:01:27.49 PF=10396 IO=18043 MEM=360
NODE::USER 10:23:04 TECO32_TV CPU=00:01:30.70 PF=10396 IO=18044 MEM=360
NODE::USER 10:23:12 TECO32_TV CPU=00:01:38.16 PF=10396 IO=18045 MEM=360
NODE::USER 10:23:12 TECO32_TV CPU=00:01:38.35 PF=10396 IO=18046 MEM=360
NODE::USER 10:23:12 TECO32_TV CPU=00:01:38.53 PF=10396 IO=18047 MEM=360
NODE::USER 10:29:25 TECO32_TV CPU=00:07:49.89 PF=10396 IO=18054 MEM=360
NODE::USER 10:29:26 TECO32_TV CPU=00:07:50.16 PF=10396 IO=18055 MEM=360
NODE::USER 10:29:26 TECO32_TV CPU=00:07:50.36 PF=10396 IO=18056 MEM=360
 Interrupt 

$ stop
$

[tesneddon]

TECO on Itanium is an interesting beast. I'm not sure if V8.4 shipped with the latest TECO images. I do know it works with the latest fixes though, as that's how I build it. They can be fetched from here:

http://ftp.endlesssoftware.com.au/teco/teco32_tv_av/

There were a whole bunch of bugs in the AEST/TIE_I64 facilities that stuffed TECO around. I fixed a great number of them and ended up with something that actually runs (and at reasonable speed too).

[hb--]

No luck, here, on a 8.4 I64 system ...

this is with the vms supplied teco

$ EDIT/TECO/EXECUTE= MAKE_SYMBOL_VECTOR.TEC "SYS$DISK[]SYMBOL_VECTOR.TXT=SYS$DISK:[.ETC-I64]SQLITE3.LIS"
MAKE_SYMBOL_VECTOR  V2.0
...Reading symbol vector table from library listing...
NODE::USER 10:03:54 TECO32_TV CPU=00:03:30.38 PF=10396 IO=6229 MEM=353
NODE::USER 10:03:55 TECO32_TV CPU=00:03:31.17 PF=10396 IO=6230 MEM=353
NODE::USER 10:03:55 TECO32_TV CPU=00:03:31.47 PF=10396 IO=6231 MEM=353
NODE::USER 10:04:00 TECO32_TV CPU=00:03:36.13 PF=10396 IO=6232 MEM=353
NODE::USER 10:04:00 TECO32_TV CPU=00:03:36.34 PF=10396 IO=6233 MEM=353
NODE::USER 10:04:00 TECO32_TV CPU=00:03:36.52 PF=10396 IO=6234 MEM=353
NODE::USER 10:04:28 TECO32_TV CPU=00:04:04.22 PF=10405 IO=6235 MEM=362
NODE::USER 10:04:28 TECO32_TV CPU=00:04:04.43 PF=10405 IO=6236 MEM=362

this is with the updated teco

$ def/user sys$system DISK$USER:[USER.teco],'f$log("SYS$SYSTEM")
$ def/user sys$share DISK$USER:[USER.teco],'f$log("SYS$SHARE")
$ EDIT/TECO/EXECUTE= MAKE_SYMBOL_VECTOR.TEC "SYS$DISK[]SYMBOL_VECTOR.TXT=SYS$DISK:[.ETC-I64]SQLITE3.LIS"
MAKE_SYMBOL_VECTOR  V2.0
...Reading symbol vector table from library listing...done...
...Loading public header file for comparison...unable to open SRC_DIR:SQLITE3.H
...Loading existing symbol vector table...done...
...Building new symbol vector table......done...
...Checking for changes in symbol vector table..................................
................................................................................
................................................................................
..............
...symbol table has not changed...done...

$ 

looks promising, but the include file wasn't found, so

$ def/user src_dir sys$disk:[]
$ def/user sys$system DISK$USER:[USER.teco],'f$log("SYS$SYSTEM")
$ def/user sys$share DISK$USER:[USER.teco],'f$log("SYS$SHARE")
$ EDIT/TECO/EXECUTE= MAKE_SYMBOL_VECTOR.TEC "SYS$DISK:[]SYMBOL_VECTOR.TXT=SYS$DISK:[.ETC-I64]SQLITE3.LIS"
MAKE_SYMBOL_VECTOR  V2.0
...Reading symbol vector table from library listing...done...
...Loading public header file for comparison...sorting...
NODE::USER 10:07:45 TECO32_TV CPU=00:05:11.15 PF=11861 IO=6887 MEM=448
NODE::USER 10:07:57 TECO32_TV CPU=00:05:22.67 PF=11861 IO=6888 MEM=448
NODE::USER 10:07:58 TECO32_TV CPU=00:05:23.45 PF=11861 IO=6889 MEM=448
NODE::USER 10:07:58 TECO32_TV CPU=00:05:23.63 PF=11861 IO=6890 MEM=448
NODE::USER 10:07:58 TECO32_TV CPU=00:05:23.79 PF=11861 IO=6891 MEM=448
NODE::USER 10:07:58 TECO32_TV CPU=00:05:23.95 PF=11861 IO=6892 MEM=448
NODE::USER 10:07:58 TECO32_TV CPU=00:05:24.12 PF=11861 IO=6893 MEM=448
...
NODE::USER 10:09:24 TECO32_TV CPU=00:06:49.54 PF=11861 IO=6905 MEM=448
NODE::USER 10:09:24 TECO32_TV CPU=00:06:49.71 PF=11861 IO=6906 MEM=448
NODE::USER 10:09:24 TECO32_TV CPU=00:06:49.86 PF=11861 IO=6907 MEM=448

sorting takes so long?

And also annoying when (using mmk and) teco loops/hangs a control+Y and
stop blows the process(es) away :-(

For the moment I give up, because, even if I get this linked Java dumps on me
with

%SYSTEM-F-IMGDMP, dynamic image dump signal at PC=00000000020C7C10, PS=0000001B

Java tells me this is at SQLITE_SHR+50, whatever that means, I have no idea, yet.
It only confirms that Java called the jdbc jni, which called into that shareable image.

[tesneddon]

Hmm, I'll look into that. I'll be putting in some time to get my changes in and hopefully bring it forward a few versions. So, I'll check it out then.

[hb--]

Take your time. The linker is my friend and I know how to create symbol vectors. But to show that this works, I don't need that shareable image at all: I can link sqlite into my jni.

[hb--]

The problem which results in Java writing a process dump is not related to the symbol vector. It looks like there are problems in the sqlite vms mutex code. Analyzing the dump shows the accvio in or close to that mutex code and Java can't handle the exception, so the last chance handler is kicking in. The printed "Problematic frame" still makes no sense to me. I added some printfs to show what is called. But that is only a start: I need a better way to debug the code. And yes, I should report that to HP :-)

$ java -cp .:sqlite-jdbc-3.7.15-M1-vms.jar Sample
sqlite3DefaultMutex
vmsMutexAlloc
vmsMutexEnter
vmsMutexAlloc
vmsMutexAlloc
vmsMutexEnter
OpenVMS stack trace: 
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  %SYSTEM-F-ACCVIO (0xc) at pc=53AE510, pid=221957, tid=55833088
#
# JRE version: 6.0
# Java VM: Java HotSpot(TM) 64-Bit Server VM (20.6-b06 mixed mode -ia64 )
# Problematic frame:
# C  [sqlite-3^.7+0x50]
#
# An error report file with more information is saved as:
# /tmp//hs_err_pid221957.log
#
#  Please report this error to HP customer support.
#
%SYSTEM-F-IMGDMP, dynamic image dump signal at PC=00000000020C7C10, PS=0000001B

  Improperly handled condition, image exit forced by last chance handler.
    Signal arguments:   Number = 0000000000000003
                        Name   = 00000000000004FC
                                 00000000020C7C10
                                 000000000000001B

[tesneddon]

Hi @hb--,

Are you able to show the contents of the log file? Does it actually save anywhere?

[hb--]

I re-created another log file, the PC is different, but I don't think it is really different. Java for some reasons mapped the jni at a different location, that's all. I like this:

$ type "^UP^/tmp//hs_err_pid223434.log"
%TYPE-W-SEARCHFAIL, error searching for "^UP^/tmp/hs_err_pid223434.log"
-RMS-E-DNF, directory not found
-SYSTEM-W-NOSUCHFILE, no such file
$ 

but here it is, anyway

$ ty sys$scratch:hs_err_pid223434.log
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  %SYSTEM-F-ACCVIO (0xc) at pc=4E02510, pid=223434, tid=55833088
#
# JRE version: 6.0
# Java VM: Java HotSpot(TM) 64-Bit Server VM (20.6-b06 mixed mode -ia64 )
# Problematic frame:
# C  [sqlite-3^.7+0x50]
#
#  Please report this error to HP customer support.
#

---------------  T H R E A D  ---------------

Current thread (3493800):  JavaThread "main" [_thread_in_native, id=55833088, stack(349A000,353E000)]

siginfo:si_signo=(null): si_errno=not enough core, si_code=0

Top of Stack: (sp=0)

Instructions: (pc=0)

Stack: [349A000,353E000]
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
C  [sqlite-3^.7+0x50]

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
j  org.sqlite.NativeDB._open(Ljava/lang/String;I)V+0
j  org.sqlite.DB.open(Lorg/sqlite/SQLiteConnection;Ljava/lang/String;I)V+8
j  org.sqlite.SQLiteConnection.open(II)V+405
j  org.sqlite.SQLiteConnection.<init>(Ljava/lang/String;Ljava/lang/String;Ljava/util/Properties;)V+128
j  org.sqlite.JDBC.createConnection(Ljava/lang/String;Ljava/util/Properties;)Ljava/sql/Connection;+49
j  org.sqlite.JDBC.connect(Ljava/lang/String;Ljava/util/Properties;)Ljava/sql/Connection;+2
j  java.sql.DriverManager.getConnection(Ljava/lang/String;Ljava/util/Properties;Ljava/lang/ClassLoader;)Ljava/sql/Connection;+210
j  java.sql.DriverManager.getConnection(Ljava/lang/String;)Ljava/sql/Connection;+15
j  Sample.main([Ljava/lang/String;)V+4
v  ~StubRoutines::call_stub

---------------  P R O C E S S  ---------------

Java Threads: ( => current thread )
  4A4C000 JavaThread "Low Memory Detector" daemon [_thread_blocked, id=79770112, stack(4B6E000,4C12000)]
  4588800 JavaThread "C2 CompilerThread1" daemon [_thread_blocked, id=77869568, stack(483E000,4A42000)]
  4584800 JavaThread "C2 CompilerThread0" daemon [_thread_blocked, id=75739648, stack(4636000,483A000)]
  4582800 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=73609728, stack(458E000,4632000)]
  4401400 JavaThread "Finalizer" daemon [_thread_blocked, id=72724992, stack(44B6000,455A000)]
  43FE400 JavaThread "Reference Handler" daemon [_thread_blocked, id=72036864, stack(440E000,44B2000)]
=>3493800 JavaThread "main" [_thread_in_native, id=55833088, stack(349A000,353E000)]

Other Threads:
  42EC400 VMThread [stack: 42F4000,43F8000] [id=71275008]
  4A49400 WatcherThread [stack: 4A66000,4B6A000] [id=79081984]

VM state: not at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread: None

Heap
 PSYoungGen      total 38208K, used 1061K [7FD94E10000, 7FD978B0000, 7FDBF8B0000)
  eden space 32768K, 3% used [7FD94E10000,7FD94F19668,7FD96E10000)
  from space 5440K, 0% used [7FD97360000,7FD97360000,7FD978B0000)
  to   space 5440K, 0% used [7FD96E10000,7FD96E10000,7FD97360000)
 PSOldGen        total 87424K, used 0K [7FD3F8B0000, 7FD44E10000, 7FD94E10000)
  object space 87424K, 0% used [7FD3F8B0000,7FD3F8B0000,7FD44E10000)
 PSPermGen       total 21248K, used 4503K [7FD3A8B0000, 7FD3BD70000, 7FD3F8B0000)
  object space 21248K, 21% used [7FD3A8B0000,7FD3AD15F88,7FD3BD70000)

Code Cache  [40088000, 40288000, 50088000)
 total_blobs=199 nmethods=1 adapters=153 free_code_cache=267837056 largest_free_block=576


VM Arguments:
java_command: Sample
Launcher Type: SUN_STANDARD

Environment Variables:
PATH=DISK$USER:[USER.sqlite.jdbc]

Signal Handlers:
SIGSEGV: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGBUS: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGFPE: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGPIPE: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGILL: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGUSR1: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGUSR2: SIG_DFL, sa_mask[0]=0x00000000, sa_flags=0x00000000
SIGHUP: 2F67E70, sa_mask[0]=0xffffffff, sa_flags=0xfffffffd
SIGINT: 2F67E70, sa_mask[0]=0xffffffff, sa_flags=0xfffffffd
SIGQUIT: 2F67E70, sa_mask[0]=0xffffffff, sa_flags=0xfffffffd
SIGTERM: 2F67E70, sa_mask[0]=0xffffffff, sa_flags=0xfffffffd


---------------  S Y S T E M  ---------------

OS:iVMS


Memory: 8k page, physical 8388224k(3857040k free)

vm_info: Java HotSpot(TM) 64-Bit Server VM (20.6-b06) for -ia64 JRE (1.6.0-6), built on Sep 24 2014 16:44:51 by "MRJAVA" with cxx

time: Tue Feb 17 18:22:10 2015
elapsed time: 0 seconds

$ 

Oh, here the OS is iVMS! Maybe I should get in contact with Apple.

[hb--]

Got it to work. For some reasons, I enabled SQLITE_DEBUG, which is not a good idea - at least as long as xMutexHeld and xMutexNotheld aren't implemented. The accvio was in mutex\sqlite3_mutex_held, where sqlite3GlobalConfig.mutex.xMutexHeld is called. Unfortunately I don't remember what problem I wanted to debug when I enabled SQLITE_DEBUG. :-(

[tesneddon]

Ahh, there are some callbacks I didn't implement as they were only used for debugging. I'll create a fresh issue to add those in. Even if they are not necessary for day-to-day life, they would be useful in situations like this (rather than creating a red herring :-).

If you;re happy with the solution I can close this off.

[hb--]

Yes, the mystery about the "fatal error detected by the Java Runtime Environment" with the advice to "report this error to HP customer support" is solved.

The initial problem, not being able to create the symbol vector on I64 is still there, at least on my side. And there should be some mms/mmk rules to automatically make a new symbol vector if the enabled features (in config.h) changed.

As I could not create one and was too lazy to manually adjust it and having all the sqlite code in the jni has some advantages, too, I no longer use/used the shareable image. The first attempt to use it, with the symbol vector options from Alpha failed. This probably triggered me to set the SQLITE_DEBUG which made it worse. The shell links against the shareable, but - my fault - I didn't retest this debug feature with the shell. Getting Java to use the jni was my focus and that was/is a challenge by itself. But once I could step with the VMS debugger through the sqlite code, it was easy to find the cause of the accvio.