[Bug]: Incorrect compressed chunk name during delete

[felipenogueirajack]

What type of bug is this?

Unexpected error

What subsystems and features are affected?

Compression

What happened?

This bug might have been resolved, but here it is.

My hypertable has 3 columns:

CREATE TABLE events.test_del_evt (
	timestamp bigint NOT NULL,
	live_timescale_event_id BIGSERIAL NOT NULL,
	event jsonb NOT NULL	
);

SELECT create_hypertable('events.test_del_evt','timestamp', chunk_time_interval => 604800000);

CREATE INDEX ON events.test_del_evt (timestamp, live_timescale_event_id);

My hypertable has 21 events in 3 chunks. After inserting the rows, I enabled compression and manually compressed all chunks.

alter table events.test_del_evt set (timescaledb.compress=true);

select compress_chunk(i, true) from show_chunks('events.test_del_evt') i;

Here is the information about the chunks:

chunkName '_hyper_1_1_chunk' starts '604800000'   ends '1209600000' isCompressed 'true'
chunkName '_hyper_1_2_chunk' starts '1209600000' ends '1814400000' isCompressed 'true'
chunkName '_hyper_1_3_chunk' starts '1814400000' ends '2419200000' isCompressed 'true'

Then, a query SELECT * to retrieve all 21 events was executed. Programmatically, using the same database connection used for the query, while iterating in the result set, I tried to execute a delete statement (with the time column in the statement). If that fails due to a compressed chunk, my code decompresses it and execute the delete statement again. It executed correctly without any errors, until it reached the 8th row, which was the 1st row of chunk '_hyper_1_2_chunk'.

It wasn't possible to delete the 8th event. After decompressing its chunk, the exception wrongly points to the _hyper_1_3_chunk. Using a large database, I only managed to delete all events by handling the exceptions in recursive/iterative way. The issue of this, however, is that I might have to delete much more chunks than my real operation needs it (The user might not want to delete everything).

In production, the code isn't going to use the same db connection for the query and for decompress the chunks and delete the row. I only realized the bug manifest itself earlier that way, but even with different connections the bug appeared in TimescaleDB 2.5.0 under Postgres version 12.

Using testcontainers/ryuk:0.3.3 it was possible to change TimescaleDB docker release versions, I noticed this same problem on several versions, for instance from Timescale 2.5.0 to 2.8.0 under Postgresql 12 and 13. The bug didn't appear in 2.72-pg14 and 2.8.0-pg14. I managed to delete 90001 data from a hypertable created on 2.8.0-pg14.

If this bug has been fixed, should I only use 2.72-pg14 or 2.8.0-pg14? Another relevant question. I am using regex to discover the chunk name from the SQLException raised by TimescaleDB. Is there a better alternative (including tableoid::regclass does not work, for the reasons stated in the issue) ?

Thanks in advance

TimescaleDB version affected

2.5.0

PostgreSQL version used

12.9

What operating system did you use?

Ubuntu 20.04 LTS

What installation method did you use?

Docker

What platform did you run on?

On prem/Self-hosted

Relevant log output and stack trace

deleting timestamp '691200000' eventId '1' chunkName '_timescaledb_internal._hyper_1_1_chunk'
decompressing chunkName '_timescaledb_internal._hyper_1_1_chunk'
select decompress_chunk('_timescaledb_internal._hyper_1_1_chunk', true)
DecompressedChunk '_timescaledb_internal._hyper_1_1_chunk'
deleting timestamp '691200001' eventId '2' chunkName '_timescaledb_internal._hyper_1_1_chunk'
deleting timestamp '691200002' eventId '3' chunkName '_timescaledb_internal._hyper_1_1_chunk'
deleting timestamp '691200003' eventId '4' chunkName '_timescaledb_internal._hyper_1_1_chunk'
deleting timestamp '691200004' eventId '5' chunkName '_timescaledb_internal._hyper_1_1_chunk'
deleting timestamp '691200005' eventId '6' chunkName '_timescaledb_internal._hyper_1_1_chunk'
deleting timestamp '691200006' eventId '7' chunkName '_timescaledb_internal._hyper_1_1_chunk'
deleting timestamp '1296000000' eventId '8' chunkName '_timescaledb_internal._hyper_1_2_chunk'
decompressing chunkName '_timescaledb_internal._hyper_1_2_chunk'
select decompress_chunk('_timescaledb_internal._hyper_1_2_chunk', true)
DecompressedChunk '_timescaledb_internal._hyper_1_2_chunk'
ERROR! org.postgresql.util.PSQLException: ERROR: cannot update/delete rows from chunk "_hyper_1_3_chunk" as it is compressed

