clarus-proxy / proxy

The proxy component
Other
2 stars 3 forks source link

Cannot create multi-tables within the same transaction #18

Open hargathor opened 6 years ago

hargathor commented 6 years ago

I'm testing the CLARUS proxy using the dataset provided in the repository benchmarking. For now i'm focusing on simple tasks, creating the database, the table structure and insertion of some data.

I'm using the version 1.2-snap-ok tagged in all repositories I'm using the security policy patient_anonymisation.xml I'm using the dataset table scheme for the table creation and the dataset table data for the data insert.

Here is my test:

$ PGPASSWORD=password PGUSER=postgres psql -h localhost -c "CREATE DATABASE clarus;"
CREATE DATABASE
$ PGPASSWORD=password PGUSER=postgres psql -h localhost -p 5433 -f dataSets/ehealth/std/eHealth_tableScheme.tpl clarus
CREATE TABLE
CREATE TABLE
CREATE TABLE
CREATE TABLE
CREATE TABLE
CREATE TABLE
CREATE TABLE
CREATE TABLE
$ PGPASSWORD=password PGUSER=postgres psql -h localhost -f ./dataSets/ehealth/std/eHealth_tableData.tpl clarus
BEGIN
psql:./dataSets/ehealth/std/eHealth_tableData.tpl:91: FATAL:  Record creation not supported by this CLARUS proxy
psql:./dataSets/ehealth/std/eHealth_tableData.tpl:93: server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.
psql:./dataSets/ehealth/std/eHealth_tableData.tpl:93: connection to server was lost

The Clarus proxy output a stacktrace:

clarus_1    | 17:57:12.088 ERROR - (C<-S) Close on error
clarus_1    | 17:57:12.091 WARN  - An exceptionCaught() event was fired, and it reached at the tail of the pipeline. It usually means the last handler in the pipeline did not handle the exception.
clarus_1    | io.netty.handler.codec.DecoderException: io.netty.util.IllegalReferenceCountException: refCnt: 0, decrement: 1
clarus_1    |   at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:98) ~[netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at eu.clarussecure.proxy.protocol.plugins.pgsql.message.PgsqlMessageHandler.channelRead(PgsqlMessageHandler.java:79) ~[proxy-plugin-pgsql-1.0.1.jar:1.0.1]
clarus_1    |   at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:372) ~[netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:358) ~[netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:350) ~[netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102) ~[netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at eu.clarussecure.proxy.protocol.plugins.pgsql.message.PgsqlMessageHandler.channelRead(PgsqlMessageHandler.java:79) ~[proxy-plugin-pgsql-1.0.1.jar:1.0.1]
clarus_1    |   at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:372) ~[netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:38) ~[netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:363) ~[netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:66) ~[netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:877) [netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144) [netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at java.lang.Thread.run(Thread.java:748) [na:1.8.0_131]
clarus_1    | Caused by: io.netty.util.IllegalReferenceCountException: refCnt: 0, decrement: 1
clarus_1    |   at io.netty.buffer.AbstractReferenceCountedByteBuf.release(AbstractReferenceCountedByteBuf.java:111) ~[netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   at eu.clarussecure.proxy.spi.CString.release(CString.java:142) ~[proxy-common-1.0.1.jar:1.0.1]
clarus_1    |   at eu.clarussecure.proxy.protocol.plugins.pgsql.message.sql.SQLSession.setTransactionErrorDetails(SQLSession.java:809) ~[proxy-plugin-pgsql-1.0.1.jar:1.0.1]
clarus_1    |   at eu.clarussecure.proxy.protocol.plugins.pgsql.message.sql.PgsqlEventProcessor.processReadyForQueryResponse(PgsqlEventProcessor.java:8928) ~[proxy-plugin-pgsql-1.0.1.jar:1.0.1]
clarus_1    |   at eu.clarussecure.proxy.protocol.plugins.pgsql.message.QueryResponseHandler.lambda$process$12(QueryResponseHandler.java:79) ~[proxy-plugin-pgsql-1.0.1.jar:1.0.1]
clarus_1    |   at eu.clarussecure.proxy.protocol.plugins.pgsql.message.QueryResponseHandler.processDetails(QueryResponseHandler.java:151) ~[proxy-plugin-pgsql-1.0.1.jar:1.0.1]
clarus_1    |   at eu.clarussecure.proxy.protocol.plugins.pgsql.message.QueryResponseHandler.processDetails(QueryResponseHandler.java:132) ~[proxy-plugin-pgsql-1.0.1.jar:1.0.1]
clarus_1    |   at eu.clarussecure.proxy.protocol.plugins.pgsql.message.QueryResponseHandler.process(QueryResponseHandler.java:78) ~[proxy-plugin-pgsql-1.0.1.jar:1.0.1]
clarus_1    |   at eu.clarussecure.proxy.protocol.plugins.pgsql.message.QueryResponseHandler.process(QueryResponseHandler.java:12) ~[proxy-plugin-pgsql-1.0.1.jar:1.0.1]
clarus_1    |   at eu.clarussecure.proxy.protocol.plugins.pgsql.message.PgsqlMessageHandler.decode(PgsqlMessageHandler.java:119) ~[proxy-plugin-pgsql-1.0.1.jar:1.0.1]
clarus_1    |   at eu.clarussecure.proxy.protocol.plugins.pgsql.message.PgsqlMessageHandler.decode(PgsqlMessageHandler.java:37) ~[proxy-plugin-pgsql-1.0.1.jar:1.0.1]
clarus_1    |   at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:88) ~[netty-all-4.1.4.Final.jar:4.1.4.Final]
clarus_1    |   ... 13 common frames omitted

When i tried to inspect the database I can see that the database has been created but not the tables.

tchevallier commented 6 years ago

please test with the CREATE table and INSERT commands in a single transaction (i.e. BEGIN/COMMIT) It is probably required when running the pgsql proxy in "buffering mode" (typically the case for anonymization)

tchevallier commented 6 years ago

For example : BEGIN CREATE TABLE tbl ... INSERT INTO tbl (col1 ,col2, ... ) VALUES ... COMMIT

hargathor commented 6 years ago

Tested and it is the same issue. New table scheme

begin;CREATE TABLE patient( pat_id text PRIMARY KEY, pat_name text, pat_last1 text, pat_last2 text, pat_gen text, pat_zip text);commit;
begin;CREATE TABLE episode(ep_id text PRIMARY KEY, ep_pat text REFERENCES patient(pat_id) ON DELETE CASCADE, ep_age text, ep_range text);commit;
begin;CREATE TABLE discharge_report(dis_id text, dis_ver text, CONSTRAINT discharge_report_pk PRIMARY KEY (dis_id, dis_ver), dis_ep text REFERENCES episode(ep_id) ON DELETE CASCADE, dis_serv text, dis_adm text, dis_dis text, dis_days text, dis_adtp text, dis_dest text, dis_sig1 text, dis_sig2 text, dis_pdf text);commit;
begin;CREATE TABLE diagnose_cie9mc(dia_id text PRIMARY KEY, dia_desc text);commit;
begin;CREATE TABLE document_diagnose (dis_id text, dis_ver text, CONSTRAINT discharge_fk FOREIGN KEY (dis_id, dis_ver) REFERENCES discharge_report(dis_id, dis_ver) ON DELETE CASCADE, dia_id text REFERENCES diagnose_cie9mc(dia_id));commit;
begin;CREATE TABLE lab_result(lab_id text, lab_ver text, CONSTRAINT lab_pk PRIMARY KEY (lab_id, lab_ver), lab_ep text REFERENCES episode(ep_id) ON DELETE CASCADE, lab_pdf text);commit;
begin;CREATE TABLE medical_service_loinc(ms_id text PRIMARY KEY, ms_desc text, ms_unit text, ms_ref text);commit;
begin;CREATE TABLE document_ms(lab_id text, lab_ver text, CONSTRAINT lab_fk FOREIGN KEY (lab_id, lab_ver) REFERENCES lab_result(lab_id, lab_ver) ON DELETE CASCADE, ms_id text REFERENCES medical_service_loinc(ms_id), res_val text, res_abn text);commit;
PGPASSWORD=password PGUSER=postgres psql -h localhost -c "\dt;"
No relations found.

I'm just testing the table creation for now since the data insertion depends on it and are already in a single transaction

dieriver commented 6 years ago

I was consulting with @rmulero and he told me that he tested the requests with a single table. This means that he merged all the tables into a big, single one and he run all the inserts on that table. In addition, as @tchevallier said, Anonimization module usually works in "buffering mode", which requires transactional requests. (BEGIN; CREATE... INSERT... INSERT.... COMMIT;)

hargathor commented 6 years ago

even when I try to create one single table (patient) by hand using psql client I cannot make it work I use the command:

$ PGPASSWORD=password PGUSER=postgres psql -h localhost -c "begin;CREATE TABLE patient( pat_id text PRIMARY KEY, pat_name text, pat_last1 text, pat_last2 text, pat_gen text, pat_zip text);commit;"
COMMIT
$ PGPASSWORD=password PGUSER=postgres psql -h localhost -c "\dt;"
No relations found.
hargathor commented 6 years ago

I've identified the issue, the clarus proxy does not support multiple table creation. It seems that you need to let some time between the table creation and data insertion. ex: begin; create table patient; insert data..... commit; wait.......... begin; create table diagnose etc....

hargathor commented 6 years ago

In fact only the patient table is working with this method.... Will try with the simple_encryption module