Re: Subversion trunk (r1078338) HTTP(/WC?) performance problems?

Ivan Zhakov <ivan_at_visualsvn.com> writes:

> That's really interesting. Could you provide similiar strace for neon?

Neon:

     0.000149 sendto(3, "PUT /obj/repo/!svn/wrk/b93b2d01-8"..., 501, 0, NULL, 0) = 501 <0.002280>
     0.002360 lseek(5, 0, SEEK_SET) = 0 <0.000013>
     0.000054 read(5, "SVN\0\0\0\3\1\3\203\1\2\3"..., 4096) = 13 <0.000013>
     0.000061 read(5, ""..., 4096) = 0 <0.000010>
     0.000049 sendto(3, "SVN\0\0\0\3\1\3\203\1\2\3"..., 13, 0, NULL, 0) = 13 <0.000035>
     0.000093 read(5, ""..., 4096) = 0 <0.000012>
     0.000092 poll([{fd=3, events=POLLIN}], 1, 3600000) = 1 ([{fd=3, revents=POLLIN}]) <0.000824>
     0.000885 recvfrom(3, "HTTP/1.1 201 Created\r\nDate: Wed, "..., 4096, 0, NULL, NULL) = 507 <0.000015>
     0.000111 close(5) = 0 <0.000015>
     0.000145 sendto(3, "PROPPATCH /obj/repo/!svn/wrk/b93b"..., 466, 0, NULL, 0) = 466 <0.000035>
     0.000095 sendto(3, "<?xml version=\"1.0\" encoding=\"utf"..., 330, 0, NULL, 0) = 330 <0.000031>
     0.000086 poll([{fd=3, events=POLLIN}], 1, 3600000) = 1 ([{fd=3, revents=POLLIN}]) <0.001402>
     0.001460 recvfrom(3, "HTTP/1.1 207 Multi-Status\r\nDate: "..., 4096, 0, NULL, NULL) = 650 <0.000017>
     0.000110 brk(0xfb0000) = 0xfb0000 <0.000014>
     0.000121 close(6) = 0 <0.000014>
     0.000054 unlink("/tmp/svn-tempfile.tmp") = 0 <0.000048>
     0.000089 unlink("/tmp/svn-yqYh9X") = 0 <0.000047>
     0.000096 getcwd("/home/pm/sw/subversion/obj"..., 4096) = 27 <0.000015>
     0.000069 lstat("zz/f21", {st_mode=S_IFREG|0644, st_size=3, ...}) = 0 <0.000015>
     0.000107 lstat("zz/f21", {st_mode=S_IFREG|0644, st_size=3, ...}) = 0 <0.000013>
     0.000081 open("zz/f21", O_RDONLY) = 5 <0.000016>
     0.000056 fcntl(5, F_GETFD) = 0 <0.000010>
     0.000046 fcntl(5, F_SETFD, FD_CLOEXEC) = 0 <0.000010>
     0.000047 read(5, "\1\2\3"..., 1024) = 3 <0.000012>
     0.000052 close(5) = 0 <0.000012>
     0.000051 stat("zz/f21", {st_mode=S_IFREG|0644, st_size=3, ...}) = 0 <0.000013>
     0.000078 getuid() = 1000 <0.000010>
     0.000042 getgid() = 1000 <0.000010>
     0.000065 write(1, "Adding (bin) zz/f21\n"..., 22) = 22 <0.000023>
     0.000075 open("/tmp/svn-ipIohV", O_RDWR|O_CREAT|O_EXCL, 0600) = 5 <0.000039>
     0.000082 fcntl(5, F_GETFD) = 0 <0.000011>
     0.000045 fcntl(5, F_SETFD, FD_CLOEXEC) = 0 <0.000010>
     0.000048 fstat(5, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0 <0.000010>
     0.000074 chmod("/tmp/svn-ipIohV", 0644) = 0 <0.000017>
     0.000065 open("zz/f21", O_RDONLY) = 6 <0.000014>
     0.000052 fcntl(6, F_GETFD) = 0 <0.000010>
     0.000045 fcntl(6, F_SETFD, FD_CLOEXEC) = 0 <0.000010>
     0.000051 read(6, "\1\2\3"..., 4096) = 3 <0.000012>
     0.000068 read(6, ""..., 4096) = 0 <0.000010>
     0.000047 read(6, ""..., 4096) = 0 <0.000011>
     0.000057 read(6, ""..., 4096) = 0 <0.000011>
     0.000066 write(5, "SVN\0\0\0\3\1\3\203\1\2\3"..., 13) = 13 <0.000037>
     0.000080 fstat(5, {st_mode=S_IFREG|0644, st_size=13, ...}) = 0 <0.000010>
     0.000109 sendto(3, "PUT /obj/repo/!svn/wrk/b93b2d01-8"..., 501, 0, NULL, 0) = 501 <0.000041>

Serf:

     0.000080 writev(4, [{"PUT"...], 38) = 448 <0.003246>
     0.003767 epoll_ctl(3, EPOLL_CTL_DEL, 4, {0, {u32=0, u64=0}}) = 0 <0.000014>
     0.000063 epoll_ctl(3, EPOLL_CTL_ADD, 4, {EPOLLIN, {u32=30583992, u64=30583992}}) = 0 <0.000012>
     0.000055 epoll_wait(3, {{EPOLLIN, {u32=30583992, u64=30583992}}}, 16, 3600000000) = 1 <0.000011>
     0.000071 read(4, "HTTP/1.1 201 Created\r\nDate: Wed, "..., 8000) = 447 <0.000014>
     0.000115 munmap(0x7f56de04a000, 13) = 0 <0.000023>
     0.000067 epoll_ctl(3, EPOLL_CTL_DEL, 4, {0, {u32=0, u64=0}}) = 0 <0.000012>
     0.000053 epoll_ctl(3, EPOLL_CTL_ADD, 4, {EPOLLIN|EPOLLOUT, {u32=30583944, u64=30583944}}) = 0 <0.000012>
     0.000075 epoll_wait(3, {{EPOLLOUT, {u32=30583944, u64=30583944}}}, 16, 3600000000) = 1 <0.000011>
     0.000118 writev(4, [{"PROPPATCH"...], 60) = 584 <0.000047>
     0.000339 writev(4, [{"4b\r\n"... , 5}], 17) = 86 <0.000018>
     0.000167 epoll_ctl(3, EPOLL_CTL_DEL, 4, {0, {u32=0, u64=0}}) = 0 <0.000012>
     0.000058 epoll_ctl(3, EPOLL_CTL_ADD, 4, {EPOLLIN, {u32=30583992, u64=30583992}}) = 0 <0.000012>
     0.000056 epoll_wait(3, {{EPOLLIN, {u32=30583992, u64=30583992}}}, 16, 3600000000) = 1 <0.039952>
     0.040042 read(4, "HTTP/1.1 207 Multi-Status\r\nDate: "..., 8000) = 620 <0.000016>
     0.000168 close(6) = 0 <0.000014>
     0.000057 unlink("/tmp/svn-tempfile.tmp") = 0 <0.000049>
     0.000090 close(5) = 0 <0.000013>
     0.000046 unlink("/tmp/svn-61oBr6") = 0 <0.000052>
     0.000100 getcwd("/home/pm/sw/subversion/obj"..., 4096) = 27 <0.000015>
     0.000068 lstat("zz/f21", {st_mode=S_IFREG|0644, st_size=3, ...}) = 0 <0.000014>
     0.000102 lstat("zz/f21", {st_mode=S_IFREG|0644, st_size=3, ...}) = 0 <0.000012>
     0.000081 open("zz/f21", O_RDONLY) = 5 <0.000014>
     0.000053 fcntl(5, F_GETFD) = 0 <0.000010>
     0.000046 fcntl(5, F_SETFD, FD_CLOEXEC) = 0 <0.000010>
     0.000047 read(5, "\1\2\3"..., 1024) = 3 <0.000012>
     0.000051 close(5) = 0 <0.000011>
     0.000050 stat("zz/f21", {st_mode=S_IFREG|0644, st_size=3, ...}) = 0 <0.000013>
     0.000077 getuid() = 1000 <0.000011>
     0.000045 getgid() = 1000 <0.000010>
     0.000072 write(1, "Adding (bin) zz/f21\n"..., 22) = 22 <0.000021>
     0.000072 open("/tmp/svn-JTckhz", O_RDWR|O_CREAT|O_EXCL, 0600) = 5 <0.000038>
     0.000081 fcntl(5, F_GETFD) = 0 <0.000010>
     0.000045 fcntl(5, F_SETFD, FD_CLOEXEC) = 0 <0.000011>
     0.000049 fstat(5, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0 <0.000011>
     0.000073 chmod("/tmp/svn-JTckhz", 0644) = 0 <0.000018>
     0.000063 open("zz/f21", O_RDONLY) = 6 <0.000014>
     0.000052 fcntl(6, F_GETFD) = 0 <0.000010>
     0.000044 fcntl(6, F_SETFD, FD_CLOEXEC) = 0 <0.000010>
     0.000052 read(6, "\1\2\3"..., 4096) = 3 <0.000012>
     0.000051 read(6, ""..., 4096) = 0 <0.000011>
     0.000046 read(6, ""..., 4096) = 0 <0.000011>
     0.000053 read(6, ""..., 4096) = 0 <0.000011>
     0.000057 epoll_ctl(3, EPOLL_CTL_DEL, 4, {0, {u32=0, u64=0}}) = 0 <0.000012>
     0.000055 epoll_ctl(3, EPOLL_CTL_ADD, 4, {EPOLLIN|EPOLLOUT, {u32=30583944, u64=30583944}}) = 0 <0.000012>
     0.000054 epoll_wait(3, {{EPOLLOUT, {u32=30583944, u64=30583944}}}, 16, 3600000000) = 1 <0.000011>
     0.000054 write(5, "SVN\0\0\0\3\1\3\203\1\2\3"..., 13) = 13 <0.000037>
     0.000081 lseek(5, 0, SEEK_SET) = 0 <0.000012>
     0.000047 stat("/tmp/svn-JTckhz", {st_mode=S_IFREG|0644, st_size=13, ...}) = 0 <0.000014>
     0.000083 mmap(NULL, 13, PROT_READ, MAP_SHARED, 5, 0) = 0x7f56de04a000 <0.000018>
     0.000077 writev(4, [{"PUT"...], 38) = 448 <0.000051>

-- 
Philip