Thread: How to avoid SET application_name = ''

Hello,

I'm trying to understand the "SET application_name" command sent by the driver.

We have a database server with high concurrency, ~25K TPS, and looking the top queries (with pg_stat_statements view) I get it's the query taking more time.

The command is very fast but the number of calls is huge.

TOP 10 Queries (only ~2 hours collecting)

  calls   | total_time | avg_time |   rows   | avg_rows | hit_percent |                                                                                                                      

----------+------------+----------+----------+----------+-------------+------------------------------

 55782793 | 8212550.69 |     0.15 |        0 |     0.00 |             | SET application_name = ''

  4425751 |  322475.14 |     0.07 |   138606 |     0.00 |       98.98 | /* load one-to-many ...

  4097384 |  963780.17 |     0.24 |    84514 |     0.00 |       99.77 | /* load ...

  3908144 |  366598.92 |     0.09 |  3834578 |     0.00 |      100.00 | /* load ...

  2596097 |  480030.01 |     0.18 |  2596097 |     1.00 |      100.00 | /* SELECT count(*) FROM ...

  2365353 |  290965.73 |     0.12 |  2365335 |     0.00 |       99.99 | /* load ...

  2081011 |  127373.91 |     0.06 |   379289 |     0.00 |       99.59 | /* load collection ...

  1303931 |  145544.50 |     0.11 |  1303925 |     0.00 |       95.94 | /* load ...

  1274982 |  577683.73 |     0.45 |  1274982 |     1.00 |      100.00 | /* Select count(*) from ...

  1203475 | 1522327.87 |     1.26 |  4405775 |     3.00 |       89.44 | /* load ...

It takes ~8K seconds, more than 2 hours, it means that this command can use more than one core all the time! (if I'm understanding right)

I'm thinking as the application name is empty maybe this command could be avoid.

I have asked our Glassfish people to "unmark" this option if possible but they told me they don't know how to do it, where to do it.

I'm not sure if the quantity of calls is a problem in application, in glassfish or in driver. But, if it's possible tune to avoid it, I would like that.

Any ideas?

Thanks!

Caiut

Hi everyone, this is my first post, so forgive me If I’m not respecting any protocol rule I haven’t read.

I’ve run a small test, the driver doesn’t do that by it’s own on every statement if it’s inside a pool and correctly configured, i’m using bdcp. See by yourself:

public DbcpExperiment() throws Exception {

initializePool();

}

protected void initializePool() {

basicDataSource = new BasicDataSource();

basicDataSource.setDriverClassName("org.postgresql.Driver");

basicDataSource.setUsername("test");

basicDataSource.setPassword("test");

basicDataSource.setUrl("jdbc:postgresql://127.0.0.1:5432/test?ApplicationName=DbcpExperiment");

basicDataSource.setInitialSize(1);

basicDataSource.setMaxIdle(1);  

basicDataSource.setMaxActive(1);

basicDataSource.setDefaultAutoCommit(false);

}

public void testApplicationName() throws Exception {

Connection connection = null;

for (int i = 0; i < 1000; i++) {

connection = basicDataSource.getConnection();

PreparedStatement preparedStatement = connection.prepareStatement("SELECT 1");

preparedStatement.executeQuery();

connection.commit();

connection.close();

System.out.println(i);

}

}

test=# select calls, total_time, query FROM pg_stat_statements ORDER BY calls DESC;

 calls |    total_time    |                  query                  

-------+------------------+-----------------------------------------

  1000 | 4.85599999999995 | SELECT ?

  1000 |            0.446 | BEGIN

  1000 |            0.468 | COMMIT

     2 |            0.057 | SET application_name = 'DbcpExperiment'

     2 |            0.049 | SET extra_float_digits = 3

     1 |            0.232 | SELECT pg_stat_statements_reset();

(6 rows)

test=# 

Pom snippet:

==========

<dependencies>

<dependency>

    <groupId>commons-dbcp</groupId>

<artifactId>commons-dbcp</artifactId>

<version>1.4</version>

</dependency>

<dependency>

<groupId>junit</groupId>

<artifactId>junit</artifactId>

<version>3.8.1</version>

<scope>test</scope>

</dependency>

<dependency>

<groupId>org.postgresql</groupId>

<artifactId>postgresql</artifactId>

<version>9.4-1201-jdbc4</version>

</dependency>

</dependencies>

Regards

- Daniel 

El 25 nov 2015, a las 19:25, Thomas Kellerer <spam_eater@gmx.net> escribió:

Fabio Caiut schrieb am 25.11.2015 um 16:20:

I'm trying to understand the "SET application_name" command sent by the driver.

We have a database server with high concurrency, ~25K TPS, and looking the top queries (with pg_stat_statements view)
I get it's the query taking more time.

The command is very fast but the number of calls is huge.


TOP 10 Queries (only ~2 hours collecting)


  calls   | total_time | avg_time |   rows   | avg_rows | hit_percent |
----------+------------+----------+----------+----------+-------------+------------------------------
 55782793 | 8212550.69 |     0.15 |        0 |     0.00 |             | SET application_name = ''
  4425751 |  322475.14 |     0.07 |   138606 |     0.00 |       98.98 | /* load one-to-many ...
  4097384 |  963780.17 |     0.24 |    84514 |     0.00 |       99.77 | /* load ...
  3908144 |  366598.92 |     0.09 |  3834578 |     0.00 |      100.00 | /* load ...
  2596097 |  480030.01 |     0.18 |  2596097 |     1.00 |      100.00 | /* SELECT count(*) FROM ...
  2365353 |  290965.73 |     0.12 |  2365335 |     0.00 |       99.99 | /* load ...
  2081011 |  127373.91 |     0.06 |   379289 |     0.00 |       99.59 | /* load collection ...
  1303931 |  145544.50 |     0.11 |  1303925 |     0.00 |       95.94 | /* load ...
  1274982 |  577683.73 |     0.45 |  1274982 |     1.00 |      100.00 | /* Select count(*) from ...
  1203475 | 1522327.87 |     1.26 |  4405775 |     3.00 |       89.44 | /* load ...


It takes ~8K seconds, more than 2 hours, it means that this command can use more than one core all the time! (if I'm understanding right)

I'm thinking as the application name is empty maybe this command could be avoid.
I have asked our Glassfish people to "unmark" this option if possible but they told me they don't know how to do it, where to do it.

I'm not sure if the quantity of calls is a problem in application, in glassfish or in driver.
But, if it's possible tune to avoid it, I would like that.

Is it possible that this is configured as a "connection test" statement with your connection pool in Glassfish?
Including something like "test-on-borrow" (or test-on-return) so that this would send each time a
connection is taken out of the pool (or returned).

I don't think the driver sends this "on its own" without any trigger from the application.
The statement is sent if Connection.setClientInfo() is called, so maybe that called from somewhere in your application or the connection pool.







--
Sent via pgsql-jdbc mailing list (pgsql-jdbc@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-jdbc

Hi, 

Vladimir, Thomas ... you're right.

The glassfish guys analyzed dumps and look in the glassfish sources, the problem is there. 

They told me pool calls setClientInfo for each query!! 

Thank you for your help.

Caiut

> Date: Wed, 25 Nov 2015 19:54:56 +0300
> Subject: Re: [JDBC] How to avoid SET application_name = ''
> From: sitnikov.vladimir@gmail.com
> To: caiut@hotmail.com
> CC: pgsql-jdbc@postgresql.org
>
> As far as I can tell, there is no option to completely disable "set
> application_name" feature via property.
>
> Is SQL appears when client calls
> Connection#setClientInfo("ApplicationName", ...) or
> Connection#setClientInfo(Properties).
>
> It make sense to avoid setting the same application name again and
> again for the same connection.
> Can you please file an issue at https://github.com/pgjdbc/pgjdbc/issues?
>
> In the mean time, it would be good if you could capture thread dumps
> from the application (e.g. 100 dumps with 10 second intervals under
> typical load) and grep setClientInfo. That would point out the line in
> code that issues that excessive setClientInfo.
>
> Vladimir