tumblr / collins

groovy kind of love
tumblr.github.com/collins
Apache License 2.0
571 stars 99 forks source link

Race condition when doing parallelized asset intake / configuration #509

Open grahamc opened 7 years ago

grahamc commented 7 years ago

In a test environment, I have setup several test assets that I "intake" in parallel. This can produce stack traces and errors in provisioning:

Trace 1: Unique index or primary key violation **CLICK TO EXPAND** ``` 2017-02-01 15:58:52,793 - [WARN] - o.a.s.c.SolrCore - o.a.s.c.SolrCore:getSearcher:1761 - [collins] PERFORMANCE WARNING: Overlapping onDeckSearchers=2 2017-02-01 15:58:54,146 - [WARN] - application - c.m.AssetLifecycle:collins$models$AssetLifecycle$$handleException:303 - Error saving attributes for asset java.lang.RuntimeException: Exception while executing statement : Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 48)"; SQL statement: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] errorCode: 23505, sqlState: 23505 insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) jdbcParams:[SUFFIX,-1,1,SUFFIX,Suffix] at org.squeryl.internals.DatabaseAdapter$class._exec(DatabaseAdapter.scala:297) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] at org.squeryl.internals.DatabaseAdapter$class.exec(DatabaseAdapter.scala:349) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] at org.squeryl.adapters.H2Adapter.exec(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] at org.squeryl.internals.DatabaseAdapter$class.executeUpdateForInsert(DatabaseAdapter.scala:383) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] at org.squeryl.adapters.H2Adapter.executeUpdateForInsert(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] Caused by: org.h2.jdbc.JdbcSQLException: Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 48)"; SQL statement: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] at org.h2.message.DbException.getJdbcSQLException(DbException.java:345) ~[com.h2database.h2-1.4.188.jar:1.4.188] at org.h2.message.DbException.get(DbException.java:179) ~[com.h2database.h2-1.4.188.jar:1.4.188] at org.h2.message.DbException.get(DbException.java:155) ~[com.h2database.h2-1.4.188.jar:1.4.188] at org.h2.index.BaseIndex.getDuplicateKeyException(BaseIndex.java:102) ~[com.h2database.h2-1.4.188.jar:1.4.188] at org.h2.mvstore.db.MVSecondaryIndex.checkUnique(MVSecondaryIndex.java:231) ~[com.h2database.h2-1.4.188.jar:1.4.188] 2017-02-01 15:58:54,795 - [WARN] - o.a.s.c.SolrCore - o.a.s.c.SolrCore:getSearcher:1761 - [collins] PERFORMANCE WARNING: Overlapping onDeckSearchers=2 ```
Trace2: java.util.NoSuchElementException: None.get **CLICK TO EXPAND** ``` 2017-02-01 16:17:35,551 - [WARN] - application - c.m.AssetLifecycle:collins$models$AssetLifecycle$$handleException:303 - Error saving attributes for asset java.util.NoSuchElementException: None.get at scala.None$.get(Option.scala:347) ~[org.scala-lang.scala-library-2.11.7.jar:na] at scala.None$.get(Option.scala:345) ~[org.scala-lang.scala-library-2.11.7.jar:na] at collins.models.AssetMetaValue.meta$lzycompute(AssetMetaValue.scala:32) ~[collins.collins-2.0-SNAPSHOT.jar:2.0-SNAPSHOT] at collins.models.AssetMetaValue.meta(AssetMetaValue.scala:32) ~[collins.collins-2.0-SNAPSHOT.jar:2.0-SNAPSHOT] at collins.models.AssetMetaValue.(AssetMetaValue.scala:34) ~[collins.collins-2.0-SNAPSHOT.jar:2.0-SNAPSHOT] 2017-02-01 16:17:35,555 - [WARN] - application - c.m.AssetLifecycle:collins$models$AssetLifecycle$$handleException:303 - Error saving attributes for asset ```

~Interestingly, it doesn't seem to result in an error to the client but also does not correctly write the data to the database.~ (See first comment)

