On Thu, Feb 11, 2010 at 1:33 PM, Julian Foad <julian.foad_at_wandisco.com> wrote:
> I tried a dry-run merge, using a trunk_at_908933 client, and it hangs with
> Serf, but completes in a few seconds with Neon. (When I say it hangs, an
> identical test except using a trunk build from 2010-02-04 hung for 25
> minutes before I interrupted it.)
>
> The test case here uses a 1.6.x_at_902803 WC, clean except for a local mod
> to the 'STATUS' file. The "##" lines are comments I typed while I was
> waiting, to remind me when I issued the command.
>
> [[[
> $ svn merge --dry-run ^/subversion/branches/1.6.x-r891672/@902803
> --- Merging r891676 through r902803 into '.':
> U subversion/tests/cmdline/externals_tests.py
> ## Started ~10:49 ...
> ^C/home/julianfoad/src/subversion-a/subversion/svn/util.c:900: (apr_err=4)
> /home/julianfoad/src/subversion-a/subversion/libsvn_client/merge.c:9460: (apr_err=4)
> /home/julianfoad/src/subversion-a/subversion/libsvn_client/merge.c:8082: (apr_err=4)
> /home/julianfoad/src/subversion-a/subversion/libsvn_client/merge.c:7753: (apr_err=4)
> /home/julianfoad/src/subversion-a/subversion/libsvn_client/merge.c:4863: (apr_err=4)
> /home/julianfoad/src/subversion-a/subversion/libsvn_ra_serf/update.c:2248: (apr_err=4)
> svn: Error retrieving REPORT (4): Interrupted system call
>
> $ svn merge --dry-run ^/subversion/branches/1.6.x-r891672/@902803 --config-option=servers:global:http-library=neon
> --- Merging r891676 through r902803 into '.':
> U subversion/tests/cmdline/externals_tests.py
> U subversion/libsvn_client/commit_util.c
>
> $ svn merge --dry-run ^/subversion/branches/1.6.x-r891672/@902803 --config-option=servers:global:http-library=neon
> --- Merging r891676 through r902803 into '.':
> U subversion/tests/cmdline/externals_tests.py
> U subversion/libsvn_client/commit_util.c
>
> $ svn merge --dry-run ^/subversion/branches/1.6.x-r891672/@902803 --config-option=servers:global:http-library=serf
> --- Merging r891676 through r902803 into '.':
> U subversion/tests/cmdline/externals_tests.py
> ## Started 11:16 ...
> ]]]
>
> Here's the stack trace if I interrupt it in GDB after about 10 seconds:
> [[[
> --- Merging r891676 through r902803 into '.':
> U subversion/tests/cmdline/externals_tests.py
> ^C
> Program received signal SIGINT, Interrupt.
> 0x0040e422 in __kernel_vsyscall ()
> (gdb) bt
> #0 0x0040e422 in __kernel_vsyscall ()
> #1 0x004dc156 in epoll_wait () from /lib/tls/i686/cmov/libc.so.6
> #2 0x0061d3ad in apr_pollset_poll () from /usr/lib/libapr-1.so.0
> #3 0x00d149e8 in serf_context_run () from /usr/lib/libserf-0.so.0
> #4 0x00af2b9d in finish_report (report_baton=0x966f148, pool=0x966ef30)
> at /home/julianfoad/src/subversion-b/subversion/libsvn_ra_serf/update.c:2237
> #5 0x002eff90 in drive_merge_report_editor (
> target_abspath=0x81b5c70 "/home/julianfoad/src/subversion-1.6.x",
> url1=0x80ad3d0 "https://svn.apache.org/repos/asf/subversion/branches/1.6.x", revision1=891675,
> url2=0x80ad448 "https://svn.apache.org/repos/asf/subversion/branches/1.6.x-r891672",
> revision2=902803, children_with_mergeinfo=0x9123318, depth=svn_depth_infinity,
> notify_b=0xbfffede4, callbacks=0x31be60, merge_b=0xbfffed74, pool=0x966ef30)
> at /home/julianfoad/src/subversion-b/subversion/libsvn_client/merge.c:4863
> #6 0x002f5b76 in do_directory_merge (
> url1=0x80ad3d0 "https://svn.apache.org/repos/asf/subversion/branches/1.6.x", revision1=891675,
> url2=0x80ad448 "https://svn.apache.org/repos/asf/subversion/branches/1.6.x-r891672",
> revision2=902803, target_abspath=0x81b5c70 "/home/julianfoad/src/subversion-1.6.x",
> depth=svn_depth_infinity, squelch_mergeinfo_notifications=0, notify_b=0xbfffede4,
> merge_b=0xbfffed74, pool=0x9123270)
> at /home/julianfoad/src/subversion-b/subversion/libsvn_client/merge.c:7746
> #7 0x002f66cf in do_merge (merge_sources=0x80ac9f0,
> target_abspath=0x81b5c70 "/home/julianfoad/src/subversion-1.6.x", sources_ancestral=1,
> sources_related=1, same_repos=1, ignore_ancestry=0, force=0, dry_run=1, record_only=0,
> reintegrate_merge=0, squelch_mergeinfo_notifications=0, depth=svn_depth_infinity,
> merge_options=0x0, use_sleep=0xbfffef30, ctx=0x808fb60, pool=0x808f200)
> at /home/julianfoad/src/subversion-b/subversion/libsvn_client/merge.c:8079
> #8 0x002fa646 in svn_client_merge_peg3 (
> source=0x81b5968 "https://svn.apache.org/repos/asf/subversion/branches/1.6.x-r891672",
> ranges_to_merge=0x81b5b80, peg_revision=0xbfffefe0, target_wcpath=0x8073548 "",
> depth=svn_depth_unknown, ignore_ancestry=0, force=0, record_only=0, dry_run=1,
> merge_options=0x0, ctx=0x808fb60, pool=0x808f200)
> at /home/julianfoad/src/subversion-b/subversion/libsvn_client/merge.c:9451
> #9 0x0805b0b2 in svn_cl__merge (os=0x808f3a8, baton=0xbffff248, pool=0x808f200)
> at /home/julianfoad/src/subversion-b/subversion/svn/merge-cmd.c:322
> #10 0x0805a53e in main (argc=5, argv=0xbffff394)
> at /home/julianfoad/src/subversion-b/subversion/svn/main.c:2249
> ]]]
>
> If in GDB I step through the big loop in RA-serf's finish_report(),
> pausing in each iteration, then it works [1]. If, however, I break at
> the beginning of the loop, set a breakpoint at the end of the loop, and
> let that loop run through at full speed, then it hangs in
> serf_context_run() in some iteration of the loop. [2]
>
> If I insert debug prints [3], I get:
>
> [[[
> ## ra-serf finish_report() loop:
> ## done=0, fetches=0, propfinds=0, t=-694967296
> ## done=0, num_conns=2, cur_conn=1
> ## done=0, fetches=0, propfinds=0, t=-694967296
> ## done=0, num_conns=2, cur_conn=1
> ## done=0, fetches=0, propfinds=0, t=-694967296
> ## done=0, num_conns=2, cur_conn=1
> ## done=0, fetches=0, propfinds=0, t=-694967296
> ## done=0, num_conns=2, cur_conn=1
> ## done=0, fetches=2, propfinds=0, t=-694967296
> ## done=1, num_conns=2, cur_conn=1
> ## done=1, fetches=2, propfinds=0, t=-694967296
> ## done=1, num_conns=2, cur_conn=1
> [... hundreds of repeats ...]
> ## done=1, fetches=2, propfinds=0, t=-694967296
> ## done=1, num_conns=2, cur_conn=1
> ## done=1, fetches=2, propfinds=0, t=-694967296
> --- Merging r891676 through r902803 into '.':
> U subversion/tests/cmdline/externals_tests.py
> ## done=1, num_conns=2, cur_conn=1
> ## done=1, fetches=1, propfinds=0, t=-694967296
> [... hangs here ...]
> ]]]
>
> The timeout looks wrong, for a start. Could that be the problem?
>
> My Serf is version 0.3.0.
>
[..]
Can you try with serf branch 0.3.x? I fixed a connection cleanup bug
some time ago that caused serf to hang in apr_pollset_poll.
http://serf.googlecode.com/svn/branches/0.3.x/
Lieven
Received on 2010-02-11 14:00:30 CET