Java Open Client - Mapping temp-table to java.sql.ResultSet

[shashi12]

Hi All,

This is what I read from the Java Open Client Manual (page 65):
"In the Java Open Client, the default mechanism for passing either a single temp-table or a ProDataSet parameter (static or dynamic) is the OpenEdge ProDataGraph. An alternative mechanism for passing temp-tables (but not ProDataSets) is the SQL ResultSet interface, supported by the Java Database Connectivity (JDBC) standard. The SQL ResultSet provides a data streaming model for accessing temp-tables only and is the only mechanism for accessing complex data in the Java Open Client prior to OpenEdge Release 10.1A. This model works similar to a one-way tape reader or writer. It is provided mainly for backward compatibility."

I wrote a simple ABL Procedure that returns 5000 rows of data with two columns (one integer and one string).
When I mapped a ProDataSet output parameter to ProDataGraph on Java end, it took 1100 ms to get the results.
When I mapped a Temp-Table output parameter to a SQL ResultSet on Java end, it took 340 ms to get the results.

The results make sense because SQL ResultSet is just a data streaming model but a ProDataGraph is a full blown Object Tree representation of the same data.

Since the documentation says that "mapping temp-tables to SQL ResultSets is only provided for backward compatibility", I am a bit sceptical to use it. Does that mean this feature will be deprecated in near future?

My next question is regarding performance. An SQL query (executed through JDBC) that returns the same data takes 220 ms during the first run and just 80 ms during the second run. I am assuming that the improved performance during the second run is because the results of the first run are cached. However the ABL procedure (executed on AppServer using an Open Client architecture) takes 340 ms for the first run and 300 ms for the second run.
1) Will Open Client run slower than JDBC?
2) Why isn't there a significant improvement in performance for the second run for the State-Free Open Client program?

Thanks for reading. I appreciate your inputs.

Thanks,
Shashi

Environment: OpenEdge Architect 10.2 trial version

Code:

/* getall-fotos2.p */
DEFINE TEMP-TABLE ttFoto
FIELD fotonum LIKE foto.fotonum
FIELD fototitle LIKE foto.fototitle.

DEFINE OUTPUT PARAMETER TABLE FOR ttFoto.

FOR EACH foto NO-LOCK:

CREATE ttFoto.
BUFFER-COPY foto TO ttFoto.

END.


/* WoodpicsOpenClient.java */

package woodpics;

public class WoodpicsOpenClient {

private static woodpics.WoodpicsAppObject appObj = null;
private static com.progress.open4gl.javaproxy.Connection con = null;

public static void main(String[] args) {

try {

con = new com.progress.open4gl.javaproxy.Connection("AppServerDC://localhost:3091/esbbroker1","shashi","password","");
con.setSessionModel(1);
//Create Sports AppObject to connect
appObj = new woodpics.WoodpicsAppObject(con);
System.out.println((String) appObj._getProcReturnString());
java.util.Scanner scanner = new java.util.Scanner(System.in);
getAllPhotos();
getAllPhotos();

} catch (com.progress.open4gl.Open4GLException ex) {

System.out.println("Connection failed");
ex.printStackTrace();

} catch (java.io.IOException ex) {

System.out.println("IO Exception!");
ex.printStackTrace();

} finally {

if (appObj != null) {
try {
appObj._release();
} catch(com.progress.open4gl.SystemErrorException ex) {
ex.printStackTrace();
} catch(com.progress.open4gl.Open4GLException ex) {
ex.printStackTrace();
}
}

}

}

@SuppressWarnings("unchecked")

public static void getAllPhotos() throws com.progress.open4gl.Open4GLException, java.io.IOException {

com.progress.open4gl.ResultSetHolder resultSetHolder = new com.progress.open4gl.ResultSetHolder();



java.util.Date startTime = new java.util.Date();
appObj.getallFotos2(resultSetHolder);
java.util.Date endTime = new java.util.Date();



System.out.println("Successfull!!");
java.sql.ResultSet resultSet = resultSetHolder.getResultSetValue();
try {
int numFotos = 0;
while (resultSet.next()) {
int fotoNum = resultSet.getInt(1);
String title = resultSet.getString(2);
numFotos++;
//System.out.println(fotoNum + "\t" + title);
}
System.out.println("# Photos: " + numFotos);
} catch (Exception ignore) {
ignore.printStackTrace();
}
System.out.println("Time Taken: " + (endTime.getTime() - startTime.getTime()) + " ms");

}

}

[GregTomkins]

This is an interesting post but I don't have answers. I hope support for SQL result sets doesn't go away as we have many customers using it.

For the performance question: did you look at the times in the server log file? It will be called something like /u1/yourapp/asbroker1.server.log, and it will contain lines like this:

[09/05/27@13:21:19.277-0700] P-020753 T-000000 2 AS AS -- TRACE: Non-PERSISTENT
Procedure 'gnai/gngmsgx.p' START. (5498)
[09/05/27@13:21:19.278-0700] P-020753 T-000000 3 AS AS -- TRACE: Non-PERSISTENT
Procedure END SUCCESS. (8397)

