exasol / virtual-schemas

Entry point repository for the EXASOL Virtual Schemas
http://www.exasol.com
MIT License
24 stars 23 forks source link

Internal error on "CREATE VIRTUAL SCHEMA" #22

Closed tjlee closed 6 years ago

tjlee commented 6 years ago

Steps:

CREATE JAVA ADAPTER SCRIPT adapter.jdbc_adapter AS

%scriptclass com.exasol.adapter.jdbc.JdbcAdapter;

%jar /buckets/bucketfs/bfsdefault/default/virtualschema-jdbc-adapter-dist-0.0.1-SNAPSHOT.jar;

/

* execute 

CREATE CONNECTION exasol_conn TO 'jdbc:exa:192.168.99.100:8899' USER 'sys' IDENTIFIED BY 'exasol';

CREATE VIRTUAL SCHEMA virtual_exasol USING adapter.jdbc_adapter WITH SQL_DIALECT = 'EXASOL' CONNECTION_NAME = 'EXASOL_CONN' SCHEMA_NAME = 'default';



Result:
Error fired:
[22002] VM error: Internal error: VM crashed (Session: 1576534527788307527)
tjlee commented 6 years ago

UPD: I tried to create virtual schema using EXAplus application and I received the same error

| 14:24:12.603 | [22002] VM error: Internal error: VM crashed (Session: 1576611240647135888)
andrehacker commented 6 years ago

This could be a memory related issue (too little memory granted for the JVM), but we have to look in the logs.

Could you attach the logs here? The issue https://github.com/EXASOL/docker-db/issues/5 has some comments at the end about how to obtain the logs in Docker (I cannot test it right now). Let us know if this doesn't work for you.

You could also do some tests with tuning the Xmx and Xms parameters, e.g. set lower values, and see if this helps. Just specify jvmoption as follows.

CREATE JAVA ADAPTER SCRIPT adapter.jdbc_adapter AS
%jvmoption -Xms64m -Xmx128m;
tjlee commented 6 years ago

Hi, I tried to use jmvoptions tuning with values you provided. The same error. [2017-08-29 18:10:01] [22002] VM error: Internal error: VM crashed (Session: 1577078562553184554)

Logs:

