Hi Daniel, Thanks for reporting those result in a reproducible way.
Which HTTP connector are you using exactly? The default on in org.restlet.jar or the Simple/Jetty extensions? Thanks, Jerome -- http://restlet.com http://twitter.com/#!/jlouvel 2013/2/15 Daniel Halperin <dhalp...@cs.washington.edu> > Hi everyone, > > Just a note that I created a clean, minimal test example here: > https://github.com/dhalperi/restlet-testing > > Thanks, > Dan > > > On Fri, Feb 15, 2013 at 10:20 AM, Daniel Halperin < > dhalp...@cs.washington.edu> wrote: > >> Hi everyone, >> >> I'm having some crazy timing properties related to RESTlet responses >> being above or below 1024 bytes. The fact that this is a power of 2 makes >> me think it's no coincidence! >> >> [To start, here is some setup text copied from my previous mail.] >> I'm just getting started with RESTlet (v.2.1.1, with >> org.restlet.jee.ext.jackson & jee.ext.jaxrs), so I may be doing something >> very wrong. However, basic things work well for me. For instance, if I >> return POJOs from a function annotated with >> @Produces(MediaType.APPLICATION_JSON), they seem to be returned properly. >> >> Right now, I'm experimenting with implementing different handlers for >> different Content-Types. I started with the simplest possible: echo JSON >> input (converted to String) back as JSON: >> >> /** >> * Class that handles queries. >> * >> * @author dhalperi >> */ >> @Path("/echo") >> public final class EchoResource { >> /** >> * For now, simply echoes back its input. >> * >> * @param input the payload of the POST request itself. >> * @return the payload. >> */ >> @POST >> @Produces(MediaType.APPLICATION_JSON) >> @Consumes(MediaType.APPLICATION_JSON) >> public String postNewQuery(final String input) { >> return input; >> } >> } >> [/copied text] >> >> I just found a new, very strange effect. It seems that if the payload >> returned by this function is <= 1024 bytes, the processing time is >> near-imperceptible; a few hundred ms at most. But when it goes to 1025 >> bytes, it seems to take just about 1.06s or just about 2.04s to process. >> Also, there's almost no variation from those two numbers. >> >> I send json (and time the processing) like this: time curl -i -XPOST >> localhost:8753/echo -H "Content-type: application/json" -d >> @./single_join.json >> >> Here are the contents of single_join.json >> >> % cat single_join.json >> { >> "raw_datalog" : "testRelationJoin(x,y,y,z) :- >> testRelation(x,y),testRelation(y,z).", >> "logical_ra" : "INSERT(JOIN(SCAN1,SCAN2))", >> "query_plan" : { >> "1" : [[ >> { >> "op_name" : "SCAN1", >> "op_type" : "SQLiteScan", >> "arg_user_name" : "test", >> "arg_program_name" : "test", >> "arg_relation_name" : "testRelation" >> }, >> >> { >> "op_name" : "SCAN2", >> "op_type" : "SQLiteScan", >> "arg_user_name" : "test", >> "arg_program_name" : "test", >> "arg_relation_name" : "testRelation" >> }, >> >> { >> "op_name" : "JOIN", >> "op_type" : "LocalJoin", >> "arg_child1" : "SCAN1", >> "arg_columns1" : ["1"], >> "arg_child2" : "SCAN2", >> "arg_columns2" : ["0"], >> "arg_select1" : ["0"], >> "arg_select2" : ["1"] >> }, >> >> { >> "op_name" : "INSERT", >> "op_type" : "SQLiteInsert", >> "arg_child" : "JOIN", >> "arg_user_name" : "test", >> "arg_program_name" : "test", >> "arg_relation_name" : "testRelationJoin", >> "arg_overwrite_table" : "true" >> } >> ]] >> } >> } >> >> if I add another section, say by copying the "JOIN" map again, the (long) >> timing does not change at all. If I remove a section, say by deleting the >> "JOIN", it returns instantaneously. This happens independent of what I >> remove, so it does not appear to be data-dependent (other than bigger or >> smaller than some size threshold). I eventually started manually tweaking >> the file to find the boundary, and it's 1024 bytes as shown below. >> >> Here's a few traces for evidence. Note that the "Content-Length" flips >> from 1025 to 1024 when I remove a single byte from the request and >> processing time goes from over 1 second to a few hundred ms. >> >> *% time* curl -i -XPOST localhost:8753/echo -H "Content-type: >> application/json" -d @./single_join.5.json >> HTTP/1.1 200 OK >> Date: Fri, 15 Feb 2013 18:16:18 GMT >> Accept-Ranges: bytes >> Server: Restlet-Framework/2.1.1 >> *Content-Length: 1025* >> Content-Type: application/xml; charset=UTF-8 >> >> { "logical_ra" : "INSERT(JOIN(SCAN1,SCAN2))", "query_plan" : { "1" : >> [[ { "op_name" : "SCAN1", "arg_user_name" : >> "test", "arg_rel*aaaaaaaaaaaaaaaaaaaaaaa*tion_name" : >> "testRelation" }, { "op_name" : "SCAN2", >> "op_type" : "SQLiteScan", "arg_user_name" : "test", >> "arg_program_name" : "test", "arg_relation_name" : "testRelation" >> }, { "op_name" : "JOIN", "op_type" >> : "LocalJoin", "arg_child1" : "SCAN1", "arg_columns1" : >> ["1"], "arg_child2" : "SCAN2", "arg_columns2" : ["0"], >> "arg_select1" : ["0"], "arg_select2" : ["1"] }, >> { "op_name" : "INSERT", "op_type" : >> "SQLiteInsert", "arg_child" : "JOIN", "arg_user_name" : >> "test", "arg_program_name" : "test", "arg_relation_name" >> : "testRelationJoin", "arg_overwrite_table" : "true" } >> ]] }}curl -i -XPOST localhost:8753/echo -H "Content-type: >> application/json" -d *0.01s user 0.00s system 1% cpu 1.025 total* >> * >> * >> When I remove a single 'a' from the underlined text above, it drops to a >> few hundred ms. >> >> *% time* curl -i -XPOST localhost:8753/echo -H "Content-type: >> application/json" -d @./single_join.5.json >> HTTP/1.1 200 OK >> Date: Fri, 15 Feb 2013 18:17:10 GMT >> Accept-Ranges: bytes >> Server: Restlet-Framework/2.1.1 >> *Content-Length: 1024* >> Content-Type: application/xml; charset=UTF-8 >> >> { "logical_ra" : "INSERT(JOIN(SCAN1,SCAN2))", "query_plan" : { "1" : >> [[ { "op_name" : "SCAN1", "arg_user_name" : >> "test", "arg_rel*aaaaaaaaaaaaaaaaaaaaaa*tion_name" : >> "testRelation" }, { "op_name" : "SCAN2", >> "op_type" : "SQLiteScan", "arg_user_name" : "test", >> "arg_program_name" : "test", "arg_relation_name" : "testRelation" >> }, { "op_name" : "JOIN", "op_type" >> : "LocalJoin", "arg_child1" : "SCAN1", "arg_columns1" : >> ["1"], "arg_child2" : "SCAN2", "arg_columns2" : ["0"], >> "arg_select1" : ["0"], "arg_select2" : ["1"] }, >> { "op_name" : "INSERT", "op_type" : >> "SQLiteInsert", "arg_child" : "JOIN", "arg_user_name" : >> "test", "arg_program_name" : "test", "arg_relation_name" >> : "testRelationJoin", "arg_overwrite_table" : "true" } >> ]] }}curl -i -XPOST localhost:8753/echo -H "Content-type: >> application/json" -d *0.01s user 0.01s system 40% cpu 0.028 total* >> >> Does anyone have advice for how I should debug this? >> >> Thanks! >> Dan >> > > ------------------------------------------------------ http://restlet.tigris.org/ds/viewMessage.do?dsForumId=4447&dsMessageId=3049451