This example tells me that the P4GL procedure 'gngmsgx.p' ran for 1 millisecond (I wish they all did...). I could then compare it to the round-trip time recorded from the Open Client app and get an estimate of the overhead of the network and the proxy. This might be helpful. Or not.

In general, the server.log files are stupendously helpful. There are other log files too but I don't find much use for them.

[shashi12]

Thanks for the quick reply Greg. Its good to know that many people use SQL ResultSets.

Thanks for the tip on the server.log file. Here's what our server.log file says...

[09/05/27@14:39:42.206-0600] P-003508 T-003440 2 AS AS -- TRACE: Non-PERSISTENT Procedure 'getall-fotos2.p' START. (5498)
[09/05/27@14:39:42.476-0600] P-003508 T-003440 3 AS AS -- TRACE: Non-PERSISTENT Procedure END SUCCESS. (8397)

[09/05/27@14:39:42.656-0600] P-003552 T-001760 2 AS AS -- TRACE: Non-PERSISTENT Procedure 'getall-fotos2.p' START. (5498)
[09/05/27@14:39:42.937-0600] P-003552 T-001760 3 AS AS -- TRACE: Non-PERSISTENT Procedure END SUCCESS. (8397)

First run: 270 ms
Second run: 281 ms

When I measure it on the Java Side:
First run: 341 ms
Second run: 300 ms

I am guessing that this means its not the network/proxy overhead that's adding to the performance.

The surprising thing is, I have found that the ABL procedure consistently takes less time to run the first time than the second time. But when I measure the time taken on the Java Open Client end, the total time taken is always less the second time! Can anyone explain this please?

I ran the ABL procedure directly on the database in a procedure editor. It took 180 ms. About 100 ms less than when it ran on AppServer. Is that expected too?

Thanks again for reading. I appreciate your inputs.

Regards,
Shashi

This is an interesting post but I don't have answers. I hope support for SQL result sets doesn't go away as we have many customers using it.

For the performance question: did you look at the times in the server log file? It will be called something like /u1/yourapp/asbroker1.server.log, and it will contain lines like this:

[09/05/27@13:21:19.277-0700] P-020753 T-000000 2 AS AS -- TRACE: Non-PERSISTENT
Procedure 'gnai/gngmsgx.p' START. (5498)
[09/05/27@13:21:19.278-0700] P-020753 T-000000 3 AS AS -- TRACE: Non-PERSISTENT
Procedure END SUCCESS. (8397)

This example tells me that the P4GL procedure 'gngmsgx.p' ran for 1 millisecond (I wish they all did...). I could then compare it to the round-trip time recorded from the Open Client app and get an estimate of the overhead of the network and the proxy. This might be helpful. Or not.

In general, the server.log files are stupendously helpful. There are other log files too but I don't find much use for them.

[GregTomkins]

I would always expect the second run to be a lot faster, assuming the data from the first run wasn't still in cache from a prior test. Also, naturally the first run will be slower if you are compiling on the fly. I can't think of any reason why the first run would ever be faster, assuming of course the load on the machine is similar in both cases etc.

If I were looking at this the next thing I would do is add MESSAGE ETIME statements at the top and bottom of the .P, and compare the time observed there to the time in the AS logs. Also, it would be better to do more like 10 runs, discard the best and worst / first and last, etc. and see what patterns emerge.

[shashi12]

Greg,

Many thanks for replying.

As suggested by you, I have used ETIME to measure the time taken on the AppServer end. I found that consistently the program runs slower the second time! Also I found that the time computed by ETIME matches with the time difference in the AppServer logs. Another observation is, given that the ABL program is running slower the first time, I expected that the Java program would run faster the first time too. However, I consistently found that the Java program runs faster the second time!

Please note that both the .r and .p files are present in the PROPATH of the AppServer.

Here are the results:
ABL Java Open Client
First Run: 286 ms 380 ms
Second Run: 319 ms 350 ms

First Run: 288 ms 371 ms
Second Run: 323 ms 350 ms

First Run: 284 ms 381 ms
Second Run: 320 ms 351 ms

First Run: 278 ms 390 ms
Second Run: 318 ms 351 ms


Can anyone please explain this to me?

Regards,
Shashi

Here's the code:
/* getall-fotos2.p */
DEFINE TEMP-TABLE ttFoto
FIELD fotonum LIKE foto.fotonum
FIELD fototitle LIKE foto.fototitle.

DEFINE OUTPUT PARAMETER TABLE FOR ttFoto.
DEFINE OUTPUT PARAMETER o_timeTaken AS INTEGER NO-UNDO.

ETIME(YES).
FOR EACH foto NO-LOCK:
CREATE ttFoto.
BUFFER-COPY foto TO ttFoto.
END.
ASSIGN o_timeTaken = ETIME.

[GregTomkins]

What happens between each set of RUN's? Are you rebooting or restarting anything to achieve a fresh start? Are they seconds apart or minutes apart?