=============== WAITING FOR EXASOL ==========================
grep: /exa/logs/logd/DWAd.log: No such file or directory
[2017-08-29 15:02:23] exadt:: '/exa/etc' does not exist! Doing full initialization.
[2017-08-29 15:02:23] exadt:: copying license file '/.license.xml' to '/exa/etc'
[2017-08-29 15:02:23] exadt:: initializing EXAConf
[2017-08-29 15:02:23] exadt:: searching for the first interface with state UP
Successfully initialized configuration in '/exa/etc/EXAConf'.
[2017-08-29 15:02:23] exadt:: using interface 'eth0@if71' with address '172.18.0.11/16'.
[2017-08-29 15:02:23] exadt:: creating EXAStorage devices
[2017-08-29 15:02:23] exadt:: changing DB, volume and BucketFS owner to 500 : 500
[2017-08-29 15:02:23] exadt:: setting hostname to 'n11'
[2017-08-29 15:02:23] exadt:: calling '/usr/opt/EXASuite-6/EXAClusterOS-6.0.2/libexec/exainit.py'
grep: /exa/logs/logd/DWAd.log: No such file or directory
[2017-08-29 15:02:24] stage0: Run stage 'stage0'
[2017-08-29 15:02:24] stage0: Run service environment_conf
[2017-08-29 15:02:24] stage0: Run service license_check
[2017-08-29 15:02:24] stage0: Run service prepare_update
[2017-08-29 15:02:24] stage0: Run service next_stage
[2017-08-29 15:02:24] stage0: Current environment settings:
[2017-08-29 15:02:24] stage0: >>> [('COS_CONF_DIR', '/exa'),
[2017-08-29 15:02:24] stage0: >>>  ('COS_DIRECTORY', '/usr/opt/EXASuite-6/EXAClusterOS-6.0.2'),
[2017-08-29 15:02:24] stage0: >>>  ('EXA_NODE_ID', '11'),
[2017-08-29 15:02:24] stage0: >>>  ('HOME', '/'),
[2017-08-29 15:02:24] stage0: >>>  ('HOSTNAME', 'n11'),
[2017-08-29 15:02:24] stage0: >>>  ('LANG', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_ADDRESS', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_COLLATE', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_CTYPE', 'en_US.utf8'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_IDENTIFICATION', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_MEASUREMENT', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_MESSAGES', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_MONETARY', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_NAME', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_NUMERIC', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_PAPER', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_TELEPHONE', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('LC_TIME', 'C'),
[2017-08-29 15:02:24] stage0: >>>  ('PATH',
[2017-08-29 15:02:24] stage0: >>>   '/usr/opt/EXASuite-6/EXAClusterOS-6.0.2/bin:/usr/opt/EXASuite-6/EXAClusterOS-6.0.2/sbin:/usr/opt/EXASuite-6/EXARuntime-6.0.2/bin:/usr/opt/EXASuite-6/EXARuntime-6.0.2/sbin:/bin:/sbin:/usr/bin:/usr/sbin'),
[2017-08-29 15:02:24] stage0: >>>  ('PWD', '/'),
[2017-08-29 15:02:24] stage0: >>>  ('RE_PATH', '/usr/opt/EXASuite-6/EXARuntime-6.0.2'),
[2017-08-29 15:02:24] stage0: >>>  ('SHLVL', '1'),
[2017-08-29 15:02:24] stage0: >>>  ('_', '/usr/opt/EXASuite-6/EXAClusterOS-6.0.2/devel/docker/exadt')]
[2017-08-29 15:02:24] stage0: You have following license limits:
[2017-08-29 15:02:24] stage0: >>>     Database memory (GiB):        200 Main memory (RAM) usable by databases
[2017-08-29 15:02:24] stage0: >>>             Cluster nodes:          1 Number of usable cluster nodes
[2017-08-29 15:02:24] stage0: >>>   Database raw size (GiB):  unlimited Raw Size of Databases (see Value RAW_OBJECT_SIZE in System Tables)
[2017-08-29 15:02:24] stage0: >>>   Database mem size (GiB):  unlimited Compressed Size of Databases (see Value MEM_OBJECT_SIZE in System Tables)
[2017-08-29 15:02:24] stage0: >>>           Expiration date:  unlimited Date of license expiration
[2017-08-29 15:02:24] stage0: Next stage will be 'stage1'.
grep: /exa/logs/logd/DWAd.log: No such file or directory
[2017-08-29 15:02:25] stage1: Run stage 'stage1'
[2017-08-29 15:02:25] stage1: Run service node_options
[2017-08-29 15:02:25] stage1: Run service prepare_update
[2017-08-29 15:02:25] stage1: Run service create_users
[2017-08-29 15:02:25] stage1: Run service node_etc_cos
[2017-08-29 15:02:25] stage1: Run service name_resolution
[2017-08-29 15:02:25] stage1: Run service sysctl
[2017-08-29 15:02:25] stage1: Run service diskconf
[2017-08-29 15:02:25] stage1: Run service broadcast_peers
[2017-08-29 15:02:25] stage1: Run service root_bashrc
[2017-08-29 15:02:25] stage1: Run service super_cored
[2017-08-29 15:02:25] stage1: Run service cored_command
[2017-08-29 15:02:25] stage1: Run service next_stage
[2017-08-29 15:02:25] stage1: Current node id is '11'
[2017-08-29 15:02:25] stage1: Current node options are:
[2017-08-29 15:02:25] stage1: >>> [('disks',
[2017-08-29 15:02:25] stage1: >>>   <config at 0x7fd906d4c868: [('default', <config at 0x7fd906d4c990: [('name', 'default'), ('devices', [('dev.1.data', 'dev.1.meta')]), ('mapping', [('dev.1', '/exa/data/storage')]), ('mapped_devices', [('/exa/data/storage/dev.1.meta', '/exa/data/storage/dev.1.meta'), ('/exa/data/storage/dev.1.data', '/exa/data/storage/dev.1.data')])]>)]>),
[2017-08-29 15:02:25] stage1: >>>  ('docker_volume', '/exa/etc/n11'),
[2017-08-29 15:02:25] stage1: >>>  ('exposed_ports', [(8888, 8899), (6583, 6594)]),
[2017-08-29 15:02:25] stage1: >>>  ('id', '11'),
[2017-08-29 15:02:25] stage1: >>>  ('name', 'n11'),
[2017-08-29 15:02:25] stage1: >>>  ('private_ip', '172.18.0.11'),
[2017-08-29 15:02:25] stage1: >>>  ('private_net', '172.18.0.11/16'),
[2017-08-29 15:02:25] stage1: >>>  ('public_ip', ''),
[2017-08-29 15:02:25] stage1: >>>  ('public_net', '')]
[2017-08-29 15:02:25] stage1: Following users where created: 500:500
[2017-08-29 15:02:25] stage1: Current node UUID is 'F1D398F68EB09671857D521B451D8041CDF09769' (fresh)
[2017-08-29 15:02:25] stage1: /etc/hosts content:
[2017-08-29 15:02:25] stage1: >>> # hosts is generated by exainit
[2017-08-29 15:02:25] stage1: >>> 127.0.0.1 localhost localhost.localdomain
[2017-08-29 15:02:25] stage1: >>> 172.18.0.11 n11
[2017-08-29 15:02:25] stage1: /etc/resolv.conf content:
[2017-08-29 15:02:25] stage1: >>> # resolv.conf is disabled by exainit
[2017-08-29 15:02:25] stage1: Following sysctl parameters have incorrect values:
[2017-08-29 15:02:25] stage1:                    net.core.rmem_default: '4194304' != None
[2017-08-29 15:02:25] stage1:                    net.core.wmem_default: '524288' != None
[2017-08-29 15:02:25] stage1:                        net.ipv4.tcp_rmem: '4096        87380   1048576' != None
[2017-08-29 15:02:25] stage1:                        net.core.rmem_max: '4194304' != None
[2017-08-29 15:02:25] stage1:                       kernel.threads-max: '274432' != '63813'
[2017-08-29 15:02:25] stage1:                 net.ipv4.tcp_fin_timeout: '60' != None
[2017-08-29 15:02:25] stage1:            net.ipv4.tcp_keepalive_probes: '80' != None
[2017-08-29 15:02:25] stage1:             net.ipv4.tcp_keepalive_intvl: '20' != None
[2017-08-29 15:02:25] stage1:              net.ipv4.tcp_keepalive_time: '40' != None
[2017-08-29 15:02:25] stage1:                  net.ipv4.tcp_syncookies: '1' != None
[2017-08-29 15:02:25] stage1:                        net.ipv4.tcp_wmem: '4096        16384   4194304' != None
[2017-08-29 15:02:25] stage1:                        net.core.wmem_max: '1048576' != None
[2017-08-29 15:02:25] stage1:              net.core.netdev_max_backlog: '1000' != None
[2017-08-29 15:02:25] stage1: Register '/exa/data/storage/dev.1.data' device in meta device '/exa/data/storage/dev.1.meta'
[2017-08-29 15:02:25] stage1: Following nodes are registered: 172.18.0.11:10001
[2017-08-29 15:02:25] stage1: super_cored started with return code: 0
[2017-08-29 15:02:25] stage1: Call cored with following command: '/usr/opt/EXASuite-6/EXAClusterOS-6.0.2/libexec/cos_cored -n 11 --renice -10 --auth-sock-dir /var/lock --oom-adjustment -5 -m 224.0.0.1 -s 172.18.0.11 -t 10001 -l /exa/logs/cored --default-file-mode 644 /usr/opt/EXASuite-6/EXAClusterOS-6.0.2/libexec/exainit.py stage2 /proc/1/fd/2'
[2017-08-29 15:02:25] stage1: Next stage will be 'stage2'.
[2017-08-29 15:02:25] Starting with PID 5
[2017-08-29 15:02:25] Core Daemon v6.0.2  (build 14583)
[2017-08-29 15:02:25] Using multicast address 224.0.0.1.
[2017-08-29 15:02:25] Receive socket is bind to interface eth0.
[2017-08-29 15:02:25] Started UNIX socket authentication engine (authentication socket directory is /var/lock).
[2017-08-29 15:02:25] Core Engine started ... logdir=/exa/logs/cored
[2017-08-29 15:02:25] Received transitional Config Change Message: rid=0 seq=0 conf=3 <>
[2017-08-29 15:02:25] Received regular Config Change Message: rid=4 seq=0 conf=3 < ip://n11:10001>
[2017-08-29 15:02:25] Self information: NID = <invalid>, address = <none>; event_id: 0; no. of cluster nodes: 0
[2017-08-29 15:02:25]   11: ip://n11:10001 (offline) usage: 0
[2017-08-29 15:02:25] No partitions known.
grep: /exa/logs/logd/DWAd.log: No such file or directory
[2017-08-29 15:02:26] Active Nodes: 1 - ip://n11:10001
[2017-08-29 15:02:26] Nodes of last Configuration: 0 -
[2017-08-29 15:02:26] Config Change completed.
[2017-08-29 15:02:26] Self information: NID = 11, address = ip://n11:10001; event_id: 2; no. of cluster nodes: 1
[2017-08-29 15:02:26]   11: ip://n11:10001 (available) usage: 0
[2017-08-29 15:02:26] No partitions known.
[2017-08-29 15:02:26] Started /usr/opt/EXASuite-6/EXAClusterOS-6.0.2/libexec/exainit.py with PID:59 UID:0 GID:0 Part:0 Node:11
grep: /exa/logs/logd/DWAd.log: No such file or directory
[2017-08-29 15:02:27] stage2: Run stage 'stage2'
[2017-08-29 15:02:27] stage2: Run service node_options
[2017-08-29 15:02:27] stage2: Run service prepare_update
[2017-08-29 15:02:27] stage2: Run service wait_for_nodes
[2017-08-29 15:02:27] stage2: Run service next_stage_for_slave
[2017-08-29 15:02:27] stage2: Run service sshd
[2017-08-29 15:02:27] Started /bin/sh with PID:72 UID:0 GID:0 Part:1 Node:0
grep: /exa/logs/logd/DWAd.log: No such file or directory
[2017-08-29 15:02:28] child 72 (Part:1 Node:0) returned with state 0.
[2017-08-29 15:02:29] Started /bin/sh with PID:112 UID:0 GID:0 Part:2 Node:0
grep: /exa/logs/logd/DWAd.log: No such file or directory
[2017-08-29 15:02:30] child 112 (Part:2 Node:0) returned with state 0.
grep: /exa/logs/logd/DWAd.log: No such file or directory
Tue Aug 29 15:02:30 UTC 2017: start script '/usr/opt/EXASuite-6/EXAClusterOS-6.0.2/sbin/cos_sync_files'.
Tue Aug 29 15:02:30 UTC 2017: pack files for sync.
root/.ssh/id_rsa
root/.ssh/id_rsa.pub
root/.ssh/authorized_keys
No nodes to synchronize.
Tue Aug 29 15:02:30 UTC 2017: start script '/usr/opt/EXASuite-6/EXAClusterOS-6.0.2/sbin/cos_sync_files'.
Tue Aug 29 15:02:30 UTC 2017: pack files for sync.
u00500/.ssh/id_rsa
u00500/.ssh/id_rsa.pub
u00500/.ssh/authorized_keys
No nodes to synchronize.
[2017-08-29 15:02:30] Started /usr/sbin/sshd with PID:201 UID:0 GID:0 Part:3 Node:0
[2017-08-29 15:02:30] stage2: Run service next_stage
[2017-08-29 15:02:30] stage2: Current node id is '11'
[2017-08-29 15:02:30] stage2: All nodes are online: ('n11',)
[2017-08-29 15:02:30] stage2: Current node is a master node.
[2017-08-29 15:02:30] stage2: Next stage will be 'stage3'.
[2017-08-29 15:02:30] stage2: sshd was started with PID 3
[2017-08-29 15:02:30] stage2: SSH keys for following users was generated: 0, 500
[2017-08-29 15:02:30] stage2: Next stage will be 'stage3'.
grep: /exa/logs/logd/DWAd.log: No such file or directory
[2017-08-29 15:02:31] stage3: Run stage 'stage3'
[2017-08-29 15:02:31] stage3: Run service node_options
[2017-08-29 15:02:31] stage3: Run service prepare_update
[2017-08-29 15:02:31] stage3: Run service storaged_conf
[2017-08-29 15:02:31] stage3: Run service databases_conf
[2017-08-29 15:02:31] stage3: Run service wait_for_nodes
[2017-08-29 15:02:31] stage3: Run service bucketfs
[2017-08-29 15:02:31] Started /usr/opt/EXASuite-6/EXAClusterOS-6.0.2/libexec/bucketfsd with PID:214 UID:0 GID:0 Part:4 Node:0
[2017-08-29 15:02:31] stage3: Run service storaged_conf
[2017-08-29 15:02:31] stage3: Run service next_stage_for_slave
[2017-08-29 15:02:31] stage3: Run service logd
[2017-08-29 15:02:31] Started /usr/opt/EXASuite-6/EXAClusterOS-6.0.2/libexec/logd with PID:215 UID:0 GID:0 Part:5 Node:0
[2017-08-29 15:02:31] stage3: Run service lockd
[2017-08-29 15:02:31] Started /usr/opt/EXASuite-6/EXAClusterOS-6.0.2/libexec/lockd with PID:216 UID:0 GID:0 Part:6 Node:0
[2017-08-29 15:02:31] stage3: Run service dwad
[2017-08-29 15:02:32] Started /usr/opt/EXASuite-6/EXAClusterOS-6.0.2/libexec/dwad with PID:219 UID:0 GID:0 Part:7 Node:0
grep: /exa/logs/logd/DWAd.log: No such file or directory
[2017-08-29 15:02:34] stage3: Run service storaged
[2017-08-29 15:02:34] Started /usr/opt/EXASuite-6/EXAClusterOS-6.0.2/libexec/cos_storage with PID:264 UID:0 GID:0 Part:8 Node:0
[2017-08-29 15:02:34] Force new cluster synchronization upon user request from partition 8.
[2017-08-29 15:02:34] [Warning from node n11] Potentially out of synchronization. Force new cluster configuration.
[2017-08-29 15:02:34] Received transitional Config Change Message: rid=4 seq=44 conf=7 < ip://n11:10001>
[2017-08-29 15:02:34] Received regular Config Change Message: rid=8 seq=0 conf=7 < ip://n11:10001>
[2017-08-29 15:02:34] Self information: NID = 11, address = ip://n11:10001; event_id: 26; no. of cluster nodes: 1
[2017-08-29 15:02:34]   11: ip://n11:10001 (available) usage: 6
[2017-08-29 15:02:34]   Partition 3 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:34]   Partition 4 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:34]   Partition 5 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:34]   Partition 6 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:34]   Partition 7 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:34]   Partition 8 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:34] Registered local processes:
[2017-08-29 15:02:34] PID: 59 (PID: 0, NID: 11)
[2017-08-29 15:02:34] PID: 201 (PID: 3, NID: 0)
[2017-08-29 15:02:34] PID: 214 (PID: 4, NID: 0)
[2017-08-29 15:02:34] PID: 215 (PID: 5, NID: 0)
[2017-08-29 15:02:34] PID: 216 (PID: 6, NID: 0)
[2017-08-29 15:02:34] PID: 219 (PID: 7, NID: 0)
[2017-08-29 15:02:34] PID: 264 (PID: 8, NID: 0)
[2017-08-29 15:02:58] Active Nodes: 1 - ip://n11:10001
[2017-08-29 15:02:58] Nodes of last Configuration: 1 - ip://n11:10001
[2017-08-29 15:02:58] Config Change completed.
[2017-08-29 15:02:58] Self information: NID = 11, address = ip://n11:10001; event_id: 34; no. of cluster nodes: 1
[2017-08-29 15:02:58]   11: ip://n11:10001 (available) usage: 6
[2017-08-29 15:02:58]   Partition 3 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:58]   Partition 4 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:58]   Partition 5 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:58]   Partition 6 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:58]   Partition 7 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:58]   Partition 8 contains 1 nodes: [ 11 ]
[2017-08-29 15:02:58] Registered local processes:
[2017-08-29 15:02:58] PID: 59 (PID: 0, NID: 11)
[2017-08-29 15:02:58] PID: 201 (PID: 3, NID: 0)
[2017-08-29 15:02:58] PID: 214 (PID: 4, NID: 0)
[2017-08-29 15:02:58] PID: 215 (PID: 5, NID: 0)
[2017-08-29 15:02:58] PID: 216 (PID: 6, NID: 0)
[2017-08-29 15:02:58] PID: 219 (PID: 7, NID: 0)
[2017-08-29 15:02:58] PID: 264 (PID: 8, NID: 0)
[2017-08-29 15:02:58] stage3: Run service storage_volumes
[2017-08-29 15:02:58] stage3: Run service databases
[2017-08-29 15:02:58] Started /usr/opt/EXASuite-6/EXAClusterOS-6.0.2/bin/dwa_wrapper with PID:398 UID:500 GID:500 Part:9 Node:0
[2017-08-29 15:02:58] stage3: Run service next_stage
[2017-08-29 15:02:58] stage3: Current node id is '11'
[2017-08-29 15:02:58] stage3: storaged config file genarated here: '/exa/etc/cos_storage.conf'
[2017-08-29 15:02:58] stage3: Database configuration: nsexec(0106775), /usr/opt/mountjail, /exa/logs/db/DB1
[2017-08-29 15:02:58] stage3: All nodes are online: ('n11',)
[2017-08-29 15:02:58] stage3: bucketfs was started with PID 4
[2017-08-29 15:02:58] stage3: Current node is a master node.
[2017-08-29 15:02:58] stage3: Next stage will be 'stage4'.
[2017-08-29 15:02:58] stage3: logd was started with PID 5
[2017-08-29 15:02:58] stage3: lockd was started with PID 6
[2017-08-29 15:02:58] stage3: dwad was started with PID 7
[2017-08-29 15:02:58] stage3: storaged was started with PID 8
[2017-08-29 15:02:58] stage3: Volumes created: DataVolume1:0
[2017-08-29 15:02:58] stage3: Following databases was created: DB1
[2017-08-29 15:02:58] stage3: Next stage will be 'stage4'.
[2017-08-29 15:02:59] Started /usr/opt/EXASuite-6/EXASolution-6.0.2/bin/pddserver with PID:427 UID:500 GID:500 Part:10 Node:0
[2017-08-29 15:03:00] Started /usr/opt/EXASuite-6/EXASolution-6.0.2/bin/objectserver with PID:526 UID:500 GID:500 Part:11 Node:0
[2017-08-29 15:03:00] Started /usr/opt/EXASuite-6/EXASolution-6.0.2/bin/exasqlinit with PID:553 UID:500 GID:500 Part:12 Node:0
[2017-08-29 15:03:01] stage4: Run stage 'stage4'
[2017-08-29 15:03:01] stage4: Run service node_options
[2017-08-29 15:03:01] stage4: Run service prepare_update
[2017-08-29 15:03:01] stage4: Run service wait_for_nodes
[2017-08-29 15:03:01] stage4: Current node id is '11'
[2017-08-29 15:03:01] stage4: All nodes are online: ('n11',)
[2017-08-29 15:03:01] stage4: All stages finished.
[2017-08-29 15:03:01] root child 59 returned with state 0.
[2017-08-29 15:03:04] child 553 (Part:12 Node:0) returned with state 0.
[2017-08-29 15:03:04] Started /usr/opt/EXASuite-6/EXASolution-6.0.2/bin/exasqllog with PID:604 UID:500 GID:500 Part:13 Node:0
[2017-08-29 15:03:22] Started /usr/opt/EXASuite-6/EXASolution-6.0.2/bin/loaderd with PID:692 UID:500 GID:500 Part:14 Node:0
[2017-08-29 15:03:22] Started /usr/opt/EXASuite-6/EXASolution-6.0.2/bin/exaetl with PID:713 UID:500 GID:500 Part:15 Node:0
[2017-08-29 15:03:22] Started /usr/opt/EXASuite-6/EXASolution-6.0.2/bin/exacs with PID:714 UID:500 GID:500 Part:16 Node:0
[2017-08-29 15:03:23] Started /usr/opt/EXASuite-6/EXASolution-6.0.2/bin/exasql with PID:759 UID:500 GID:500 Part:17 Node:0
=============== PUTTING ADAPTER TO DEFAULT BUCKET ==========================
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
=============== ADAPTER ADDED TO DEFAULT BUCKET ==========================
100 7493k    0     0  100 7493k      0   215M --:--:-- --:--:-- --:--:--  228M
[2017-08-29 15:08:40] Started /usr/opt/EXASuite-6/EXASolution-6.0.2/bin/exasql with PID:1283 UID:500 GID:500 Part:18 Node:0
[2017-08-29 15:08:41] Started /usr/opt/EXASuite-6/EXASolution-6.0.2/bin/exasql with PID:1305 UID:500 GID:500 Part:19 Node:0
[2017-08-29 15:13:45] child 1305 (Part:19 Node:0) returned with state 0.
andrehacker commented 6 years ago

