NetXMS Support Forum

English Support => General Support => Topic started by: jermudgeon on October 02, 2019, 01:54:47 AM

Title: 3.0.2284 and TimescaleDB view 'idata'
Post by: jermudgeon on October 02, 2019, 01:54:47 AM
Upgraded to 3.0.2284 and ran database upgrade script. DCIs migrated successfully.

Database performance seems much worse:

2019.10.01 14:46:11.901 *E* [db.driver          ] SQL query failed (Query = "SELECT idata_value,idata_timestamp FROM idata WHERE item_id=233275 ORDER BY idata_timestamp DESC LIMIT 1"): Internal error (call to PQsendQuery failed)
2019.10.01 14:46:11.901 *E* [db.driver          ] SQL query failed (Query = "SELECT idata_value,idata_timestamp FROM idata WHERE item_id=233276 ORDER BY idata_timestamp DESC LIMIT 1"): Internal error (call to PQsendQuery failed)

Graphs load slowly, etc.

Running 'explain select' on the above failed queries result in:

Limit  (cost=2080.96..2082.61 rows=1 width=14) (actual time=19.277..20.802 rows=1 loops=1)
  ->  Merge Append  (cost=2080.96..31743.08 rows=18037 width=14) (actual time=19.128..19.128 rows=1 loops=1)
        Sort Key: _hyper_7_5752_chunk.idata_timestamp DESC
        ->  Index Scan Backward using "5752_5752_idata_sc_default_pkey" on _hyper_7_5752_chunk  (cost=0.29..13.67 rows=11 width=8) (actual time=0.012..0.012 rows=0 loops=1)
              Index Cond: (item_id = 233258)
        ->  Index Scan Backward using "5755_5755_idata_sc_default_pkey" on _hyper_7_5755_chunk  (cost=0.29..13.67 rows=11 width=8) (actual time=0.004..0.004 rows=0 loops=1)
              Index Cond: (item_id = 233258)

and continuing on with index scan backward.

Note that running similar queries on the individual hypertables that make up the idata view are VERY fast.
Title: Re: 3.0.2284 and TimescaleDB view 'idata'
Post by: Victor Kirhenshtein on October 02, 2019, 01:28:46 PM
Hi,

could you please post full explains for same queries run on idata and on idata_sc_default?

Best regards,
Victor
Title: Re: 3.0.2284 and TimescaleDB view 'idata'
Post by: jermudgeon on October 02, 2019, 05:44:44 PM
Here are full EXPLAIN queries.

Title: Re: 3.0.2284 and TimescaleDB view 'idata'
Post by: jermudgeon on October 03, 2019, 12:07:50 AM
FWIW, this may be related to what appears to be a DOS re: the database itself in netxms:

2019.10.02 13:06:24.280 *D* [db.cpool           ] Database connection pool exhausted (call from dcitem.cpp:1
511)                                                                                                        2019.10.02 13:06:24.280 *D* [db.cpool           ] Database connection pool exhausted (call from devdb.cpp:30


Pool minimum is 20.
Title: Re: 3.0.2284 and TimescaleDB view 'idata'
Post by: jermudgeon on October 03, 2019, 12:10:26 AM
And while we're at it, there are some bogus queries in the query log:
2019-10-02 13:07:00.206 AKDT [28100] netxms@netxmsts ERROR:  cannot insert into view "tdata"
2019-10-02 13:07:00.206 AKDT [28100] netxms@netxmsts DETAIL:  Views containing UNION, INTERSECT, or EXCEPT are not automatically updatable.
2019-10-02 13:07:00.206 AKDT [28100] netxms@netxmsts HINT:  To enable inserting into the view, provide an INSTEAD OF INSERT trigger or an unconditional ON INSERT DO INSTEAD rule.
2019-10-02 13:07:00.206 AKDT [28100] netxms@netxmsts STATEMENT:  INSERT INTO tdata (item_id,tdata_timestamp,tdata_value) VALUES ($1,$2,$3)
2019-10-02 13:07:25.950 AKDT [28102] netxms@netxmsts ERROR:  cannot insert into view "tdata"
2019-10-02 13:07:25.950 AKDT [28102] netxms@netxmsts DETAIL:  Views containing UNION, INTERSECT, or EXCEPT are not automatically updatable.
2019-10-02 13:07:25.950 AKDT [28102] netxms@netxmsts HINT:  To enable inserting into the view, provide an INSTEAD OF INSERT trigger or an unconditional ON INSERT DO INSTEAD rule.
2019-10-02 13:07:25.950 AKDT [28102] netxms@netxmsts STATEMENT:  INSERT INTO tdata (item_id,tdata_timestamp,tdata_value) VALUES ($1,$2,$3)
Title: Re: 3.0.2284 and TimescaleDB view 'idata'
Post by: jermudgeon on October 03, 2019, 12:16:20 AM
I believe I've tracked the pool exhaustion down. It's DCIs that are querying idata, which we've already shown is slow. I can disable them temporarily, but they are ultimately essential.

netxms@netxmsts STATEMENT:  SELECT max(idata_value::double precision) FROM idata WHERE item_id=$1 AND idata_timestamp BETWEEN $2 AND $3 AND idata_value~E'^\\d+(\\.\\d+)*$'
2019-10-02 13:13:24.901 AKDT [28860] netxms@netxmsts ERROR:  out of shared memory
2019-10-02 13:13:24.901 AKDT [28860] netxms@netxmsts HINT:  You might need to increase max_locks_per_transaction.
2019-10-02 13:13:25.043 AKDT [28099] netxms@netxmsts LOG:  duration: 10728.421 ms  bind <unnamed>: SELECT max(idata_value::double precision) FROM idata WHERE item_id=$1 AND idata_timestamp BETWEEN $2 AND $3 AND idata_value~E'^\\d+(\\.\\d+)*$'
2019-10-02 13:13:25.043 AKDT [28099] netxms@netxmsts DETAIL:  parameters: $1 = '219502', $2 = '1570049993', $3 = '1570050293'
2019-10-02 13:13:26.104 AKDT [28108] netxms@netxmsts LOG:  duration: 10927.128 ms  bind <unnamed>: SELECT min(idata_value::double precision) FROM idata WHERE item_id=$1 AND idata_timestamp BETWEEN $2 AND $3 AND idata_value~E'^\\d+(\\.\\d+)*$'
2019-10-02 13:13:26.104 AKDT [28108] netxms@netxmsts DETAIL:  parameters: $1 = '219506', $2 = '1570049993', $3 = '1570050293'
2019-10-02 13:14:31.489 AKDT [28107] netxms@netxmsts LOG:  duration: 144850.468 ms  statement: SELECT idata_value,idata_timestamp FROM idata WHERE item_id=222029 ORDER BY idata_timestamp DESC LIMIT 1