How can we reproduce the bug?

Create the hypertable as above. The insert statement:

INSERT INTO events."abc_evt" ("timestamp",event) VALUES (691200000,'{"__type":"abc","__src":"stream","timestamp":691200000}')
...
INSERT INTO events."abc_evt" ("timestamp",event) VALUES (691200006,'{"__type":"abc","__src":"stream","timestamp":691200006}')

21 inserts, each chunk has 7 elements with the following time column values: from 691200000 to 691200006 from 1296000000 to 1296000006 from 1814400000 to 1814400006

Manually compress all chunks.

the relevant java code:

try (Connection connection = dataSource.getConnection()) {
            String sql = "SELECT *, tableoid::regclass as chunk_name FROM events.abc_evt ORDER BY timestamp ASC";
            
            try (Statement statement = connection.createStatement()) {
                try (ResultSet resultSet = statement.executeQuery(sql)) {
                    
                    while (resultSet.next()) {
                        long timestamp = resultSet.getLong("timestamp");
                        long eventId = resultSet.getLong("live_timescale_event_id");
                        String chunkName = resultSet.getString("chunk_name");
                        
                        try {
                            LOGGER.info("deleting timestamp '{}' eventId '{}' chunkName '{}'", timestamp, eventId, chunkName);
                            deleteRow(connection, timestamp, eventId); //DELETE FROM events.test_del_evt WHERE timestamp =? AND live_timescale_event_id = ?
                        
                        } catch (SQLException e) {
                            
                            String compressedChunkName = "_timescaledb_internal." + getChunkNameFrom(e); //getting chunk name from the exception using regex
                            
                            LOGGER.info("decompressing chunkName '{}'", compressedChunkName);
                            
                            try (Statement st = connection.createStatement()) {
                                String decompressSql = "select decompress_chunk('" + compressedChunkName + "', true)";
                                LOGGER.info(decompressSql);
                            
                                try (ResultSet rs = st.executeQuery(decompressSql)) {
                                    if(rs.next())
                                        LOGGER.info("DecompressedChunk '{}'", rs.getString(1));
                                }
                            }
                            deleteRow(connection, timestamp, eventId); //DELETE FROM events.test_del_evt WHERE timestamp =? AND live_timescale_event_id = ?
                        }
                    }
                }
            }
        }

[svenklemm]

Could you provide the reproduction steps as plain SQL script. It is unclear what the problem is.

[sb230132]

Hi @felipenogueirajack

Please give details of deleteRow() method too. Can you also log the exception which you get when deleteRow() is called before decompression is executed. You iterate over the result set and try to delete a row which has been fetched. I assume you need to create statement with ResultSet.TYPE_FORWARD_ONLY, ResultSet.CONCUR_UPDATABLE Please refer: https://docs.oracle.com/javase/8/docs/api/java/sql/Connection.html#createStatement-int-int-

[felipenogueirajack]

Hi @sb230132, thanks for the comment.

The deleteRow method is simple as possible - only creates a statement to delete the row, but here it is:

private void deleteRow(Connection connection, long timestamp, long eventId) throws SQLException {
        try (PreparedStatement statement = connection.prepareStatement("DELETE FROM events.abc_evt WHERE timestamp = ? AND live_timescale_event_id = ?")) {
            statement.setLong(1, timestamp);
            statement.setLong(2, eventId);
            statement.executeUpdate();
        }
    }

Regarding the exception I get when deleteRow() is called - it's the SQLExpcetion saying the chunk is compressed.
When I attempt to delete the first row of the first chunk (timestamp '691200000', eventId '1'), I got the following exception:

org.postgresql.util.PSQLException: ERROR: cannot update/delete rows from chunk "_hyper_1_1_chunk" as it is compressed
	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2553)
	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2285)
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:323)
	at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:481)
	at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:401)
	at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:164)
	at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:130)
	at net.intelie.timescaledb.simple.TimescaleDeleteErrorPlaygroundTest.deleteRow(TimescaleDeleteErrorPlaygroundTest.java:108)