Thanks for trying out jvmoptions. However, the docker logs were not sufficient (my comment was a bit unclear about this), instead we need the full content of the logs directory. You can obtain this as follows: If you followed the steps described at https://github.com/exasol/docker-db with --root ~/MyCluster/, then the logs will be stored in ~/MyCluster/n11/logs/db/DB1. There should be many files, recently updated. Please send an archive with this folder content.

tjlee commented 6 years ago

@andrehacker Logs you asked: l.tar.gz Thank you.

ooke commented 6 years ago

@tjlee I can not reproduce your problem, if I call it, than I get following:

SQL_EXA> CREATE VIRTUAL SCHEMA virtual_exasol USING adapter.jdbc_adapter WITH SQL_DIALECT = 'EXASOL' CONNECTION_NAME = 'EXASOL_CONN' SCHEMA_NAME = 'TEST';
EXA: CREATE VIRTUAL SCHEMA virtual_exasol2 USING adapter.jdbc_adapter2 WITH...
Error: [22002] VM error: Java VM cannot find '/buckets/bucketfs/bfsdefault/default/virtualschema-jdbc-adapter-dist-0.0.1-SNAPSHOT.jar': No such file or directory (Session: 1577345180638206579)

And it is, because the bucket is not /buckets/bucketfs/bfsdefalt/default but /buckets/bfsdefault/default, with correct path it looks like following for me:

SQL_EXA> CREATE VIRTUAL SCHEMA virtual_exasol USING adapter.jdbc_adapter WITH SQL_DIALECT = 'EXASOL' CONNECTION_NAME = 'EXASOL_CONN' SCHEMA_NAME = 'TEST';
EXA: CREATE VIRTUAL SCHEMA virtual_exasol USING adapter.jdbc_adapter WITH S...

Rows affected: 0

To look, what you have, you can use this handy script:

SQL_EXA> CREATE PYTHON SCALAR SCRIPT ls(p VARCHAR(10000)) EMITS (n VARCHAR(10000)) as
1  > def run(ctx):
2  >   import os
3  >   for x in os.listdir(ctx.p):
4  >     ctx.emit(os.path.join(ctx.p, x))
5  > /

Then you could use it like follows:

SQL_EXA> select ls('/buckets/bfsdefault/default');
EXA: select ls('/buckets/bfsdefault/default');

N                                                                                                                                                                                                       
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
/buckets/bfsdefault/default/EXAClusterOS                                                                                                                                                                
/buckets/bfsdefault/default/EXASolution-6.0.2                                                                                                                                                           
/buckets/bfsdefault/default/virtualschema-jdbc-adapter-dist-0.0.1-SNAPSHOT.jar                                                                                                                          

