Choria with Puppet 7 and postgres DB query

118 views
Skip to first unread message

Derek

unread,
Jan 21, 2021, 11:28:21 AM1/21/21
to Choria Users
Hi,

Recently upgraded to Puppet7 and Facter4, with choria-0.19.0

Now having issues with mco commands with choria discovery method.
--dm=mc seems to be working ok.


The package application failed to run, use -v for full error backtrace details: Failed to make request to PuppetDB: 500: Server Error: {
"cause1":"org.postgresql.util.PSQLException: ERROR: syntax error at or near ")"\n  Position: 1205",
"cause0":"javax.servlet.ServletException: org.postgresql.util.PSQLException: ERROR: syntax error at or near ")"\n  Position: 1205",
"message":"javax.servlet.ServletException: org.postgresql.util.PSQLException: ERROR: syntax error at or near ")"\n  Position: 1205",
"url":"/pdb/query/v4",
"status":"500"
}


/var/log/puppetlabs/puppetdb/puppetdb.log

2021-01-21T11:27:01.295-05:00 WARN  [o.e.j.s.HttpChannel] /pdb/query/v4
javax.servlet.ServletException: org.postgresql.util.PSQLException: ERROR: syntax error at or near ")"
  Position: 1205
        at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:162)
        at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:767)
        at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:54)
        at com.puppetlabs.trapperkeeper.services.webserver.jetty9.utils.MDCRequestLogHandler.handle(MDCRequestLogHandler.java:36)
        at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
        at org.eclipse.jetty.server.Server.handle(Server.java:500)
        at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
        at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
        at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:543)
        at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:398)
        at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:161)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
        at java.lang.Thread.run(Thread.java:748)
Caused by: org.postgresql.util.PSQLException: ERROR: syntax error at or near ")"
  Position: 1205
        at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2532)
        at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2267)
        at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:312)
        at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:448)
        at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:369)
        at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:153)
        at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:103)
        at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeQuery(ProxyPreparedStatement.java:52)
        at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeQuery(HikariProxyPreparedStatement.java)
        at puppetlabs.puppetdb.jdbc$call_with_array_converted_query_rows$fn__24748.invoke(jdbc.clj:320)
        at clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:814)
        at clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:741)
        at puppetlabs.puppetdb.jdbc$call_with_array_converted_query_rows.invokeStatic(jdbc.clj:312)
        at puppetlabs.puppetdb.jdbc$call_with_array_converted_query_rows.invoke(jdbc.clj:295)
        at puppetlabs.puppetdb.jdbc$call_with_array_converted_query_rows.invokeStatic(jdbc.clj:308)
        at puppetlabs.puppetdb.jdbc$call_with_array_converted_query_rows.invoke(jdbc.clj:295)
        at puppetlabs.puppetdb.query_eng$body_stream$fn__31251$fn__31254$fn__31255.invoke(query_eng.clj:339)
        at clojure.java.jdbc$db_transaction_STAR_.invokeStatic(jdbc.clj:771)
        at clojure.java.jdbc$db_transaction_STAR_.invoke(jdbc.clj:741)
        at puppetlabs.puppetdb.query_eng$body_stream$fn__31251$fn__31254.invoke(query_eng.clj:321)
        at puppetlabs.puppetdb.query_eng$body_stream$fn__31251.invoke(query_eng.clj:318)
        at puppetlabs.puppetdb.query_eng$generated_stream$fn__31225.invoke(query_eng.clj:275)
        at ring.util.io$piped_input_stream$fn__190.invoke(io.clj:28)
        at clojure.core$binding_conveyor_fn$fn__5754.invoke(core.clj:2030)
        at clojure.lang.AFn.call(AFn.java:18)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        ... 1 common frames omitted


Thanks,
- Derek

R.I.Pienaar

unread,
Jan 21, 2021, 2:57:38 PM1/21/21
to choria-users
Weird, I use it all the time with success - but I guess it depends on your query etc

Can you please:

  • set your client to log debug
  • show the logging output from "mco find" and also "mco find" with your flags
--
You received this message because you are subscribed to the Google Groups "Choria Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to choria-users...@googlegroups.com.

--
R.I.Pienaar / www.devco.net / @ripienaar

Derek

unread,
Jan 21, 2021, 4:07:55 PM1/21/21
to Choria Users
Thanks for the response.