I am running the docker container with (mostly) standard / default configurations under systemd, and have 7 units (#s 10-16) looking like this:

[Unit]
After=collins.service container@mysql-container-13.service
BindsTo=collins.service
Description=Collins MySQL Node Intake: mysql-container-13
Wants=collins.service

[Service]
ExecStart=/path/to/collins-intake-mysql-container-13-start
Type=oneshot
#! /bin/bash -e

URL="http://localhost:9000/api/asset"
TAG="mysql-container-13"
LLDP_FILE="./single.lldp"
LSHW_FILE="./virident.lshw"

curl --basic -X PUT -H "Accept: text/plain" \
     -u blake:admin:first "$URL/$TAG"

curl --basic -H "Accept: text/plain" -u blake:admin:first \
     --data-urlencode "lldp@$LLDP_FILE" \
     --data-urlencode "lshw@$LSHW_FILE" \
     --data-urlencode 'CHASSIS_TAG=Testing this' \
     "$URL/$TAG"

collins modify -C "./collins-cli.yaml" -t "mysql-container-13" -S maintenance:maint_noop -r "Provisioning"
collins provision -C "./collins-cli.yaml" -t "mysql-container-13"  -n databasenode  -r DATABASE -b blake
collins modify -C "./collins-cli.yaml" -t "mysql-container-13" \
  -S Allocated:SPARE \
  -r "Provisioning" \
  -a "HOSTNAME:mysql-container-13"
curl --basic -u blake:admin:first -X POST \
  -d pool=DATABASE \
  -d address=10.50.2.13 \
  -d gateway=10.50.2.1 \
  -d netmask=255.255.255.0 \
  http://localhost:9000/api/asset/mysql-container-13/address

Unfortunately, since it doesn't seem to fail in the response, I'm not sure what step failed.

I was able to reproduce these issues in about 9 out of 10 test runs, and can share with you instructions on how to reproduce what I'm seeing (using tooling which is not public at this time.)

grahamc commented 7 years ago

Ok, so I crossed-out the part about not updating the database.

I've seen this happen at least once:

+ curl --basic -u blake:admin:first -X POST -d pool=DATABASE -d address=10.50.2.10 -d gateway=10.50.2.1 -d netmask=255.255.255.0 http://localhost:9000/api/asset/mysql-container-10/address
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
[158B blob data]
{"status":"error","data":{"message":"Unable to update address:  ...

(but didn't catch the http response code...)

but

sometimes it doesn't seem to - CLICK TO EXPAND This is a big log, but I believe it is showing errors corresponding to SUCCESSes... ``` Feb 01 17:47:39 nixos collins-intake-mysql-container-16-start[6090]: + collins modify -C /nix/store/diyzwylw4dv42362vysbks5av57pjh0b-collins-cli.yaml -t mysql-container-16 -S maintenance:maint_noop -r Provisioning Feb 01 17:47:40 nixos collins-intake-mysql-container-15-start[6096]: mysql-container-15 changing status to MAINTENANCE:MAINT_NOOP... SUCCESS Feb 01 17:47:40 nixos collins-intake-mysql-container-15-start[6096]: + collins provision -C /nix/store/diyzwylw4dv42362vysbks5av57pjh0b-collins-cli.yaml -t mysql-container-15 -n databasenode -r DATABASE -b blake Feb 01 17:47:40 nixos docker[5807]: 2017-02-01 17:47:40,437 - [WARN] - application - c.m.AssetLifecycle:collins$models$AssetLifecycle$$handleException:303 - Error saving attributes for asset Feb 01 17:47:40 nixos docker[5807]: java.lang.RuntimeException: Exception while executing statement : Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGN Feb 01 17:47:40 nixos docker[5807]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] Feb 01 17:47:40 nixos docker[5807]: errorCode: 23505, sqlState: 23505 Feb 01 17:47:40 nixos docker[5807]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) Feb 01 17:47:40 nixos docker[5807]: jdbcParams:[SUFFIX,-1,1,SUFFIX,Suffix] Feb 01 17:47:40 nixos docker[5807]: at org.squeryl.internals.DatabaseAdapter$class._exec(DatabaseAdapter.scala:297) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] Feb 01 17:47:40 nixos docker[5807]: at org.squeryl.internals.DatabaseAdapter$class.exec(DatabaseAdapter.scala:349) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] Feb 01 17:47:40 nixos docker[5807]: at org.squeryl.adapters.H2Adapter.exec(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] Feb 01 17:47:40 nixos docker[5807]: at org.squeryl.internals.DatabaseAdapter$class.executeUpdateForInsert(DatabaseAdapter.scala:383) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] Feb 01 17:47:40 nixos docker[5807]: at org.squeryl.adapters.H2Adapter.executeUpdateForInsert(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] Feb 01 17:47:40 nixos docker[5807]: Caused by: org.h2.jdbc.JdbcSQLException: Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 48)"; SQL state Feb 01 17:47:40 nixos docker[5807]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] Feb 01 17:47:40 nixos docker[5807]: at org.h2.message.DbException.getJdbcSQLException(DbException.java:345) ~[com.h2database.h2-1.4.188.jar:1.4.188] Feb 01 17:47:40 nixos docker[5807]: at org.h2.message.DbException.get(DbException.java:179) ~[com.h2database.h2-1.4.188.jar:1.4.188] Feb 01 17:47:40 nixos docker[5807]: at org.h2.message.DbException.get(DbException.java:155) ~[com.h2database.h2-1.4.188.jar:1.4.188] Feb 01 17:47:40 nixos docker[5807]: at org.h2.index.BaseIndex.getDuplicateKeyException(BaseIndex.java:102) ~[com.h2database.h2-1.4.188.jar:1.4.188] Feb 01 17:47:40 nixos dockerd[883]: 2017-02-01 17:47:40,437 - [WARN] - application - c.m.AssetLifecycle:collins$models$AssetLifecycle$$handleException:303 - Error saving attributes for asset Feb 01 17:47:40 nixos docker[5807]: at org.h2.mvstore.db.MVSecondaryIndex.checkUnique(MVSecondaryIndex.java:231) ~[com.h2database.h2-1.4.188.jar:1.4.188] Feb 01 17:47:40 nixos dockerd[883]: java.lang.RuntimeException: Exception while executing statement : Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGN Feb 01 17:47:40 nixos dockerd[883]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] Feb 01 17:47:40 nixos dockerd[883]: errorCode: 23505, sqlState: 23505 Feb 01 17:47:40 nixos dockerd[883]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) Feb 01 17:47:40 nixos dockerd[883]: jdbcParams:[SUFFIX,-1,1,SUFFIX,Suffix] Feb 01 17:47:40 nixos dockerd[883]: at org.squeryl.internals.DatabaseAdapter$class._exec(DatabaseAdapter.scala:297) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] Feb 01 17:47:40 nixos dockerd[883]: at org.squeryl.internals.DatabaseAdapter$class.exec(DatabaseAdapter.scala:349) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] Feb 01 17:47:40 nixos dockerd[883]: at org.squeryl.adapters.H2Adapter.exec(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] Feb 01 17:47:40 nixos dockerd[883]: at org.squeryl.internals.DatabaseAdapter$class.executeUpdateForInsert(DatabaseAdapter.scala:383) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] Feb 01 17:47:40 nixos dockerd[883]: at org.squeryl.adapters.H2Adapter.executeUpdateForInsert(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] Feb 01 17:47:40 nixos dockerd[883]: Caused by: org.h2.jdbc.JdbcSQLException: Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 48)"; SQL state Feb 01 17:47:40 nixos dockerd[883]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] Feb 01 17:47:40 nixos dockerd[883]: at org.h2.message.DbException.getJdbcSQLException(DbException.java:345) ~[com.h2database.h2-1.4.188.jar:1.4.188] Feb 01 17:47:40 nixos dockerd[883]: at org.h2.message.DbException.get(DbException.java:179) ~[com.h2database.h2-1.4.188.jar:1.4.188] Feb 01 17:47:40 nixos dockerd[883]: at org.h2.message.DbException.get(DbException.java:155) ~[com.h2database.h2-1.4.188.jar:1.4.188] Feb 01 17:47:40 nixos dockerd[883]: at org.h2.index.BaseIndex.getDuplicateKeyException(BaseIndex.java:102) ~[com.h2database.h2-1.4.188.jar:1.4.188] Feb 01 17:47:40 nixos dockerd[883]: at org.h2.mvstore.db.MVSecondaryIndex.checkUnique(MVSecondaryIndex.java:231) ~[com.h2database.h2-1.4.188.jar:1.4.188] Feb 01 17:47:40 nixos collins-intake-mysql-container-14-start[6097]: mysql-container-14 provisioning with nodeclass:databasenode primary_role:DATABASE by blake... SUCCESS Feb 01 17:47:40 nixos collins-intake-mysql-container-14-start[6097]: + collins modify -C /nix/store/diyzwylw4dv42362vysbks5av57pjh0b-collins-cli.yaml -t mysql-container-14 -S Allocated:SPARE -r Provisioning -a HOSTNAME:mysql-conta Feb 01 17:47:40 nixos collins-intake-mysql-container-11-start[6088]: mysql-container-11 changing status to MAINTENANCE:MAINT_NOOP... SUCCESS Feb 01 17:47:40 nixos collins-intake-mysql-container-10-start[6095]: mysql-container-10 provisioning with nodeclass:databasenode primary_role:DATABASE by blake... SUCCESS Feb 01 17:47:40 nixos collins-intake-mysql-container-11-start[6088]: + collins provision -C /nix/store/diyzwylw4dv42362vysbks5av57pjh0b-collins-cli.yaml -t mysql-container-11 -n databasenode -r DATABASE -b blake ```
byxorna commented 7 years ago

@grahamc have you only been able to repro using the built-in H2 database, or with mysql as well?

grahamc commented 7 years ago

I have also reproduced with mysql.

byxorna commented 7 years ago

I'll need to allocate time to dig into the root cause here. Thanks for the report!

grahamc commented 7 years ago

Sounds good. Let me know if I can help, likely soon I'll be able to open source the code used to cause the issue in the first place.

yl3w commented 7 years ago

need to add transactional reads when verifying that a meta attribute exists

https://github.com/tumblr/collins/blob/master/conf/evolutions/collins/1.sql#L32

But this shouldn't be an issue in practice. Collins does create meta fields when they don't exist during asset creation. In practice this happens rarely. If you create an initial asset so that meta fields are created and then run any number in intakes at the same time, it won't be an issue.

I'd go to the extent of suggesting that this be considered a known issue, or implemented via a flag, blocking asset intake on account of validating asset meta existence has implication beyond the cases when asset meta needs to be created.

grahamc commented 7 years ago

@maddalab does it need to be any asset, or a server asset in particular?

grahamc commented 7 years ago

Hmm... @maddalab I gave it a try, loading in a server nearly identical to the rest of my assets, then once that finished doing parallel intake of many servers. However, I still found the problem.

Here is the script I'm running prior to intake:

URL="http://localhost:9000/api/asset"
TAG="bogus-server"
LLDP_FILE="single.lldp"
LSHW_FILE="virident.lshw"

curl --basic -X PUT -H "Accept: text/plain" \
     -u blake:admin:first "$URL/$TAG"

curl --basic -H "Accept: text/plain" -u blake:admin:first \
     --data-urlencode "lldp@$LLDP_FILE" \
     --data-urlencode "lshw@$LSHW_FILE" \
     --data-urlencode 'CHASSIS_TAG=bogus-server' \
     "$URL/$TAG"

and then I run this for several nodes simultaneously (this is for #12, but I run this for 10, 11, and 12 in this case):

URL="http://localhost:9000/api/asset"
TAG="mysql-container-12"
LLDP_FILE="single.lldp"
LSHW_FILE="virident.lshw"

curl --basic -X PUT -H "Accept: text/plain" \
     -u blake:admin:first "$URL/$TAG"

curl --basic -H "Accept: text/plain" -u blake:admin:first \
     --data-urlencode "lldp@$LLDP_FILE" \
     --data-urlencode "lshw@$LSHW_FILE" \
     --data-urlencode 'CHASSIS_TAG=Testing this' \
     "$URL/$TAG"

collins modify -C "collins-cli.yaml" -t "mysql-container-12" -S maintenance:maint_noop -r "Provisioning"
collins provision -C "collins-cli.yaml" -t "mysql-container-12"  -n databasenode  -r DATABASE -b blake
collins modify -C "collins-cli.yaml" -t "mysql-container-12" \
  -S Allocated:SPARE \
  -r "Provisioning" \
  -a "HOSTNAME:mysql-container-12"
curl --basic -u blake:admin:first -X POST \
  -d pool=DATABASE \
  -d address=10.50.2.12 \
  -d gateway=10.50.2.1 \
  -d netmask=255.255.255.0 \
  http://localhost:9000/api/asset/mysql-container-12/address

should this have fixed it? Here is the log, continuing to demonstrate the problem:

CLICK TO EXPAND ``` machine# [ 52.138779] systemd[1]: Starting Create a bogus collins asset to prepare the mysql asset columns... machine# [ 52.175784] docker[3094]: 2017-06-02 14:44:11,953 - [WARN] - o.a.s.c.SolrCore - o.a.s.c.SolrCore:getSearcher:1761 - [collins] PERFORMANCE WARNING: Overlapping onDeckSearchers=2 machine# [ 52.176781] dockerd[1015]: 2017-06-02 14:44:11,953 - [WARN] - o.a.s.c.SolrCore - o.a.s.c.SolrCore:getSearcher:1761 - [collins] PERFORMANCE WARNING: Overlapping onDeckSearchers=2 machine# [ 52.183327] collins-stub-asset-for-meta-columns-start[3433]: % Total % Received % Xferd Average Speed Time Time Time Current machine# [ 52.184106] collins-stub-asset-for-meta-columns-start[3433]: Dload Upload Total Spent Left Speed machine: running command: systemctl --no-pager show 'default.target' machine: exit status 0 machine: running command: systemctl list-jobs --full 2>&1 machine# [ 52.272428] dockerd[1015]: 2017-06-02 14:44:12,049 - [WARN] - SolrPlugin - p.a.LoggerLike$class:warn:112 - No items to index! machine# [ 52.273177] docker[3094]: 2017-06-02 14:44:12,049 - [WARN] - SolrPlugin - p.a.LoggerLike$class:warn:112 - No items to index! machine: exit status 0 100 318 100 318 0 0 2350 0 --:--:-- --:--:-- --:--:-- 2373 machine# [ 52.317820] collins-stub-asset-for-meta-columns-start[3433]: ASSET machine# [ 52.318467] collins-stub-asset-for-meta-columns-start[3433]: ID 4 machine# [ 52.318829] collins-stub-asset-for-meta-columns-start[3433]: CREATED 2017-06-02T14:44:11 machine# [ 52.319310] collins-stub-asset-for-meta-columns-start[3433]: TAG bogus-server machine# [ 52.319687] collins-stub-asset-for-meta-columns-start[3433]: STATUS Incomplete machine# [ 52.320096] collins-stub-asset-for-meta-columns-start[3433]: DELETED null machine# [ 52.320534] collins-stub-asset-for-meta-columns-start[3433]: UPDATED null machine# [ 52.320850] collins-stub-asset-for-meta-columns-start[3433]: STATE null machine# [ 52.321364] collins-stub-asset-for-meta-columns-start[3433]: TYPE SERVER_NODE machine# [ 52.321690] collins-stub-asset-for-meta-columns-start[3433]: IPMI machine# [ 52.322117] collins-stub-asset-for-meta-columns-start[3433]: IPMI_USERNAME root machine# [ 52.322587] collins-stub-asset-for-meta-columns-start[3433]: ID 2 machine# [ 52.322956] collins-stub-asset-for-meta-columns-start[3433]: IPMI_ADDRESS 172.16.32.20 machine# [ 52.323465] collins-stub-asset-for-meta-columns-start[3433]: IPMI_NETMASK 255.255.240.0 machine# [ 52.323793] collins-stub-asset-for-meta-columns-start[3433]: ASSET_ID 4 machine# [ 52.324217] collins-stub-asset-for-meta-columns-start[3433]: ASSET_TAG bogus-server machine# [ 52.324591] collins-stub-asset-for-meta-columns-start[3433]: IPMI_GATEWAY 172.16.32.1 machine# [ 52.324934] collins-stub-asset-for-meta-columns-start[3433]: IPMI_PASSWORD 4Ec2rHwPQiZYUl96 machine# [ 52.353222] collins-stub-asset-for-meta-columns-start[3433]: % Total % Received % Xferd Average Speed Time Time Time Current machine# [ 52.353559] collins-stub-asset-for-meta-columns-start[3433]: Dload Upload Total Spent Left Speed 100 100k 100 13 100 100k 36 280k --:--:-- --:--:-- --:--:-- 281k machine# [ 52.711394] collins-stub-asset-for-meta-columns-start[3433]: SUCCESS true machine# [ 52.719450] systemd[1]: Started Create a bogus collins asset to prepare the mysql asset columns. machine# [ 52.723006] systemd[1]: Starting Collins MySQL Node Intake: mysql-container-11... machine# [ 52.724609] systemd[1]: Starting Collins MySQL Node Intake: mysql-container-10... machine# [ 52.726539] systemd[1]: Starting Collins MySQL Node Intake: mysql-container-12... machine# [ 52.764774] collins-intake-mysql-container-11-start[3461]: % Total % Received % Xferd Average Speed Time Time Time Current machine# [ 52.765401] collins-intake-mysql-container-11-start[3461]: Dload Upload Total Spent Left Speed machine# [ 52.775092] collins-intake-mysql-container-12-start[3467]: % Total % Received % Xferd Average Speed Time Time Time Current machine# [ 52.775638] collins-intake-mysql-container-10-start[3463]: % Total % Received % Xferd Average Speed Time Time Time Current machine# [ 52.776271] collins-intake-mysql-container-10-start[3463]: Dload Upload Total Spent Left Speed machine# [ 52.779925] collins-intake-mysql-container-12-start[3467]: Dload Upload Total Spent Left Speed 100 330 100 330 0 0 2826 0 --:--:-- --:--:-- --:--:-- 2844 machine# [ 52.881306] collins-intake-mysql-container-11-start[3461]: ASSET machine# [ 52.881867] collins-intake-mysql-container-11-start[3461]: ID 5 machine# [ 52.882449] collins-intake-mysql-container-11-start[3461]: CREATED 2017-06-02T14:44:12 machine# [ 52.882809] collins-intake-mysql-container-11-start[3461]: TAG mysql-container-11 machine# [ 52.883374] collins-intake-mysql-container-11-start[3461]: STATUS Incomplete machine# [ 52.883731] collins-intake-mysql-container-11-start[3461]: DELETED null machine# [ 52.884149] collins-intake-mysql-container-11-start[3461]: UPDATED null machine# [ 52.884581] collins-intake-mysql-container-11-start[3461]: STATE null machine# [ 52.884935] collins-intake-mysql-container-11-start[3461]: TYPE SERVER_NODE machine# [ 52.885505] collins-intake-mysql-container-11-start[3461]: IPMI machine# [ 52.885863] collins-intake-mysql-container-11-start[3461]: IPMI_USERNAME root machine# [ 52.886488] collins-intake-mysql-container-11-start[3461]: ID 3 machine# [ 52.886898] collins-intake-mysql-container-11-start[3461]: IPMI_ADDRESS 172.16.32.21 machine# [ 52.887430] collins-intake-mysql-container-11-start[3461]: IPMI_NETMASK 255.255.240.0 machine# [ 52.887777] collins-intake-mysql-container-11-start[3461]: ASSET_ID 5 machine# [ 52.888170] collins-intake-mysql-container-11-start[3461]: ASSET_TAG mysql-container-11 machine# [ 52.888540] collins-intake-mysql-container-11-start[3461]: IPMI_GATEWAY 172.16.32.1 machine# [ 52.888910] collins-intake-mysql-container-11-start[3461]: IPMI_PASSWORD lKKOqFYgCxYogzUA machine# [ 52.907441] dockerd[1015]: 2017-06-02 14:44:12,684 - [WARN] - o.a.s.c.SolrCore - o.a.s.c.SolrCore:getSearcher:1761 - [collins] PERFORMANCE WARNING: Overlapping onDeckSearchers=2 machine# [ 52.907962] docker[3094]: 2017-06-02 14:44:12,684 - [WARN] - o.a.s.c.SolrCore - o.a.s.c.SolrCore:getSearcher:1761 - [collins] PERFORMANCE WARNING: Overlapping onDeckSearchers=2 machine# [ 52.922601] docker[3094]: 2017-06-02 14:44:12,700 - [WARN] - o.a.s.c.SolrCore - o.a.s.c.SolrCore:getSearcher:1761 - [collins] PERFORMANCE WARNING: Overlapping onDeckSearchers=2 machine# [ 52.923251] dockerd[1015]: 2017-06-02 14:44:12,700 - [WARN] - o.a.s.c.SolrCore - o.a.s.c.SolrCore:getSearcher:1761 - [collins] PERFORMANCE WARNING: Overlapping onDeckSearchers=2 machine# [ 52.926890] collins-intake-mysql-container-11-start[3461]: % Total % Received % Xferd Average Speed Time Time Time Current machine# [ 52.927498] collins-intake-mysql-container-11-start[3461]: Dload Upload Total Spent Left Speed 100 331 100 331 0 0 2071 0 --:--:-- --:--:-- --:--:-- 2081 machine# [ 52.934691] collins-intake-mysql-container-12-start[3467]: ASSET machine# [ 52.935674] collins-intake-mysql-container-12-start[3467]: ID 7 machine# [ 52.936462] collins-intake-mysql-container-12-start[3467]: CREATED 2017-06-02T14:44:12 machine# [ 52.937210] collins-intake-mysql-container-12-start[3467]: TAG mysql-container-12 machine# [ 52.937805] collins-intake-mysql-container-12-start[3467]: STATUS Incomplete machine# [ 52.938546] collins-intake-mysql-container-12-start[3467]: DELETED null machine# [ 52.939199] collins-intake-mysql-container-12-start[3467]: UPDATED null machine# [ 52.939832] collins-intake-mysql-container-12-start[3467]: STATE null machine# [ 52.940615] collins-intake-mysql-container-12-start[3467]: TYPE SERVER_NODE machine# [ 52.941251] collins-intake-mysql-container-12-start[3467]: IPMI machine# [ 52.941694] collins-intake-mysql-container-12-start[3467]: IPMI_USERNAME root machine# [ 52.942497] collins-intake-mysql-container-12-start[3467]: ID 16 machine# [ 52.943106] collins-intake-mysql-container-12-start[3467]: IPMI_ADDRESS 172.16.32.22 machine# [ 52.943649] collins-intake-mysql-container-12-start[3467]: IPMI_NETMASK 255.255.240.0 machine# [ 52.944247] collins-intake-mysql-container-12-start[3467]: ASSET_ID 7 machine# [ 52.944807] collins-intake-mysql-container-12-start[3467]: ASSET_TAG mysql-container-12 machine# [ 52.945511] collins-intake-mysql-container-12-start[3467]: IPMI_GATEWAY 172.16.32.1 machine# [ 52.946258] collins-intake-mysql-container-12-start[3467]: IPMI_PASSWORD WQ0RlMHz4zSuQDK7 machine# [ 52.972447] collins-intake-mysql-container-12-start[3467]: % Total % Received % Xferd Average Speed Time Time Time Current machine# [ 52.972856] collins-intake-mysql-container-12-start[3467]: Dload Upload Total Spent Left Speed machine# [ 52.985998] docker[3094]: 2017-06-02 14:44:12,763 - [WARN] - o.a.s.c.SolrCore - o.a.s.c.SolrCore:getSearcher:1761 - [collins] PERFORMANCE WARNING: Overlapping onDeckSearchers=2 machine# [ 52.986529] dockerd[1015]: 2017-06-02 14:44:12,763 - [WARN] - o.a.s.c.SolrCore - o.a.s.c.SolrCore:getSearcher:1761 - [collins] PERFORMANCE WARNING: Overlapping onDeckSearchers=2 100 331 100 331 0 0 1502 0 --:--:-- --:--:-- --:--:-- 1511 machine# [ 52.995401] collins-intake-mysql-container-10-start[3463]: ASSET machine# [ 52.995774] collins-intake-mysql-container-10-start[3463]: ID 6 machine# [ 52.996182] collins-intake-mysql-container-10-start[3463]: CREATED 2017-06-02T14:44:12 machine# [ 52.996544] collins-intake-mysql-container-10-start[3463]: TAG mysql-container-10 machine# [ 52.996863] collins-intake-mysql-container-10-start[3463]: STATUS Incomplete machine# [ 52.997462] collins-intake-mysql-container-10-start[3463]: DELETED null machine# [ 52.997848] collins-intake-mysql-container-10-start[3463]: UPDATED null machine# [ 52.998225] collins-intake-mysql-container-10-start[3463]: STATE null machine# [ 52.998622] collins-intake-mysql-container-10-start[3463]: TYPE SERVER_NODE machine# [ 52.999106] collins-intake-mysql-container-10-start[3463]: IPMI machine# [ 52.999518] collins-intake-mysql-container-10-start[3463]: IPMI_USERNAME root machine# [ 52.999904] collins-intake-mysql-container-10-start[3463]: ID 29 machine# [ 53.000385] collins-intake-mysql-container-10-start[3463]: IPMI_ADDRESS 172.16.32.23 machine# [ 53.000732] collins-intake-mysql-container-10-start[3463]: IPMI_NETMASK 255.255.240.0 machine# [ 53.001143] collins-intake-mysql-container-10-start[3463]: ASSET_ID 6 machine# [ 53.001470] collins-intake-mysql-container-10-start[3463]: ASSET_TAG mysql-container-10 machine# [ 53.001806] collins-intake-mysql-container-10-start[3463]: IPMI_GATEWAY 172.16.32.1 machine# [ 53.002227] collins-intake-mysql-container-10-start[3463]: IPMI_PASSWORD oUNsNMARrdwCHL7Z machine# [ 53.027608] collins-intake-mysql-container-10-start[3463]: % Total % Received % Xferd Average Speed Time Time Time Current machine# [ 53.027953] collins-intake-mysql-container-10-start[3463]: Dload Upload Total Spent Left Speed 100 100k 100 13 100 100k 66 517k --:--:-- --:--:-- --:--:-- 524k machine# [ 53.118884] collins-intake-mysql-container-11-start[3461]: SUCCESS true 100 100k 100 13 100 100k 86 669k --:--:-- --:--:-- --:--:-- 671k machine# [ 53.122888] collins-intake-mysql-container-12-start[3467]: SUCCESS true 100 100k 100 13 100 100k 86 666k --:--:-- --:--:-- --:--:-- 671k machine# [ 53.178562] collins-intake-mysql-container-10-start[3463]: SUCCESS true machine: running command: systemctl --no-pager show 'default.target' machine: exit status 0 machine: running command: systemctl list-jobs --full 2>&1 machine: exit status 0 machine# [ 53.639273] dhcpcd[1499]: docker0: no IPv6 Routers available machine# [ 54.064923] collins-intake-mysql-container-11-start[3461]: mysql-container-11 changing status to MAINTENANCE:MAINT_NOOP... SUCCESS machine# [ 54.082840] dhcpcd[1499]: veth926ea7b: no IPv6 Routers available machine# [ 54.107957] collins-intake-mysql-container-12-start[3467]: mysql-container-12 changing status to MAINTENANCE:MAINT_NOOP... SUCCESS machine# [ 54.176486] collins-intake-mysql-container-10-start[3463]: mysql-container-10 changing status to MAINTENANCE:MAINT_NOOP... SUCCESS machine: running command: systemctl --no-pager show 'default.target' machine: exit status 0 machine: running command: systemctl list-jobs --full 2>&1 machine: exit status 0 machine# [ 55.130286] docker[3094]: 2017-06-02 14:44:14,907 - [WARN] - application - c.m.AssetLifecycle:collins$models$AssetLifecycle$$handleException:308 - Error saving attributes for asset machine# [ 55.132341] docker[3094]: java.lang.RuntimeException: Exception while executing statement : Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 50)"; SQL statement: machine# [ 55.133000] docker[3094]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] machine# [ 55.133702] docker[3094]: errorCode: 23505, sqlState: 23505 machine# [ 55.134120] docker[3094]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) machine# [ 55.134680] docker[3094]: jdbcParams:[SUFFIX,-1,1,SUFFIX,Suffix] machine# [ 55.135310] docker[3094]: at org.squeryl.internals.DatabaseAdapter$class._exec(DatabaseAdapter.scala:297) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.135767] docker[3094]: at org.squeryl.internals.DatabaseAdapter$class.exec(DatabaseAdapter.scala:349) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.136492] docker[3094]: at org.squeryl.adapters.H2Adapter.exec(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.136995] docker[3094]: at org.squeryl.internals.DatabaseAdapter$class.executeUpdateForInsert(DatabaseAdapter.scala:383) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.137544] docker[3094]: at org.squeryl.adapters.H2Adapter.executeUpdateForInsert(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.138087] docker[3094]: Caused by: org.h2.jdbc.JdbcSQLException: Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 50)"; SQL statement: machine# [ 55.138680] docker[3094]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] machine# [ 55.139115] docker[3094]: at org.h2.message.DbException.getJdbcSQLException(DbException.java:345) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.139599] docker[3094]: at org.h2.message.DbException.get(DbException.java:179) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.140244] docker[3094]: at org.h2.message.DbException.get(DbException.java:155) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.140676] docker[3094]: at org.h2.index.BaseIndex.getDuplicateKeyException(BaseIndex.java:102) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.141362] docker[3094]: at org.h2.mvstore.db.MVSecondaryIndex.checkUnique(MVSecondaryIndex.java:231) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.141816] docker[3094]: 2017-06-02 14:44:14,907 - [WARN] - application - c.m.AssetLifecycle:collins$models$AssetLifecycle$$handleException:308 - Error saving attributes for asset machine# [ 55.142477] docker[3094]: java.lang.RuntimeException: Exception while executing statement : Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 50)"; SQL statement: machine# [ 55.143151] docker[3094]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] machine# [ 55.143447] docker[3094]: errorCode: 23505, sqlState: 23505 machine# [ 55.143806] docker[3094]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) machine# [ 55.144476] docker[3094]: jdbcParams:[SUFFIX,-1,1,SUFFIX,Suffix] machine# [ 55.144987] docker[3094]: at org.squeryl.internals.DatabaseAdapter$class._exec(DatabaseAdapter.scala:297) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.145519] docker[3094]: at org.squeryl.internals.DatabaseAdapter$class.exec(DatabaseAdapter.scala:349) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.146169] docker[3094]: at org.squeryl.adapters.H2Adapter.exec(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.146694] docker[3094]: at org.squeryl.internals.DatabaseAdapter$class.executeUpdateForInsert(DatabaseAdapter.scala:383) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.147289] docker[3094]: at org.squeryl.adapters.H2Adapter.executeUpdateForInsert(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.147729] docker[3094]: Caused by: org.h2.jdbc.JdbcSQLException: Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 50)"; SQL statement: machine# [ 55.148252] docker[3094]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] machine# [ 55.148523] docker[3094]: at org.h2.message.DbException.getJdbcSQLException(DbException.java:345) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.148950] docker[3094]: at org.h2.message.DbException.get(DbException.java:179) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.149481] docker[3094]: at org.h2.message.DbException.get(DbException.java:155) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.150169] dockerd[1015]: 2017-06-02 14:44:14,907 - [WARN] - application - c.m.AssetLifecycle:collins$models$AssetLifecycle$$handleException:308 - Error saving attributes for asset machine# [ 55.150628] docker[3094]: at org.h2.index.BaseIndex.getDuplicateKeyException(BaseIndex.java:102) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.151179] docker[3094]: at org.h2.mvstore.db.MVSecondaryIndex.checkUnique(MVSecondaryIndex.java:231) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.151650] dockerd[1015]: java.lang.RuntimeException: Exception while executing statement : Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 50)"; SQL statement: machine# [ 55.152281] dockerd[1015]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] machine# [ 55.152812] dockerd[1015]: errorCode: 23505, sqlState: 23505 machine# [ 55.153631] dockerd[1015]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) machine# [ 55.153983] dockerd[1015]: jdbcParams:[SUFFIX,-1,1,SUFFIX,Suffix] machine# [ 55.154667] dockerd[1015]: at org.squeryl.internals.DatabaseAdapter$class._exec(DatabaseAdapter.scala:297) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.182218] dockerd[1015]: at org.squeryl.internals.DatabaseAdapter$class.exec(DatabaseAdapter.scala:349) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.182756] dockerd[1015]: at org.squeryl.adapters.H2Adapter.exec(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.183295] dockerd[1015]: at org.squeryl.internals.DatabaseAdapter$class.executeUpdateForInsert(DatabaseAdapter.scala:383) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.183870] dockerd[1015]: at org.squeryl.adapters.H2Adapter.executeUpdateForInsert(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.184558] dockerd[1015]: Caused by: org.h2.jdbc.JdbcSQLException: Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 50)"; SQL statement: machine# [ 55.185174] dockerd[1015]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] machine# [ 55.185744] dockerd[1015]: at org.h2.message.DbException.getJdbcSQLException(DbException.java:345) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.186543] dockerd[1015]: at org.h2.message.DbException.get(DbException.java:179) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.187160] dockerd[1015]: at org.h2.message.DbException.get(DbException.java:155) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.187702] dockerd[1015]: at org.h2.index.BaseIndex.getDuplicateKeyException(BaseIndex.java:102) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.188059] dockerd[1015]: at org.h2.mvstore.db.MVSecondaryIndex.checkUnique(MVSecondaryIndex.java:231) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.188653] dockerd[1015]: 2017-06-02 14:44:14,907 - [WARN] - application - c.m.AssetLifecycle:collins$models$AssetLifecycle$$handleException:308 - Error saving attributes for asset machine# [ 55.188989[ 55.742094] serial8250: too much work for irq4 machine# ] dockerd[1015]: java.lang.RuntimeException: Exception while executing statement : Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 50)"; SQL statement: machine# [ 55.189636] dockerd[1015]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] machine# [ 55.190032] dockerd[1015]: errorCode: 23505, sqlState: 23505 machine# [ 55.190663] dockerd[1015]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) machine# [ 55.191257] dockerd[1015]: jdbcParams:[SUFFIX,-1,1,SUFFIX,Suffix] machine# [ 55.191815] dockerd[1015]: at org.squeryl.internals.DatabaseAdapter$class._exec(DatabaseAdapter.scala:297) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.192294] dockerd[1015]: at org.squeryl.internals.DatabaseAdapter$class.exec(DatabaseAdapter.scala:349) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.192618] dockerd[1015]: at org.squeryl.adapters.H2Adapter.exec(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.193165] dockerd[1015]: at org.squeryl.internals.DatabaseAdapter$class.executeUpdateForInsert(DatabaseAdapter.scala:383) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.193701] dockerd[1015]: at org.squeryl.adapters.H2Adapter.executeUpdateForInsert(H2Adapter.scala:22) ~[org.squeryl.squeryl_2.11-0.9.5-7.jar:0.9.5-7] machine# [ 55.194346] dockerd[1015]: Caused by: org.h2.jdbc.JdbcSQLException: Unique index or primary key violation: "CONSTRAINT_9D9B1_INDEX_F ON PUBLIC.ASSET_META(NAME) VALUES (CAST('SUFFIX' AS VARCHAR_IGNORECASE), 50)"; SQL statement: machine# [ 55.194650] dockerd[1015]: insert into asset_meta (name, priority, value_type, description, label) values (?,?,?,?,?) [23505-188] machine# [ 55.195062] dockerd[1015]: at org.h2.message.DbException.getJdbcSQLException(DbException.java:345) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.195331] dockerd[1015]: at org.h2.message.DbException.get(DbException.java:179) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.195746] dockerd[1015]: at org.h2.message.DbException.get(DbException.java:155) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.196338] dockerd[1015]: at org.h2.index.BaseIndex.getDuplicateKeyException(BaseIndex.java:102) ~[com.h2database.h2-1.4.188.jar:1.4.188] machine# [ 55.196682] dockerd[1015]: at org.h2.mvstore.db.MVSecondaryIndex.checkUnique(MVSecondaryIndex.java:231) ~[com.h2database.h2-1.4.188.jar:1.4.188] ```