3 rows in resultset.

But I do not get any crash, do you have the latest exasol/docker-db image? (my has ID 716a0d81cf30)

tjlee commented 6 years ago

@ooke Hi, Our custom image is based on exasol/docker-db:latest

FROM exasol/docker-db:latest
ADD "virtualschema-jdbc-adapter-dist-0.0.1-SNAPSHOT.jar" /
ADD entrypoint.sh /
ADD init.sh /

RUN ["/bin/bash", "-c", "chmod +x /virtualschema-jdbc-adapter-dist-0.0.1-SNAPSHOT.jar &&\
chmod +x entrypoint.sh &&\
chmod +x init.sh"]

EXPOSE 8888 6583 2580

ENTRYPOINT ["/entrypoint.sh"]

You can find files here: https://github.com/DataGrip/docker-env/tree/master/exasol

We found out, that we can't execute java and python script (only lua). When we try to execute ls we've got [22002] VM error: Internal error: VM crashed (Session: 1577701465689038336) Do we need to enable java & python support somehow?

ooke commented 6 years ago

@tjlee Hi,

which Linux kernel do you use? Can you please paste the output of uname -a command?

tjlee commented 6 years ago
[root@f938c16f4524 /]# uname -a
Linux f938c16f4524 4.4.83-boot2docker #1 SMP Fri Aug 18 17:31:15 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
ooke commented 6 years ago

