Hey,
I found the problem in my logs (compared with wget) and then, on the
Internet (http://curl.haxx.se/mail/lib-2008-02/0048.html)
Curl automatically uses a Expect: 100-continue header when sending payloads
>1024 bytes. Apparently Restlet does not handle this correctly?
Sorry to keep spamming, but I hope this is useful!
Thanks,
Dan
On Mon, Mar 4, 2013 at 5:29 PM, Daniel Halperin
<dhalp...@cs.washington.edu>wrote:
> Followup: the bug persists with the newer 2.1.2 release.
>
> Dan
>
>
> On Mon, Mar 4, 2013 at 5:23 PM, Daniel Halperin <
> dhalp...@cs.washington.edu> wrote:
>
>> Hi Jerome,
>>
>> Sorry for not responding until now -- I am not signed up for the mailing
>> list (about to rectify this) and I never saw your answer.
>>
>> If you look at the clean git project, in build.gradle, you can see that
>> the only libraries used in the project are:
>>
>> dependencies {
>> compile "org.restlet.jee:org.restlet:${restletVersion}"
>> compile "org.restlet.jee:org.restlet.ext.jackson:${restletVersion}"
>> compile "org.restlet.jee:org.restlet.ext.jaxrs:${restletVersion}"
>> }
>>
>> I think that means this demo uses uses the org.restlet.jar ones.
>>
>> Thanks,
>> Dan
>>
>>
>> On Fri, Feb 15, 2013 at 2:58 PM, Daniel Halperin <
>> dhalp...@cs.washington.edu> wrote:
>>
>>> 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=3050319