This exception is expected, as _hyper_1_1_chunk it is compressed and the row I tried to delete belongs to that chunk. I also expected the "same" exception on every attempt to delete the first row of any compressed chunk.

I also got this exception, when trying to delete the first row of the second chunk timestamp '1296000000' and eventId '8'): org.postgresql.util.PSQLException: ERROR: cannot update/delete rows from chunk "_hyper_1_2_chunk" as it is compressed

What I don't expect, however, is that after decompressing the "_hyper_1_2_chunk" and attempt to delete the same row again, I got the following:
org.postgresql.util.PSQLException: ERROR: cannot update/delete rows from chunk "_hyper_1_3_chunk" as it is compressed

It's unexpected because the row belongs to the second chunk which I already decompressed.

I changed my code above to create statement with ResultSet.TYPE_FORWARD_ONLY, ResultSet.CONCUR_UPDATABLE and I got the same behavior. I'll try to test it using a big hypertable to see if there is any change. Another interesting aspect is that it this error did not occur in docker release 2.8.0-pg14.

[sb230132]

Hi @felipenogueirajack Thanks for trying what i suggested, unfortunately it did no work. Also iam not sure on how and which order JDBC code submits the sql statements to database. To take this issue forward, i need a simple jdbc program illustrating above problem and detailed steps on how to compile against postgresql. Once i can compile and build i should be able to debug and understand more about the problem.

In mean time i will try to reproduce using a libpq C library.

[felipenogueirajack]

@sb230132, if I understood correctly, the Google Driver folder have all the files I think you need.

If you don't need to debug inside the java program, you can run the timescaledb-delete-error.jar by informing 4 command-line arguments in the following order: hostname:port username password databasename. My TimescaleDB is running at port 5467 and the database I created for this is called "timescale_delete_error" (you need to create the database first or just use postgres):

java -jar timescaledb-delete-error.jar localhost:5467 postgres password timescale_delete_error

This will be the result of the execution:

Command-line arguments:localhost:5467 postgres password timescale_delete_error
TimescaleDB version:2.5.1
Postgre version:14.1
chunkName '_hyper_13_37_chunk' starts '604800000' ends '1209600000' isCompressed true
chunkName '_hyper_13_38_chunk' starts '1209600000' ends '1814400000' isCompressed true
chunkName '_hyper_13_39_chunk' starts '1814400000' ends '2419200000' isCompressed true
deleting timestamp '691200000' eventId '1' chunkName '_timescaledb_internal._hyper_13_37_chunk'
Error while deleting: ERROR: cannot update/delete rows from chunk "_hyper_13_37_chunk" as it is compressed
chunk was decompressed: _timescaledb_internal._hyper_13_37_chunk
deleting timestamp '691200001' eventId '2' chunkName '_timescaledb_internal._hyper_13_37_chunk'
deleting timestamp '691200002' eventId '3' chunkName '_timescaledb_internal._hyper_13_37_chunk'
deleting timestamp '691200003' eventId '4' chunkName '_timescaledb_internal._hyper_13_37_chunk'
deleting timestamp '691200004' eventId '5' chunkName '_timescaledb_internal._hyper_13_37_chunk'
deleting timestamp '691200005' eventId '6' chunkName '_timescaledb_internal._hyper_13_37_chunk'
deleting timestamp '691200006' eventId '7' chunkName '_timescaledb_internal._hyper_13_37_chunk'
deleting timestamp '1296000000' eventId '8' chunkName '_timescaledb_internal._hyper_13_38_chunk'
Error while deleting: ERROR: cannot update/delete rows from chunk "_hyper_13_38_chunk" as it is compressed
chunk was decompressed: _timescaledb_internal._hyper_13_38_chunk
Exception in thread "main" org.postgresql.util.PSQLException: ERROR: cannot update/delete rows from chunk "_hyper_13_39_chunk" as it is compressed
	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2676)
	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2366)
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:356)
	at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496)
	at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413)
	at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:190)
	at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:152)
	at TimescaleDbDeleteError.deleteRow(TimescaleDbDeleteError.java:84)
	at TimescaleDbDeleteError.queryAndDelete(TimescaleDbDeleteError.java:72)
	at TimescaleDbDeleteError.main(TimescaleDbDeleteError.java:40)