I can not reproduce your problem, if I build the docker image from your Dockerfile it still works. Could maybe you try to reproduce this output:

$ docker exec -it romantic_knuth /usr/opt/EXASuite-6/EXASolution-6.0.3/bin/Console/exaplus -c localhost:8888
EXAplus 6.0.3 (c) EXASOL AG

User (root): sys
Password: ******

Friday, September 29, 2017 2:13:15 PM UTC
Connected to database DB1 as user sys.
EXASolution 6.0.3 (c) EXASOL AG

SQL_EXA> create schema test;
EXA: create schema test;

Rows affected: 0

SQL_EXA> create or replace python scalar script t1(x int) returns int as
1  > def run(c):
2  >   return c.x + 1
3  > /
EXA: create or replace python scalar script t1(x int) returns int as...

Rows affected: 0

SQL_EXA> select t1(1);
EXA: select t1(1);

T1(1)
---------------------
                    2

1 row in resultset.

SQL_EXA>

Dockerfile:

FROM exasol/docker-db:6.0.3-d1

ADD "virtualschema-jdbc-adapter-dist-0.0.1-SNAPSHOT.jar" /
ADD entrypoint.sh /
ADD init.sh /

RUN ["/bin/bash", "-c", "chmod +x /virtualschema-jdbc-adapter-dist-0.0.1-SNAPSHOT.jar &&\
chmod +x entrypoint.sh &&\
chmod +x init.sh"]

EXPOSE 8888 6583 2580

ENTRYPOINT ["/entrypoint.sh"]

entrypoint.sh:

#!/bin/bash
/usr/opt/EXASuite-6/EXAClusterOS-6.0.3/devel/docker/exadt init-sc & /init.sh

init.sh:

#!/bin/bash

echo =============== WAITING FOR EXASOL ==========================
#waiting for exasol to start
export STATUS=0
i=0
while [[ $STATUS -eq 0 ]] || [[ $i -lt 120 ]]; do
        sleep 1
        i=$((i+1))
        STATUS=$(grep 'System is ready to receive client connections.' /exa/logs/logd/DWAd.log | wc -l)
done

echo =============== PUTTING ADAPTER TO DEFAULT BUCKET ==========================
#get default bucket write password
BW_PWD=$(grep 'write-password' /exa/etc/bucketfs.cfg | sed "s/write-password = //g" | base64 -d)
curl -X PUT -T /virtualschema-jdbc-adapter-dist-0.0.1-SNAPSHOT.jar http://w:$BW_PWD@localhost:6583/default/virtualschema-jdbc-adapter-dist-0.0.1-SNAPSHOT.jar

if [ ! -f /exa/logs/logd/Authentication.log ]; then
    echo =============== ADAPTER ADDED TO DEFAULT BUCKET ==========================
fi

if [ ! -z $EXASOL_SCHEMA ]; then
        echo "EXASOL_SCHEMA: $EXASOL_SCHEMA"
else
        EXASOL_SCHEMA=test
        echo "EXASOL_SCHEMA: $EXASOL_SCHEMA"
fi