- mco find <flags> -v command output

Discovering hosts using the choria method .... 
The find application failed to run: Failed to make request to PuppetDB: 500: Server Error: {
"cause1":"org.postgresql.util.PSQLException: ERROR: syntax error at or near &quot;)&quot;\n  Position: 1205",
"cause0":"javax.servlet.ServletException: org.postgresql.util.PSQLException: ERROR: syntax error at or near &quot;)&quot;\n  Position: 1205",
"message":"javax.servlet.ServletException: org.postgresql.util.PSQLException: ERROR: syntax error at or near &quot;)&quot;\n  Position: 1205",
"url":"/pdb/query/v4",
"status":"500"
}

Failed to make request to PuppetDB: 500: Server Error: {
"cause1":"org.postgresql.util.PSQLException: ERROR: syntax error at or near &quot;)&quot;\n  Position: 1205",
"cause0":"javax.servlet.ServletException: org.postgresql.util.PSQLException: ERROR: syntax error at or near &quot;)&quot;\n  Position: 1205",
"message":"javax.servlet.ServletException: org.postgresql.util.PSQLException: ERROR: syntax error at or near &quot;)&quot;\n  Position: 1205",
"url":"/pdb/query/v4",
"status":"500"
} (RuntimeError)
        from /opt/puppetlabs/mcollective/plugins/mcollective/util/choria.rb:348:in `pql_query'  <----
        from /opt/puppetlabs/mcollective/plugins/mcollective/discovery/choria.rb:40:in `discover'
        from /opt/puppetlabs/mcollective/plugins/mcollective/discovery/choria.rb:8:in `discover'
        from /opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/choria-mcorpc-support-2.23.3/lib/mcollective/discovery.rb:119:in `discover'
        from /opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/choria-mcorpc-support-2.23.3/lib/mcollective/client.rb:153:in `discover'
        from /opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/choria-mcorpc-support-2.23.3/lib/mcollective/rpc/client.rb:565:in `discover'
        from /opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/choria-mcorpc-support-2.23.3/lib/mcollective/application/find.rb:11:in `main'
        from /opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/choria-mcorpc-support-2.23.3/lib/mcollective/application.rb:313:in `run'
        from /opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/choria-mcorpc-support-2.23.3/lib/mcollective/applications.rb:23:in `run'
        from /opt/puppetlabs/puppet/lib/ruby/gems/2.7.0/gems/choria-mcorpc-support-2.23.3/bin/mco:33:in `<top (required)>'
        from /usr/bin/mco:23:in `load'
        from /usr/bin/mco:23:in `<main>'


After setting loglevel to debug on the client:

choriabroker:/var/log/choria.log
{"component":"network_broker","level":"debug","msg":"10.20.32.110:32862 - cid:4626 - \"v0.6.2:ruby2:choriabroker\" - Client connection closed: Client Closed","time":"2021-01-21T15:43:44-05:00"}




R.I. Pienaar

unread,
Jan 21, 2021, 4:45:38 PM1/21/21
to choria...@googlegroups.com
With the client set to debug we should see the queries it executes 

So edit client.conf for log level  

---
R.I.Pienaar

On 21 Jan 2021, at 22:07, Derek <derekc...@gmail.com> wrote:

Thanks for the response.

Derek

unread,
Jan 21, 2021, 5:07:05 PM1/21/21
to Choria Users

/etc/puppetlabs/mcollective/client.cfg
loglevel = debug


