But the profile shows it costs too much time in readResponse. com.unboundid.ldap.sdk.LDAPConnection.readResponse(int) costs more than 3,000 ms in a invocation.(The network itself is good) I think there must be something wrong with my code or config, but I haven't figured it out.
I'm confused about this for Unbound SDK should have a good performance. Thank you in advance.
Last edit: Owen Tsao 2014-08-07
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
The LDAPConnection.readResponse method is used to wait for a response to be received over a connection. It's used for connections in synchronous mode (connections not in synchronous mode have a dedicated reader thread that does the same thing but in the background) -- as soon as the request is sent to the server, the SDK calls the readResponse method to wait for the corresponding response to be received. If this method takes a long time, then it's almost certainly because it took the server a long time to send the response.
If the server that you're using offers log files, you can try to use the log to determine whether the server took a long time to send the response. Alternately, you can use a network packet capture utility like Wireshark, snoop, or tcpdump to determine whether the server takes a while to send the response packets.
Also note that since you're creating a connection pool, then you may actually be creating multiple connections, so this could be the aggregate time required to establish and authenticate all of those connections. If that turns out to be prohibitively high, then you could have the connection pool create the connections in parallel (some LDAPConnectionPool constructors have an initialConnectThreads argument that allow multiple connections to be established simultaneously instead of establishing them one at a time).
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
Thank your for your kind reply, this does help me a lot. I checked UnboundID Proxy logs, and found the etime is high; the value is about more than 5 (in seconds) which indicate that it took UnboundID Server more than 5s to perform the LDAP operation. What confused me is the value is much higher than my experience. In other words, my app sent request and got the response in 1s, but the logs backend shows this operation cost more than 5s. Did I misunderstand something?
This log shows that the problem isn't in the LDAP SDK. It's also probably not in the Directory Proxy Server, since it's unlikely to be introducing the delay. Rather, it's probably the case that the search is taking that long in the backend sever for some reason. Given that it is otherwise a very simple equality search, my guess is that it is being processed as unindexed.
Since you're using an UnboundID Directory Proxy Server, I'll assume you're also using an UnboundID Directory Server as the backend server. If that's true, then you can tell whether the search is unindexed by looking in the access log for that server to see if the corresponding log message (with "conn=306375 op=8") has "unindexed=true". If it does, then you should add an equality index for the tokenid attribute and run the rebuild-index tool to generate it.
If the backend server doesn't report the search as being unindexed but it's still taking a long time for some reason, then I would recommend enabling the operation timing access logger, which will provide very detailed information about where the server is spending its time in the course of processing an operation. You can do that with the commands:
Hopefully, the problem is as simple as defining an index, but if that isn't the case then it's probably better to move this discussion to a more appropriate support channel (e.g., working with a technical support engineer via SalesForce or whatever sales engineer is assigned to your evaluation), as this forum is specific to the UnboundID LDAP SDK for Java and the problem doesn't appear to be directly related to that product.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
I use UnboundID SDK to create a LDAPConnectionPool, and then use method getConnection() to get a connection and do operations. Here are my code:
public LDAPConnection getConnection() throws LDAPException { LDAPConnection storeConnection = null; try { if (this.connectionPool == null) { String trustStore = TokenStoreConfig.gettruststore(); String pwd = TokenStoreConfig.gettruststorePassword(); char[] secret = (pwd == null || pwd.length() == 0) ? null : pwd.toCharArray(); SSLUtil ssl = new SSLUtil(new TrustStoreTrustManager(trustStore, secret, null, true)); try { String[] addresses = new String[1]; int[] ports = new int[1]; ports[0] = TokenStoreConfig.getport(); addresses[0] = TokenStoreConfig.getdomain(); RoundRobinServerSet serverSet = new RoundRobinServerSet(addresses, ports, ssl.createSSLSocketFactory()); SimpleBindRequest bindRequest = new SimpleBindRequest(TokenStoreConfig.getuser(), TokenStoreConfig.getpassword()); connectionPool = new LDAPConnectionPool(serverSet, bindRequest, TokenStoreConfig.getmaxServiceConnections()); } catch (Exception ex) { System.out.println("Could not create connection pool"); ex.printStackTrace(); } } storeConnection = this.connectionPool.getConnection(); this.proxyControl = this.createProxyControl(storeConnection); } catch (LDAPException e) { this.releaseConnection(storeConnection); throw e; } return storeConnection; }But the profile shows it costs too much time in readResponse. com.unboundid.ldap.sdk.LDAPConnection.readResponse(int) costs more than 3,000 ms in a invocation.(The network itself is good) I think there must be something wrong with my code or config, but I haven't figured it out.
I'm confused about this for Unbound SDK should have a good performance. Thank you in advance.
Last edit: Owen Tsao 2014-08-07
The LDAPConnection.readResponse method is used to wait for a response to be received over a connection. It's used for connections in synchronous mode (connections not in synchronous mode have a dedicated reader thread that does the same thing but in the background) -- as soon as the request is sent to the server, the SDK calls the readResponse method to wait for the corresponding response to be received. If this method takes a long time, then it's almost certainly because it took the server a long time to send the response.
If the server that you're using offers log files, you can try to use the log to determine whether the server took a long time to send the response. Alternately, you can use a network packet capture utility like Wireshark, snoop, or tcpdump to determine whether the server takes a while to send the response packets.
Also note that since you're creating a connection pool, then you may actually be creating multiple connections, so this could be the aggregate time required to establish and authenticate all of those connections. If that turns out to be prohibitively high, then you could have the connection pool create the connections in parallel (some LDAPConnectionPool constructors have an initialConnectThreads argument that allow multiple connections to be established simultaneously instead of establishing them one at a time).
Thank your for your kind reply, this does help me a lot. I checked UnboundID Proxy logs, and found the etime is high; the value is about more than 5 (in seconds) which indicate that it took UnboundID Server more than 5s to perform the LDAP operation. What confused me is the value is much higher than my experience. In other words, my app sent request and got the response in 1s, but the logs backend shows this operation cost more than 5s. Did I misunderstand something?
Log:
[08/Aug/2014:12:36:32.359 +0800] SEARCH RESULT threadID=9 conn=15968 op=15 msgID=16 base="ou=OAuth2Tokens,dc=Identity" scope=2 filter="(tokenid=YzFmNTg3NzItYjYyZi00YjBmLTg4ZGEtMzUzYTM1NzA0MWJiNjhlMTQ4NzEtOTYx)" attrs="expirytime,scope,parent,username,cisUUID" targetHost="unboundid.test.com" targetPort=1636 targetProtocol="LDAP" resultCode=0 serversAccessed="unboundid.test.com:1636" etime=6.125 from="app='UnboundID-DS' sessionID='conn=306375' responseID='op=8'" entriesReturned=1This log shows that the problem isn't in the LDAP SDK. It's also probably not in the Directory Proxy Server, since it's unlikely to be introducing the delay. Rather, it's probably the case that the search is taking that long in the backend sever for some reason. Given that it is otherwise a very simple equality search, my guess is that it is being processed as unindexed.
Since you're using an UnboundID Directory Proxy Server, I'll assume you're also using an UnboundID Directory Server as the backend server. If that's true, then you can tell whether the search is unindexed by looking in the access log for that server to see if the corresponding log message (with "conn=306375 op=8") has "unindexed=true". If it does, then you should add an equality index for the tokenid attribute and run the rebuild-index tool to generate it.
If the backend server doesn't report the search as being unindexed but it's still taking a long time for some reason, then I would recommend enabling the operation timing access logger, which will provide very detailed information about where the server is spending its time in the course of processing an operation. You can do that with the commands:
dsconfig set-global-configuration-prop \ --set enable-sub-operation-timer:true dsconfig create-log-publisher \ --publisher-name "Operation Timing" \ --type operation-timing-access \ --set enabled:true \ --set log-file:logs/operation-timing \ --set "rotation-policy:24 Hours Time Limit Rotation Policy" \ --set "rotation-policy:Size Limit Rotation Policy" \ --set "retention-policy:File Count Retention Policy" \ --set "retention-policy:Free Disk Space Retention Policy" \ --set "retention-policy:Size Limit Retention Policy"Hopefully, the problem is as simple as defining an index, but if that isn't the case then it's probably better to move this discussion to a more appropriate support channel (e.g., working with a technical support engineer via SalesForce or whatever sales engineer is assigned to your evaluation), as this forum is specific to the UnboundID LDAP SDK for Java and the problem doesn't appear to be directly related to that product.
Thank you very much. The performance has been improved significantly after I add index in attribute oauthtokenid.
Last edit: Owen Tsao 2014-08-11