#creating default schema
echo "CREATE SCHEMA $EXASOL_SCHEMA;" | ./usr/opt/EXASuite-6/EXASolution-6.0.3/bin/Console/exaplus -c n11:8888 -u sys -P exasol

#trap
while [ "$END" == '' ]; do
    sleep 1
        trap "/usr/opt/EXASuite-6/EXAClusterOS-6.0.3/devel/docker/exadt stop && END=1" INT TERM
done

Start container with this command:

$ docker run --privileged --rm -it 5917fc0f30e9

My versions:

$ uname -a
Linux ip-27-1-244-62 4.4.51-40.58.amzn1.x86_64 #1 SMP Tue Feb 28 21:57:17 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
$ docker --version
Docker version 17.03.2-ce, build 7392c3b/17.03.2-ce
ooke commented 6 years ago

@tjlee: have you tried to reproduce it?

tjlee commented 6 years ago

@ooke I tried to reproduce step with EXA: create or replace python scalar script t1(x int) returns int as... and I received

SQL_EXA> select t1(1);
EXA: select t1(1);
Error: [22002] VM error: Internal error: VM crashed (Session: 1583605424288551298)

The only difference is Exasol version. I use /usr/opt/EXASuite-6/EXASolution-6.0.2/bin/Console/ &

[root@n11 Console]# ./exaplus -c localhost:8888
EXAplus 6.0.1 (c) EXASOL AG

User (root): sys
Password: ******

Thursday, November 9, 2017 4:08:38 PM UTC
Connected to database DB1 as user sys.
EXASolution 6.0.2 (c) EXASOL AG

I'll try with Exasol 6.0.3

tjlee commented 6 years ago

@ooke Hi, Could you specify java version to build virtualschema-jdbc-adapter-dist-0.0.1-SNAPSHOT.jar ? Thank you.

P.S.: I was using:

Created-By: Apache Maven 3.5.0
Build-Jdk: 1.8.0_101
tjlee commented 6 years ago

@ooke Hi, I rebuilt image with EXASolution 6.0.3 (c) EXASOL AG and I got Error: [22002] VM error: Internal error: VM crashed (Session: 1583955331794950227)

SQL_EXA> [root@n11 Console]# uname -a
Linux n11 4.4.93-boot2docker #1 SMP Wed Oct 18 17:00:16 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
Docker version 17.06.0-ce, build 02c1d87
tjlee commented 6 years ago

Crashed session log:

[root@n11 DB1]# less 20171113_135
20171113_135158_SqlSession_1583955331794950227.0  20171113_135232_SqlProcess_9.0
[root@n11 DB1]# less 20171113_135158_SqlSession_1583955331794950227.0
13.11 13:51:58.267 R6.0.3 | REPOSITORY_URL = bzr+https://bzr.blau.exasol.com/gbc/exasol/R6.0.3/ | REPOSITORY_REVISION = 8010
13.11 13:51:58.267 Login attributes V12:
13.11 13:51:58.267      attribute: 1 ATTR_USERNAME: sys
13.11 13:51:58.267      attribute: 2 ATTR_CLIENTNAME: EXAplus
13.11 13:51:58.267      attribute: 3 ATTR_CLIENTOS: Linux - 4.4.93-boot2docker - amd64
13.11 13:51:58.267      attribute: 4 ATTR_DRIVERNAME: EXASolution JDBC Driver
13.11 13:51:58.267      attribute: 5 ATTR_LANGUAGE: en
13.11 13:51:58.268      attribute: 7 ATTR_AUTOCOMMIT: true
13.11 13:51:58.268      attribute: 8 ATTR_RELEASE_VERSION: 6.0.3
13.11 13:51:58.268      attribute: 10 ATTR_CLIENTVERSION: 6.0.3
13.11 13:51:58.268      attribute: 11 ATTR_CLIENTRUNTIME: Oracle Corporation - 1.8.0_131 - OpenJDK 64-Bit Server VM - mixed mode
13.11 13:51:58.268      attribute: 44 ATTR_FEEDBACK_INTERVAL: 1
13.11 13:51:58.268      attribute: 13 ATTR_CLIENTOS_USERNAME: root
13.11 13:51:58.269 Protocol encryption chacha20 is enabled
13.11 13:51:58.277 ESC[32mEXAOP_NOTICE ESC[0mLogin accepted: User "sys" logged in successfully from host "127.0.0.1". Session: 1583955331794950227.
13.11 13:51:58.292 MetadataThread: SID: 1583955331794950227: Received packet: type: 120, serial: 4, size: 0
13.11 13:51:58.312 MetadataThread: SID: 1583955331794950227: Received packet: type: 121, serial: 5, size: 0
13.11 13:51:58.314 MetadataThread: SID: 1583955331794950227: Received packet: type: 122, serial: 6, size: 8
ESC[0m13.11 13:52:32.880 >>> /exa/logs/db/DB1/20171113_133158_SqlProcess_8.0 ===> /exa/logs/db/DB1//20171113_135158_SqlSession_1583955331794950227.0 >>>
13.11 13:52:32.880 Main connection on this node. SID: 1583955331794950227
13.11 13:52:32.880 Waiting for packet..
13.11 13:52:32.880 Received packet: type: 12, serial: 7, nr_attr: 0, size: 21 [CC]
13.11 13:52:32.880 [CC] virtual bool ClientConnection::closeLastPreparedStatement(bool, bool, bool, bool): result_sent: FALSE, lastPreparedStatementHandle: -1
13.11 13:52:32.880 [CC] virtual void ClientConnection::execute(const Protocol::TExecute*)
13.11 13:52:32.881 [CC] virtual void ClientConnection::execute_sql(const char* const*, const size_t*, size_t, bool)
13.11 13:52:32.881 Process 8 created new transaction 199
13.11 13:52:32.884 [Compiler - profile] starting compilation for statement 1
Preparing parser for pluginlanguage: SCHEMA
13.11 13:52:32.886 [Compiler - SQL] create schema test2;

13.11 13:52:32.890 [Compiler - profile] finished compilation, total compile time: real(0.005992s) user(0.000000s) system(0.000000s) load(0.00)
13.11 13:52:32.898 Determined query resources for session_id=1583955331794950227, stmt_id=1, command_id=56, error_code=, nesting=0, duration=0.014000 sec, rows=0, res=100 %, cpu=37.600000 %, mem=8 MB, temp=0 MB, pers=0 MB, hdd_in=0 MB/s, hdd_out=0 MB/s, net=0 MB/s)
13.11 13:52:32.898 AUTOCOMMIT
13.11 13:52:32.899 Start commit of transaction 199
13.11 13:52:32.899 Start nonAtomarCommit
13.11 13:52:32.900 End nonAtomarCommit
13.11 13:52:32.912 End of commit of transaction 199
13.11 13:52:32.912 Determined query resources for session_id=1583955331794950227, stmt_id=2, command_id=44, error_code=, nesting=0, duration=0.013000 sec, rows=0, res= %, cpu=10.000000 %, mem=7 MB, temp=0 MB, pers=0 MB, hdd_in=0 MB/s, hdd_out=0 MB/s, net=0 MB/s)
13.11 13:52:32.914 Waiting for packet..
13.11 13:52:42.071 Received packet: type: 12, serial: 8, nr_attr: 0, size: 5 [CC]
13.11 13:52:42.071 [CC] virtual bool ClientConnection::closeLastPreparedStatement(bool, bool, bool, bool): result_sent: FALSE, lastPreparedStatementHandle: -1
13.11 13:52:42.071 [CC] virtual void ClientConnection::execute(const Protocol::TExecute*)
13.11 13:52:42.071 [CC] virtual void ClientConnection::execute_sql(const char* const*, const size_t*, size_t, bool)
13.11 13:52:42.071 Process 8 created new transaction 202
13.11 13:52:42.072 [Compiler - profile] starting compilation for statement 3
13.11 13:52:42.073 [Compiler - SQL] cr
;

13.11 13:52:42.073 ESC[33mError while SQL execution: Caught this exception: 42000:syntax error, unexpected ';', expecting assignment_operator or ':' [line 2, column 1]ESC[0m
13.11 13:52:42.073 virtual void SQL_API::StatementBasis::freeParameters(bool): exception_mode: TRUE
13.11 13:52:42.073 Determined query resources for session_id=1583955331794950227, stmt_id=3, command_id=0, error_code=42000, nesting=0, duration=0.001000 sec, rows=, res=98 %, cpu=83.200000 %, mem=7 MB, temp=0 MB, pers=0 MB, hdd_in=0 MB/s, hdd_out=0 MB/s, net=0 MB/s)
13.11 13:52:42.073 Start of rollback of transaction 202
13.11 13:52:42.074 End of rollback of transaction 202
13.11 13:52:42.074 Determined query resources for session_id=1583955331794950227, stmt_id=4, command_id=45, error_code=, nesting=0, duration=0.000000 sec, rows=0, res= %, cpu=59.300000 %, mem=7 MB, temp=0 MB, pers=0 MB, hdd_in=0 MB/s, hdd_out=0 MB/s, net=0 MB/s)
13.11 13:52:42.074 writeException: 42000 syntax error, unexpected ';', expecting assignment_operator or ':' [line 2, column 1] (Session: 1583955331794950227)
13.11 13:52:42.074 Waiting for packet..
13.11 13:53:17.642 Received packet: type: 12, serial: 9, nr_attr: 0, size: 181 [CC]
13.11 13:53:17.643 [CC] virtual bool ClientConnection::closeLastPreparedStatement(bool, bool, bool, bool): result_sent: FALSE, lastPreparedStatementHandle: -1
13.11 13:53:17.643 [CC] virtual void ClientConnection::execute(const Protocol::TExecute*)
13.11 13:53:17.643 [CC] virtual void ClientConnection::execute_sql(const char* const*, const size_t*, size_t, bool)
13.11 13:53:17.643 Process 8 created new transaction 209
13.11 13:53:17.644 [Compiler - profile] starting compilation for statement 5
Preparing parser for pluginlanguage: PYTHON
EVALUATE EXPRESSION SCRIPT (x int) ;
EVALUATE EXPRESSION SCRIPT ( FAKENAME int );
13.11 13:53:17.645 [Compiler - SQL] create or replace python scalar script t1(x int) returns int as
def run(c) (

;
;
ooke commented 6 years ago

@tjlee sorry, I do not see any problem. Could you please send me your public SSH key to ok@exasol.com, I will create an AWS instance and give you access to it and we will try to reproduce your problem there together, is it an acceptable plan for you?

tjlee commented 6 years ago

@ooke Hi, You can close the ticket. Possibly, I found the problem. I use boot-to-docker as OS to host EXASOL. I can't reproduce the problem on Ubuntu. Thank you.

tjlee commented 7 months ago

@ooke we face the issue again. Success rate is about 90% for the test and it fails with the same error java.sql.SQLException: VM error: Internal error: VM crashed (Session: 1788406532139843584)

image