> mco puppet status
debug 2021/01/21 16:52:15: pluginmanager.rb:162:in `loadclass' Loading Mcollective::Facts::Yaml_facts from mcollective/facts/yaml_facts.rb
debug 2021/01/21 16:52:15: pluginmanager.rb:43:in `<<' Registering plugin facts_plugin with class MCollective::Facts::Yaml_facts single_instance: true
debug 2021/01/21 16:52:15: pluginmanager.rb:162:in `loadclass' Loading Mcollective::Connector::Nats from mcollective/connector/nats.rb
debug 2021/01/21 16:52:15: cache.rb:117:in `block in ttl' Cache miss on 'ddl' key 'connector/nats'
debug 2021/01/21 16:52:15: base.rb:100:in `block in findddlfile' Found nats ddl at /opt/puppetlabs/mcollective/plugins/mcollective/connector/nats.ddl
debug 2021/01/21 16:52:15: pluginmanager.rb:43:in `<<' Registering plugin connector_plugin with class MCollective::Connector::Nats single_instance: true
debug 2021/01/21 16:52:15: pluginmanager.rb:162:in `loadclass' Loading Mcollective::Security::Choria from mcollective/security/choria.rb
debug 2021/01/21 16:52:15: pluginmanager.rb:43:in `<<' Registering plugin security_plugin with class MCollective::Security::Choria single_instance: true
info 2021/01/21 16:52:15: config.rb:151:in `loadconfig' The Marionette Collective version 2.23.3 started by /usr/bin/mco using config file /etc/puppetlabs/mcollective/client.cfg
debug 2021/01/21 16:52:15: pluginmanager.rb:162:in `loadclass' Loading MCollective::Application::Puppet from mcollective/application/puppet.rb
debug 2021/01/21 16:52:15: pluginmanager.rb:43:in `<<' Registering plugin puppet_application with class MCollective::Application::Puppet single_instance: true
debug 2021/01/21 16:52:15: pluginmanager.rb:79:in `[]' Returning new plugin puppet_application with class MCollective::Application::Puppet
debug 2021/01/21 16:52:15: pluginmanager.rb:79:in `[]' Returning new plugin connector_plugin with class MCollective::Connector::Nats
info 2021/01/21 16:52:15: nats.rb:15:in `initialize' Choria NATS.io connector using pure ruby nats/io/client 0.6.2 with protocol version 1
debug 2021/01/21 16:52:15: pluginmanager.rb:79:in `[]' Returning new plugin security_plugin with class MCollective::Security::Choria
debug 2021/01/21 16:52:15: choria.rb:363:in `block in have_ssl_files?' Checking for SSL file /home/user/.puppetlabs/etc/puppet/ssl/certs/user.mcollective.pem
debug 2021/01/21 16:52:15: choria.rb:363:in `block in have_ssl_files?' Checking for SSL file /home/user/.puppetlabs/etc/puppet/ssl/private_keys/user.mcollective.pem
debug 2021/01/21 16:52:15: choria.rb:363:in `block in have_ssl_files?' Checking for SSL file /home/user/.puppetlabs/etc/puppet/ssl/certs/ca.pem
debug 2021/01/21 16:52:15: choria.rb:412:in `valid_certificate?' Verified certificate /CN=user.mcollective/OU=mcollective against CA /CN=Puppet CA: puppetmaster
debug 2021/01/21 16:52:16: choria.rb:191:in `block in query_srv_records' Attempting to resolve SRV record _mcollective-server._tcp.xx.xx
debug 2021/01/21 16:52:16: choria.rb:193:in `block in query_srv_records' Found 0 SRV records for _mcollective-server._tcp.xx.xx
debug 2021/01/21 16:52:16: choria.rb:191:in `block in query_srv_records' Attempting to resolve SRV record _x-puppet-mcollective._tcp.xx.xx
debug 2021/01/21 16:52:16: choria.rb:193:in `block in query_srv_records' Found 1 SRV records for _x-puppet-mcollective._tcp.xx.xx
debug 2021/01/21 16:52:16: choria.rb:201:in `block in query_srv_records' Found choriabroker:4222 with priority 10 and weight 0
debug 2021/01/21 16:52:16: nats.rb:90:in `connect' Connecting to servers: nats://choriabroker:4222
debug 2021/01/21 16:52:16: cache.rb:117:in `block in ttl' Cache miss on 'ddl' key 'agent/puppet'
debug 2021/01/21 16:52:16: base.rb:100:in `block in findddlfile' Found puppet ddl at /opt/puppetlabs/mcollective/plugins/mcollective/agent/puppet.ddl
debug 2021/01/21 16:52:16: cache.rb:117:in `block in ttl' Cache miss on 'ddl' key 'discovery/choria'
debug 2021/01/21 16:52:16: base.rb:100:in `block in findddlfile' Found choria ddl at /opt/puppetlabs/mcollective/plugins/mcollective/discovery/choria.ddl
debug 2021/01/21 16:52:16: pluginmanager.rb:162:in `loadclass' Loading MCollective::Discovery::Choria from mcollective/discovery/choria.rb
debug 2021/01/21 16:52:16: choria.rb:33:in `discover' Performing direct discovery against PuppetDB
debug 2021/01/21 16:52:16: choria.rb:342:in `pql_query' Performing PQL query: nodes[certname, deactivated] { (certname in inventory[certname] { facts.mcollective.server.collectives.match("\d+") = "mcollective" }) and (resources {type = "File" and tag = "mcollective_agent_puppet_server"}) }
debug 2021/01/21 16:52:17: choria.rb:191:in `block in query_srv_records' Attempting to resolve SRV record _x-puppet-db._tcp.xx.xx
debug 2021/01/21 16:52:17: choria.rb:193:in `block in query_srv_records' Found 0 SRV records for _x-puppet-db._tcp.xx.xx
debug 2021/01/21 16:52:18: choria.rb:191:in `block in query_srv_records' Attempting to resolve SRV record _x-puppet._tcp.xx.xx
debug 2021/01/21 16:52:18: choria.rb:193:in `block in query_srv_records' Found 1 SRV records for _x-puppet._tcp.xx.xx
debug 2021/01/21 16:52:18: choria.rb:201:in `block in query_srv_records' Found puppetmaster:8140 with priority 10 and weight 0
debug 2021/01/21 16:52:18: choria.rb:256:in `https' Creating new HTTPS connection to puppetmaster:8081
debug 2021/01/21 16:52:18: choria.rb:363:in `block in have_ssl_files?' Checking for SSL file /home/user/.puppetlabs/etc/puppet/ssl/certs/user.mcollective.pem
debug 2021/01/21 16:52:18: choria.rb:363:in `block in have_ssl_files?' Checking for SSL file /home/user/.puppetlabs/etc/puppet/ssl/private_keys/user.mcollective.pem
debug 2021/01/21 16:52:18: choria.rb:363:in `block in have_ssl_files?' Checking for SSL file /home/user/.puppetlabs/etc/puppet/ssl/certs/ca.pem
debug 2021/01/21 16:52:18: choria.rb:412:in `valid_certificate?' Verified certificate /CN=user.mcollective/OU=mcollective against CA /CN=Puppet CA: puppetmaster