The code creates the schema, the table/hypertable, inserts 21 rows into the hypertable and mannually compress the 3 chunks. It prints the information about TimescaleDb and postgre versions as well the chunks name, range and compression status. Then, it proceeds to query and attempts to delete every row - by decompressing the corresponding chunk if needed. The error happens when I tried to delete the eventId 8, which belongs to _timescaledb_internal._hyper_13_38_chunk. After decompressing this chunk, I receive the error that _hyper_13_39_chunk is compressed.

Another option, if you want to debug the java code:

Inside the folder timescale_delete_error, you can find the the class file under src/ and the only library dependency (the postgres jdbc jar). You can create a Java project , for instance using IntelieJ. To add the external dependency, the second answer on this link explains clearly how to do it. Then, just execute the main method.

Let me know if this what you need or if there is something else. Thanks!

[sb230132]

Hi @felipenogueirajack Thanks for all the details. Currently Iam working on a different issue. Will get back to this issue after a day or 2 and will update what i find out.

[sb230132]

I tried as you say, please check below.

bharathysatish@Bharathys-MacBook-Pro-2 build % bin/createdb timescale_delete_error createdb: error: database creation failed: ERROR: database "timescale_delete_error" already exists

bharathysatish@Bharathys-MacBook-Pro-2 build % java -jar /Volumes/Work/PR/PR4798\ -\ java\ program\ error/timescaledb-delete-error.jar localhost:5432 bharathysatish "" timescale_delete_error Command-line arguments:localhost:5432 bharathysatish timescale_delete_error Exception in thread "main" org.postgresql.util.PSQLException: ResultSet not positioned properly, perhaps you need to call next. at org.postgresql.jdbc.PgResultSet.getRawValue(PgResultSet.java:3149) at org.postgresql.jdbc.PgResultSet.getString(PgResultSet.java:2225) at TimescaleDbDeleteError.printVersion(TimescaleDbDeleteError.java:123) at TimescaleDbDeleteError.main(TimescaleDbDeleteError.java:37)

What am i missing ?

FYI: java -version java version "19" 2022-09-20 Java(TM) SE Runtime Environment (build 19+36-2238) Java HotSpot(TM) 64-Bit Server VM (build 19+36-2238, mixed mode, sharing)

[felipenogueirajack]

It looks we have two different errors. The first was because the 'timescale_delete_error' database already existed and there is an attempt to create it. I updated the jar file and also the code file. The updated version handles the database creation. You don't have to worry about anymore, for instance, if the database already exists, the codes deal with that.

Regarding the second error, apparently the error was happening on printVersion() method. If you tried to import the files into a Java IDE, you should check if there is any call to resultSet.getString without calling resultSet.next() before.

In any case, I think these errors won't happen with the update jar and code.

[sb230132]

First error iam aware off, i only want to point out that i have a databases created on my setup.

Ok now i downloaded jar file.

Started postgres server.

bin/pg_ctl -D tsdb -l logfile start waiting for server to start.... done server started

bharathysatish@Bharathys-MacBook-Pro-2 build % tail -f logfile 
2022-10-10 21:00:18.822 IST [33276] LOG:  background worker "TimescaleDB Background Worker Scheduler" (PID 33285) exited with exit code 1
2022-10-10 21:00:18.822 IST [33278] LOG:  shutting down
2022-10-10 21:00:18.832 IST [33276] LOG:  database system is shut down
2022-10-10 21:00:24.594 IST [33333] LOG:  starting PostgreSQL 14.0 on aarch64-apple-darwin21.5.0, compiled by Apple clang version 13.1.6 (clang-1316.0.21.2.5), 64-bit
2022-10-10 21:00:24.597 IST [33333] LOG:  listening on IPv6 address "::1", port 5432
2022-10-10 21:00:24.597 IST [33333] LOG:  listening on IPv4 address "127.0.0.1", port 5432
2022-10-10 21:00:24.597 IST [33333] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-10-10 21:00:24.601 IST [33334] LOG:  database system was shut down at 2022-10-10 21:00:18 IST
2022-10-10 21:00:24.604 IST [33333] LOG:  database system is ready to accept connections
2022-10-10 21:00:24.605 IST [33340] LOG:  TimescaleDB background worker launcher connected to shared catalogs
2022-10-10 21:00:36.340 IST [33347] ERROR:  database "timescale_delete_error" already exists
2022-10-10 21:00:36.340 IST [33347] STATEMENT:  CREATE DATABASE timescale_delete_error
2022-10-10 21:00:36.362 IST [33349] ERROR:  function create_hypertable(unknown, unknown, chunk_time_interval => integer) does not exist at character 8
2022-10-10 21:00:36.362 IST [33349] HINT:  No function matches the given name and argument types. You might need to add explicit type casts.
2022-10-10 21:00:36.362 IST [33349] STATEMENT:  SELECT create_hypertable('events.test_del_evt','timestamp', chunk_time_interval => 604800000)

