« Return to Thread: Slowness of http_open/3
Re: Slowness of http_open/3
by Torbjörn Lager-2
::
Rate this Message:
I found a tool called "Instruments". I'm not sure I captured the right
kind of info, but here's what I got:
#,,Caller,Function,FD,Path,Bytes
1,0,,pread,3,/Developer/Library/PrivateFrameworks/InstrumentsPlugIn.framework/Resources/libsimshim.dylib,4096
2,0,,pread,3,/Developer/Library/PrivateFrameworks/InstrumentsPlugIn.framework/Resources/libsimshim.dylib,4096
3,0,,pread,3,/opt/local/lib/swipl-5.6.52/lib/i386-darwin9.2.0/libpl.dylib,4096
4,0,,pread,3,/opt/local/lib/libgmp.3.dylib,4096
5,0,,pread,3,/opt/local/lib/libreadline.5.2.dylib,4096
6,0,,pread,3,/opt/local/lib/libncursesw.5.dylib,4096
7,0,,pread,3,/opt/local/lib/libncurses.5.dylib,4096
8,0,,read,3,/opt/local/lib/swipl-5.6.52/bin/i386-darwin9.2.0/swipl,1023
9,0,,read,3,/opt/local/lib/swipl-5.6.52/bin/swipl,4096
10,0,,read,3,/opt/local/lib/swipl-5.6.52/swipl.rc,4096
11,0,,read,4,/opt/local/lib/swipl-5.6.52/xpce/prolog/lib/swi_hooks.pl,4096
12,0,,read,4,/opt/local/lib/swipl-5.6.52/xpce/prolog/lib/swi_hooks.pl,4096
13,0,,read,3,/opt/local/lib/swipl-5.6.52/swipl.rc,4096
14,0,,write,2,,23
15,0,,write,2,,16
16,0,,write,2,,9
17,0,,write,2,,8
18,0,,write,2,,6
19,0,,write,2,,1
20,0,,write,2,,1
21,0,,write,2,,48
22,0,,write,2,,1
23,0,,write,2,,68
24,0,,write,2,,1
25,0,,write,2,,64
26,0,,write,2,,1
27,0,,write,2,,51
28,0,,write,2,,1
29,0,,write,2,,1
30,0,,write,2,,50
31,0,,write,2,,1
32,0,,write,2,,1
33,0,,read,0,,4096
34,0,,write,2,,1
35,0,,write,2,,2
36,0,,write,2,,4
37,0,,write,2,,1
38,0,rl_read_key,read,0,,1
39,0,rl_read_key,read,0,,1
40,0,rl_read_key,read,0,,1
41,0,rl_read_key,read,0,,1
42,0,rl_read_key,read,0,,1
43,0,rl_read_key,read,0,,1
44,0,S__fillbuf,read,5,/Users/lager/Development/Synergy/assets/examples/test.xml,4096
45,0,S__fillbuf,read,5,/Users/lager/Development/Synergy/assets/examples/test.xml,4096
46,0,S__flushbuf,write,2,,2
47,0,S__flushbuf,write,2,,62
48,0,S__flushbuf,write,2,,1
49,0,S__flushbuf,write,2,,2
50,0,S__flushbuf,write,2,,62
51,0,S__flushbuf,write,2,,1
52,0,S__flushbuf,write,2,,2
53,0,S__flushbuf,write,2,,62
54,0,S__flushbuf,write,2,,1
55,0,S__flushbuf,write,2,,2
56,0,S__flushbuf,write,2,,62
57,0,S__flushbuf,write,2,,1
58,0,S__flushbuf,write,2,,2
59,0,S__flushbuf,write,2,,62
60,0,S__flushbuf,write,2,,1
61,0,S__flushbuf,write,2,,2
62,0,S__flushbuf,write,2,,62
63,0,S__flushbuf,write,2,,1
64,0,S__flushbuf,write,2,,2
65,0,S__flushbuf,write,2,,62
66,0,S__flushbuf,write,2,,1
67,0,S__flushbuf,write,2,,2
68,0,S__flushbuf,write,2,,62
69,0,S__flushbuf,write,2,,1
70,0,S__flushbuf,write,2,,2
71,0,S__flushbuf,write,2,,62
72,0,S__flushbuf,write,2,,1
73,0,S__flushbuf,write,2,,2
74,0,S__flushbuf,write,2,,62
75,0,S__flushbuf,write,2,,1
76,0,S__flushbuf,write,2,,2
77,0,S__flushbuf,write,2,,62
78,0,S__flushbuf,write,2,,1
79,0,S__flushbuf,write,2,,2
80,0,S__flushbuf,write,2,,62
81,0,S__flushbuf,write,2,,1
82,0,S__flushbuf,write,2,,2
83,0,S__flushbuf,write,2,,62
84,0,S__flushbuf,write,2,,1
85,0,S__flushbuf,write,2,,2
86,0,S__flushbuf,write,2,,62
87,0,S__flushbuf,write,2,,1
88,0,S__flushbuf,write,2,,2
89,0,S__flushbuf,write,2,,62
90,0,S__flushbuf,write,2,,1
91,0,S__flushbuf,write,2,,2
92,0,S__flushbuf,write,2,,62
93,0,S__flushbuf,write,2,,1
94,0,S__flushbuf,write,2,,2
95,0,S__flushbuf,write,2,,62
96,0,S__flushbuf,write,2,,1
97,0,S__flushbuf,write,2,,5
98,0,S__flushbuf,write,2,,1
99,0,S__flushbuf,write,2,,1
100,0,rl_read_key,read,0,,1
Is that what you need?
- Torbjörn
On Tue, May 20, 2008 at 4:49 PM, Jan Wielemaker <wielemak@...> wrote:
> On Tuesday 20 May 2008 16:31, Torbjörn Lager wrote:
>> Here's what happens:
>> :- use_module(library(http/http_open)).
>> :- use_module(library(sgml)).
>>
>> t(Data) :-
>> http_open('http://localhost:5001/pages/assets/examples/test.xml',
>> In, []),
>> read_data(In),
>> close(In).
>>
>> read_data(In) :-
>> repeat,
>> time(get_byte(In, B0)),
>> B0 == -1, !.
>>
>> ?- time(t(_)).
>> % 1 inferences, 0.00 CPU in 0.00 seconds (0% CPU, Infinite Lips)
> <snip>
>> % 1 inferences, 0.00 CPU in 0.00 seconds (0% CPU, Infinite Lips)
>> % 1 inferences, 0.00 CPU in 5.00 seconds (0% CPU, Infinite Lips)
>> % 2,080 inferences, 0.00 CPU in 5.00 seconds (0% CPU, Infinite Lips)
>> true.
>
> Ok. So, somehow detecting end-of-file takes very long!? Typically, it is
> now time to run a system call tracer to see what happens when. I don't
> recall what this is called on MacOS (or even whether it exists as
> default component), but typically they go by the name 'strace', 'truss',
> 'trace' or something sinmilar. Now run "% strace swipl <options>" and
> your program. I think there is by default no timing information
> displayed, but you should notice a call blocking 5 seconds. Can you find
> that call? If its gets too confusing on your terminal, use two. Start
> Prolog on the first, get the PID and attach strace from the other (most
> implementations have options such as -p PID).
>
> --- Jan
>
> P.s. Any other MacOS users suffering from this?
>
> _______________________________________________
> SWI-Prolog mailing list
> SWI-Prolog@...
> https://mailbox.iai.uni-bonn.de/mailman/listinfo.cgi/swi-prolog
>_______________________________________________
SWI-Prolog mailing list
SWI-Prolog@...
https://mailbox.iai.uni-bonn.de/mailman/listinfo.cgi/swi-prolog
kind of info, but here's what I got:
#,,Caller,Function,FD,Path,Bytes
1,0,,pread,3,/Developer/Library/PrivateFrameworks/InstrumentsPlugIn.framework/Resources/libsimshim.dylib,4096
2,0,,pread,3,/Developer/Library/PrivateFrameworks/InstrumentsPlugIn.framework/Resources/libsimshim.dylib,4096
3,0,,pread,3,/opt/local/lib/swipl-5.6.52/lib/i386-darwin9.2.0/libpl.dylib,4096
4,0,,pread,3,/opt/local/lib/libgmp.3.dylib,4096
5,0,,pread,3,/opt/local/lib/libreadline.5.2.dylib,4096
6,0,,pread,3,/opt/local/lib/libncursesw.5.dylib,4096
7,0,,pread,3,/opt/local/lib/libncurses.5.dylib,4096
8,0,,read,3,/opt/local/lib/swipl-5.6.52/bin/i386-darwin9.2.0/swipl,1023
9,0,,read,3,/opt/local/lib/swipl-5.6.52/bin/swipl,4096
10,0,,read,3,/opt/local/lib/swipl-5.6.52/swipl.rc,4096
11,0,,read,4,/opt/local/lib/swipl-5.6.52/xpce/prolog/lib/swi_hooks.pl,4096
12,0,,read,4,/opt/local/lib/swipl-5.6.52/xpce/prolog/lib/swi_hooks.pl,4096
13,0,,read,3,/opt/local/lib/swipl-5.6.52/swipl.rc,4096
14,0,,write,2,,23
15,0,,write,2,,16
16,0,,write,2,,9
17,0,,write,2,,8
18,0,,write,2,,6
19,0,,write,2,,1
20,0,,write,2,,1
21,0,,write,2,,48
22,0,,write,2,,1
23,0,,write,2,,68
24,0,,write,2,,1
25,0,,write,2,,64
26,0,,write,2,,1
27,0,,write,2,,51
28,0,,write,2,,1
29,0,,write,2,,1
30,0,,write,2,,50
31,0,,write,2,,1
32,0,,write,2,,1
33,0,,read,0,,4096
34,0,,write,2,,1
35,0,,write,2,,2
36,0,,write,2,,4
37,0,,write,2,,1
38,0,rl_read_key,read,0,,1
39,0,rl_read_key,read,0,,1
40,0,rl_read_key,read,0,,1
41,0,rl_read_key,read,0,,1
42,0,rl_read_key,read,0,,1
43,0,rl_read_key,read,0,,1
44,0,S__fillbuf,read,5,/Users/lager/Development/Synergy/assets/examples/test.xml,4096
45,0,S__fillbuf,read,5,/Users/lager/Development/Synergy/assets/examples/test.xml,4096
46,0,S__flushbuf,write,2,,2
47,0,S__flushbuf,write,2,,62
48,0,S__flushbuf,write,2,,1
49,0,S__flushbuf,write,2,,2
50,0,S__flushbuf,write,2,,62
51,0,S__flushbuf,write,2,,1
52,0,S__flushbuf,write,2,,2
53,0,S__flushbuf,write,2,,62
54,0,S__flushbuf,write,2,,1
55,0,S__flushbuf,write,2,,2
56,0,S__flushbuf,write,2,,62
57,0,S__flushbuf,write,2,,1
58,0,S__flushbuf,write,2,,2
59,0,S__flushbuf,write,2,,62
60,0,S__flushbuf,write,2,,1
61,0,S__flushbuf,write,2,,2
62,0,S__flushbuf,write,2,,62
63,0,S__flushbuf,write,2,,1
64,0,S__flushbuf,write,2,,2
65,0,S__flushbuf,write,2,,62
66,0,S__flushbuf,write,2,,1
67,0,S__flushbuf,write,2,,2
68,0,S__flushbuf,write,2,,62
69,0,S__flushbuf,write,2,,1
70,0,S__flushbuf,write,2,,2
71,0,S__flushbuf,write,2,,62
72,0,S__flushbuf,write,2,,1
73,0,S__flushbuf,write,2,,2
74,0,S__flushbuf,write,2,,62
75,0,S__flushbuf,write,2,,1
76,0,S__flushbuf,write,2,,2
77,0,S__flushbuf,write,2,,62
78,0,S__flushbuf,write,2,,1
79,0,S__flushbuf,write,2,,2
80,0,S__flushbuf,write,2,,62
81,0,S__flushbuf,write,2,,1
82,0,S__flushbuf,write,2,,2
83,0,S__flushbuf,write,2,,62
84,0,S__flushbuf,write,2,,1
85,0,S__flushbuf,write,2,,2
86,0,S__flushbuf,write,2,,62
87,0,S__flushbuf,write,2,,1
88,0,S__flushbuf,write,2,,2
89,0,S__flushbuf,write,2,,62
90,0,S__flushbuf,write,2,,1
91,0,S__flushbuf,write,2,,2
92,0,S__flushbuf,write,2,,62
93,0,S__flushbuf,write,2,,1
94,0,S__flushbuf,write,2,,2
95,0,S__flushbuf,write,2,,62
96,0,S__flushbuf,write,2,,1
97,0,S__flushbuf,write,2,,5
98,0,S__flushbuf,write,2,,1
99,0,S__flushbuf,write,2,,1
100,0,rl_read_key,read,0,,1
Is that what you need?
- Torbjörn
On Tue, May 20, 2008 at 4:49 PM, Jan Wielemaker <wielemak@...> wrote:
> On Tuesday 20 May 2008 16:31, Torbjörn Lager wrote:
>> Here's what happens:
>> :- use_module(library(http/http_open)).
>> :- use_module(library(sgml)).
>>
>> t(Data) :-
>> http_open('http://localhost:5001/pages/assets/examples/test.xml',
>> In, []),
>> read_data(In),
>> close(In).
>>
>> read_data(In) :-
>> repeat,
>> time(get_byte(In, B0)),
>> B0 == -1, !.
>>
>> ?- time(t(_)).
>> % 1 inferences, 0.00 CPU in 0.00 seconds (0% CPU, Infinite Lips)
> <snip>
>> % 1 inferences, 0.00 CPU in 0.00 seconds (0% CPU, Infinite Lips)
>> % 1 inferences, 0.00 CPU in 5.00 seconds (0% CPU, Infinite Lips)
>> % 2,080 inferences, 0.00 CPU in 5.00 seconds (0% CPU, Infinite Lips)
>> true.
>
> Ok. So, somehow detecting end-of-file takes very long!? Typically, it is
> now time to run a system call tracer to see what happens when. I don't
> recall what this is called on MacOS (or even whether it exists as
> default component), but typically they go by the name 'strace', 'truss',
> 'trace' or something sinmilar. Now run "% strace swipl <options>" and
> your program. I think there is by default no timing information
> displayed, but you should notice a call blocking 5 seconds. Can you find
> that call? If its gets too confusing on your terminal, use two. Start
> Prolog on the first, get the PID and attach strace from the other (most
> implementations have options such as -p PID).
>
> --- Jan
>
> P.s. Any other MacOS users suffering from this?
>
> _______________________________________________
> SWI-Prolog mailing list
> SWI-Prolog@...
> https://mailbox.iai.uni-bonn.de/mailman/listinfo.cgi/swi-prolog
>
SWI-Prolog mailing list
SWI-Prolog@...
https://mailbox.iai.uni-bonn.de/mailman/listinfo.cgi/swi-prolog
« Return to Thread: Slowness of http_open/3
| Free Forum Powered by Nabble | Forum Help |
