gpdb + pxf + pool + jdbc + mongo = not authorized for query about pxf HOT 14 CLOSED

@denalex any ideas what could be happening?

from pxf.

Also I've faced with similar but more distinct problem:

1. Create a big collection in mongo:

mongo> for (var i = 1; i <= 1000000; i++) { db.activity.insert({   _id : "name"+i } ) }

2. Try to run query and cancel it without waiting the result:

<CREATE EXTERNAL TABLE activity>

gpadmin=# SELECT * FROM activity WHERE 1=1 LIMIT 1;
^C
Cancel request sent
ERROR:  canceling statement due to user request

gpadmin=# SELECT * FROM activity WHERE 1=1 LIMIT 1;
ERROR:  remote component error (0) from '127.0.0.1:5888': Empty reply from server (libchurl.c:920)  (seg1 slice1 10.0.0.21:40001 pid=1623) (libchurl.c:920)
CONTEXT:  External table activity

gpadmin=# SELECT * FROM activity WHERE 1=1 LIMIT 1;
ERROR:  remote component error (0) from '127.0.0.1:5888': Failed connect to localhost:5888; Connection refused (libchurl.c:920)  (seg0 slice1 10.0.0.21:40000 pid=1720) (libchurl.c:920)
CONTEXT:  External table activity

So simple cancelling of the query made external table crashed. And it unrelated with pool enabling.

from pxf.

Not sure what might be wrong there with Mongo, we have not specifically tested Mongo connectivity. With the pool, we have connection idle timeout at 30sec by default, not sure if you spread the queries and those within 30secs from each other use a good connection while maybe the later one tries to establish a new connection and fails ? Maybe you can enable debug output on Mongo JDBC driver and see if you notice anything out of order.

For query cancellation, it seems that your PXF instance has crashed. If you can set DEBUG logging for PXF and provide a log file corresponding to the use case, we might see what is going on in there.

from pxf.

@denalex thank you for response!

Maybe you can enable debug output on Mongo JDBC driver and see if you notice anything out of order.

I'll try.

For query cancellation, it seems that your PXF instance has crashed. If you can set DEBUG logging for PXF and provide a log file corresponding to the use case, we might see what is going on in there.

I've got ClientAbortException in logs on simple use case:

1. First of all I edit pxf/conf/pxf-log4j.properties (am I right?):

log4j.rootLogger=ALL, ROLLINGFILE       # INFO to ALL
log4j.logger.org.greenplum.pxf=DEBUG    # uncomment

2. Next I create the external table (mongo_testdb2 has jdbc.pool.enabled=false):

CREATE EXTERNAL TABLE test2 ( _id text )
LOCATION ('pxf://activity?PROFILE=JDBC&SERVER=mongo_testdb2')
FORMAT 'CUSTOM' (FORMATTER='pxfwritable_import');

3. Next I do query and get result as expected:

gpadmin=# select * from test2 limit 1;
  _id
-------
 name1
(1 row)

4. While I do the query I've seen an exception in pxf/logs$ tail -f * (exception appeared after I seen the result of the query) --- tail1.log

5. If I repeat the query I will get the result as expected but .ClientAbortException: java.net.SocketException: Broken pipe (Write failed) appears in the log --- tail2.log

6. And if I will repeat and repeat the query I will get the data as expected but in log the error org.apache.catalina.connector.ClientAbortException: java.net.SocketException: Broken pipe (Write failed) will appears every query.

7. If I swith jdbc.pool.enabled to true the behavior is the same.

from pxf.

@denalex @frankgh I've made experiments and I think the problem in the pooling (may be caching).

Look:

1. I have one server with two databases so I create two pxf/servers:

• mongo_ud (URL: mongo://10.0.0.4:27017/ud)
• mongo_act (URL: mongo://10.0.0.4:27017/act)

Config in jdbc-site.xml are identical (exclude db in url) and with jdbc.pool.enabled=true.

2. When I select the data from the first server all next queries to the second server will fail with not authorized for query error:

gpadmin=# CREATE EXTERNAL TABLE test_ud ( _id text )
gpadmin-# LOCATION ('pxf://Users?PROFILE=JDBC&SERVER=mongo_ud')
gpadmin-# FORMAT 'CUSTOM' (FORMATTER='pxfwritable_import');
CREATE EXTERNAL TABLE

gpadmin=# select * from test_ud limit 1;
           _id
--------------------------
 5d2344e0004f7800019a1cd6
(1 row)

gpadmin=# CREATE EXTERNAL TABLE test_act ( _id text )
gpadmin-# LOCATION ('pxf://Activities?PROFILE=JDBC&SERVER=mongo_act')
gpadmin-# FORMAT 'CUSTOM' (FORMATTER='pxfwritable_import');
CREATE EXTERNAL TABLE

gpadmin=# select * from test_act limit 1;
ERROR:  remote component error (500) from '127.0.0.1:5888':  type  Exception report   message   com.mongodb.MongoQueryException: Query failed with error code 13 and error message 'not authorized for query on act.Activities' on server 10.0.0.4:27017 

In MongoDB log I see:

assertion 13 not authorized for query on ud.Users ns:act.Activities query:{}
User Assertion: 13:not authorized for query on act.Activities src/mongo/db/instance.cpp 365

3. If I restart pxf and then query second server successfully then I will get the error when I will querying first server. If I set jdbc.pool.enabled=false for all servers the issue not appeared.

4. So as result: the first used server is locking the pool for self.

📜 I've switch pxf logging to ALL and made the pxf-service.log diff, please review - https://diff-online.com/view/5d7ce99cadf65140f0c47e37
This is two queries from the example above. On the left side you can see the log when I select from test_ud, and on the right side when I do select from test_act.

Files with log:
pxf-service-1.log
pxf-service-2.log

You can notice that both queries use one session 1568373517-0000011833 may be this is the problem.

from pxf.

@denalex @frankgh New info. I've tested different jdbc driver and discovered that jdbc config was identified by server name and make collisions (I think it is PXF side). So if I create two jdbc-site.xml configs for mongo://10.0.0.4:27017/ud and mongo://10.0.0.4:27017/act the connection identifier becomes 10.0.0.4 for both and probably this may be around the cause why configurations are intersected.

In this jdbc driver I've made two custom different configs with separate names for every server (mongo_ud.config and mongo_act.config) and it works perfect for jdbc.pool.enabled=true because settings for the jdbc connection managed by jdbc driver and not by PXF/pool.

So I've found workaround for me. 😃

But the case described above still unresolved.

from pxf.

@denalex @frankgh I confirmed my hypothesis and fix the issue for my first JDBC driver.

1. I've added fake hosts to /etc/hosts:

10.0.0.4 mongo_ud
10.0.0.4 mongo_act

2. Than I replace 10.0.0.4 to fake hosts in jdbc-site.xml's:

    <property>
        <name>jdbc.url</name>
        <value>jdbc:mongo://mongo_ud:27017/ud</value>
    </property>

    <property>
        <name>jdbc.url</name>
        <value>jdbc:mongo://mongo_act:27017/act</value>
    </property>

3. I've set jdbc.pool.enabled=true

As result the errors was gone 🎉🎉🎉

You should just identify JDBC servers not only by hostname.

from pxf.

@anki-code -- 2 things here:

1. The ClientAbortException that you see in the logs is due to the fact that you have LIMIT 1 in your SQL query. You can see in the logs that a fragment has 2800-3000 records, but once the first batch is given to GPDB, it takes 1 row and cancels the request (since it does not need more), which kills the postgres backend process connected to PXF and PXF reports ClientAbortedException, but cleans up connections after this, as expected. So these error are normal. Try removing LIMIT 1 clause from your query and you should not see any errors in the log file.

2. When you run 2 servers with the same endpoint but different databases on that endpoint, you can see PXF is still using 2 HikariCP connection pools, as expected, since we have a pool per URL and user. What I think is happening (and you proven, I believe) is that MongoDB JDBC driver is being smart here and perhaps is using some kind of connection pooling inside itself and that pool is likely not taking the database name into the account ?

I do not believe there is any problem with PXF here, if you agree, then perhaps close the issue. If you think any change is needed, please suggest what exactly would you expect. Thank you for experimenting.

from pxf.

@denalex thank you for response!

My concern after experiments:

1. GPDB hasn't method to pass database name to CREATE EXTERNAL TABLE
2. And other users who want to use many databases on one server would create many configs for PXF: one per database
3. And they will faced with this not trivial issue. It's really hard to understand that problem in hostname

If you think it's ok feel free to close the issue. After two days of research and two litres of coffee I think the hostname check should be in PXF side with warning in the log or fixing if it possible on PXF side. ☕️

from pxf.

1. GPDB hasn't method to pass database name to CREATE EXTERNAL TABLE

You can actually pass the database location by passing the whole JDBC URL as a parameter:
LOCATION ('pxf://Activities?PROFILE=JDBC&SERVER=mongo_act&JDBC_URL=jdbc:mongo://10.0.0.4:27017/ud') even though we do not encourage this style.

2. And other users who want to use many databases on one server would create many configs for PXF: one per database

That is the idea, as different databases might require different settings, but you should be able to overcome this with specifying the URL containing the database info as in #1 above.

3. And they will faced with this not trivial issue. It's really hard to understand that problem in hostname

I believe the issue you faced is specific to MongoDB, but I agree, it was probably frustrating to debug through this. While we do not officially support MongoDB, we will test a similar scenario with Postgres to make sure it is not an issue there and if there is, we will investigate further.

If you think it's ok feel free to close the issue. After two days of research and two litres of coffee I think the hostname check should be in PXF side with warning in the log or fixing if it possible on PXF side. ☕️

Coffee always helps :) What do you mean by "the hostname check should be in PXF side with warning in the log". How would you describe the requirement (given ... when ... then ...) ?

from pxf.

@anki-code maybe if you could share your docker compose, then it'd make it easier for us to standup an environment to test the mongodb driver

from pxf.

@denalex
1-2. Thank you for new info! It's undocumented option. Good to know dirty to use ;)
3. Great! Please tell me back the result of your check. It's really interesting.
4. I'm not so experienced with pxf to know what pxf has under the hood and give your advice. From my point of view it will be a good to have a setting to choose identifier type: host or host+database. And if there are many pxf/servers described with one hostname may be warn about it in pxf log with link to best practices.

@anki-code maybe if you could share your docker compose, then it'd make it easier for us to standup an environment to test the mongodb driver

@frankgh @denalex I've built a complete example of this issue for you and sent you invite to my private repo. Please review the readme in the repo and enjoy!

from pxf.

@anki-code thanks! but I am not able to access the repo, I received the email invitation, but I am seeing a not found error.

from pxf.

@frankgh oh, sorry I've renamed the repo and I supposed github will redirect right way ) I've send you invites again. Please check it out :)

from pxf.