The puppet application failed to run, use -v for full error backtrace details: Failed to make request to PuppetDB: 500: Server Error: {
"cause1":"org.postgresql.util.PSQLException: ERROR: syntax error at or near &quot;)&quot;\n  Position: 1205",
"cause0":"javax.servlet.ServletException: org.postgresql.util.PSQLException: ERROR: syntax error at or near &quot;)&quot;\n  Position: 1205",
"message":"javax.servlet.ServletException: org.postgresql.util.PSQLException: ERROR: syntax error at or near &quot;)&quot;\n  Position: 1205",
"url":"/pdb/query/v4",
"status":"500"
}
debug 2021/01/21 16:52:18: pluginmanager.rb:82:in `[]' Returning cached plugin connector_plugin with class MCollective::Connector::Nats
info 2021/01/21 16:52:18: natswrapper.rb:140:in `block in start' Disconnected from NATS for an unknown reason
info 2021/01/21 16:52:18: natswrapper.rb:149:in `block in start' Connection to NATS server closed


Thanks.

R.I.Pienaar

unread,
Jan 22, 2021, 3:51:19 AM1/22/21
to choria-users
Best I can tell all PQL queries are broken,

following a clean install and using the puppetdb install guide - first it goes wrong because by default puppet modules installs the wrong version of Postgres, but after fixing that even basic queries fail:

$ puppet query 'nodes { certname = "macbook-pro.local" }'
FATAL: Last PuppetDB API response code

$ sudo tail -n 100 /var/log/puppetlabs/puppetdb/puppetdb.log|grep Cause
Caused by: org.postgresql.util.PSQLException: ERROR: syntax error at or near ")"


So I dont think this is a choria problem at all, PuppetDB is just borked.

R.I.Pienaar

unread,
Jan 22, 2021, 3:48:16 PM1/22/21
to choria-users
On some further investigation it appears that puppetdb has removed support for one aspect of the queries that we do, I'll see if they feel like putting it back.

till ten puppet 7 support will be spotty

R.I.Pienaar

unread,
Jan 22, 2021, 3:56:32 PM1/22/21
to choria-users

Derek

unread,
Jan 22, 2021, 6:15:30 PM1/22/21
to Choria Users

Thanks for looking into it further and opening a ticket!
For now --dm=mc will do.

- Derek

Reply all
Reply to author
Forward
0 new messages