Now i run the new updated jar file.

java -jar timescaledb-delete-error.jar 127.0.0.1:5432 bharathysatish "" timescale_delete_error
Command-line arguments:127.0.0.1:5432 bharathysatish  timescale_delete_error
creating database 'timescale_delete_error'
Postgre version:14.0
Exception in thread "main" org.postgresql.util.PSQLException: ERROR: function create_hypertable(unknown, unknown, chunk_time_interval => integer) does not exist
  Hint: No function matches the given name and argument types. You might need to add explicit type casts.
  Position: 8
	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2676)
	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2366)
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:356)
	at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:496)
	at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:413)
	at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:333)
	at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:319)
	at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:295)
	at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:290)
	at TimescaleDbDeleteError.prepareHypertable(TimescaleDbDeleteError.java:166)
	at TimescaleDbDeleteError.main(TimescaleDbDeleteError.java:50)

I have timescaledb extention installed.

timescale_delete_error=# \dx
                                       List of installed extensions
    Name     |  Version  |   Schema   |                            Description                            
-------------+-----------+------------+-------------------------------------------------------------------
 plpgsql     | 1.0       | pg_catalog | PL/pgSQL procedural language
 timescaledb | 2.9.0-dev | public     | Enables scalable inserts and complex queries for time-series data
(2 rows)

timescale_delete_error=# \q

Please ignore my knowledge with jdbc program. I can read and understand the program, but dont know how to build jar file by making needed changes. What am i missing here ?

[felipenogueirajack]

Are you using any IDE to help with it? In the most IDEs, like Eclipse or IntelliJ, it builds automatically for you. You can even execute the code through the IDE, which is I recommend it, so you can make changes and execute it. Let me know if the following link is of help: https://www.jetbrains.com/help/idea/creating-and-running-your-first-java-application.html#run_app

If you follow this approach of downloading and using IDE, don't forget to add the external postgresql jar dependency - the file is also located in the Google driver folder.

If you want to build and generate the jar, it's also easy using IDE: https://www.jetbrains.com/help/idea/compiling-applications.html#compile_module

I'm not getting the reason TimescaleDB isn't recognizing the create_hypertable function. The error line is saying it's not recognizing the first two arguments as "text"/strings" (or as regclass), as the error says `"create_hypertable(unknown, unknown, chunk_time_interval => integer)". I update the java code, so it creates the hypertable by casting the parameters. Let's see if this works.

Another thing: I'd suggest you try using TimescaleDB version 2.7 or even earlier than that. From local tests, I didn't see the problem at 2.7.2 using postgresql 14 or even later. The odd thing is that the problem happened in both 2.7.2 and 2.8.0 using postgres 12.

[ScottLangridge]

Hey, I've run into a similar issue (which I'm fairly sure is actually the same issue, just a more specific case).

There are concise reproduction steps for @svenklemm and @sb230132, and a workaround for @felipenogueirajack here

[mkindahl]

@ScottLangridge @felipenogueirajack From my understanding of the problem you have, it is related to that you need to scan all chunks to decide what to delete. The value alone does not allow you to prune the chunks, and the error message is printed very early in the execution: when starting to execute the custom scan node.

A possible way to fix it might be to allow the scan to proceed and just not bother with printing the error message until an attempt is actually made to delete the row.

[antekresic]

Hey,

Could somebody confirm if this issue is still relevant post 2.11.0 version? I believe latest version should work correctly for this case.

Thanks.

[nikkhils]

@felipenogueirajack can you please confirm if this issue is fixed for you in 2.11.0 and above versions?

[felipenogueirajack]

@felipenogueirajack can you please confirm if this issue is fixed for you in 2.11.0 and above versions?

Hi, thanks for the reply. I'll try to test this in 2.11.0 version as soon as possible - the last version I tested was 2.8.0.