{"thread":{"id":"50514","subject":"RE: [PATCH 0/1] Fix hang in t5562, introduced in v2.21.0-rc1 (stack traces inside)","startedAt":"2019-02-14T23:34:10Z","lastAt":"2019-02-15T12:59:41Z","messageCount":3,"participants":["Randall S. Becker","Max Kirillov"],"isPatch":true,"patchVersion":1,"patchTotal":1},"messages":[{"id":"369362","messageId":"005b01d4c4bd$c5026ac0$4f074040$@nexbridge.com","threadId":"50514","inReplyTo":null,"subject":"RE: [PATCH 0/1] Fix hang in t5562, introduced in v2.21.0-rc1 (stack traces inside)","fromName":"Randall S. Becker","fromEmail":"rsbecker@nexbridge.com","sentAt":"2019-02-14T23:33:56Z","receivedAt":"2019-02-14T23:34:10Z","isPatch":true,"sender":{"key":"randall.becker@nexbridge.ca","avatar":"https://avatars.githubusercontent.com/u/28956764?v=4"},"body":"On February 14, 2019 17:34, Max Kirillov wrote:\n> To: Randall S. Becker <rsbecker@nexbridge.com>\n> Cc: 'Johannes Schindelin via GitGitGadget' <gitgitgadget@gmail.com>;\n> git@vger.kernel.org; 'Junio C Hamano' <gitster@pobox.com>; 'Max Kirillov'\n> <max@max630.net>\n> Subject: Re: [PATCH 0/1] Fix hang in t5562, introduced in v2.21.0-rc1\n> \n> On Thu, Feb 14, 2019 at 05:17:26PM -0500, Randall S. Becker wrote:\n> > Unfortunately, subtest 13 still hangs on NonStop, even with this\n> > patch, so our Pipeline still hangs. I'm glad it's better on Azure, but\n> > I don't think this actually addresses the root cause of the hang. This\n> > is now the fourth attempt at fixing this. Is it possible this is not\n> > the test that is failing, but actually the git-http-backend? The code\n> > is not in a loop, if that helps. It is not consuming any significant\n> > cycles. I don't know that part of the code at all, sadly. The code is\n> > here:\n> >\n> > * in the operating system from here up *\n> >   cleanup_children + 0x5D0 (UCr)\n> \n> ... so does the process which the stack was taken from has any children\n> processes still?\n> \n> I could imagine if a child somehow manages to end up in uninterruptible\n> sleep, then probably it would never complete this way, wouldn't it?\n\nHere is the full set of traces (from subtest 6, which just hung). There are\nno I/O errors reported on any pipe or file descriptor. There is one git\nprocess waiting for a read to occur but no one is doing any writing. Most\nprocesses are sitting in waitpid, except for the initiating git, which is\nwaiting on a read that never receives data, so everyone is asleep and hung.\nThe git process sitting in read is reading from a PIPE, not a file.\n\nThere are no other processes involved in the test that I can see.\n\nPerl (waiting for output to be read):\n  waitpid + 0x130 (SLr)\n  $n_EnterPriv + 0x280 (Milli)\n  Perl_wait4pid + 0x130 (UCr)\n  Perl_my_pclose + 0x4C0 (UCr)\n  Perl_io_close + 0x180 (UCr)\n  Perl_do_close + 0x620 (UCr)\n  Perl_pp_close + 0xA70 (UCr)\n  Perl_runops_standard + 0xF0 (UCr)\n  S_run_body + 0x870 (UCr)\n  perl_run + 0x2D0 (UCr)\n  main + 0x3D0 (UCr)\n\ngit-http-backend:\n  waitpid + 0x320 (SLr)\n  $n_EnterPriv + 0x280 (Milli)\n  cleanup_children + 0x5D0 (UCr)\n  cleanup_children_on_exit + 0x70 (UCr)\n  git_atexit_dispatch + 0x200 (UCr)\n  __process_atexit_functions + 0xA0 (DLL zcredll)\n  CRE_TERMINATOR_ + 0xB50 (DLL zcredll)\n  exit + 0x2A0 (DLL zcrtldll)\n  die_webcgi + 0x240 (UCr)\n  die_errno + 0x360 (UCr)\n  write_or_die + 0x1C0 (UCr)\n  end_headers + 0x1A0 (UCr)\n  die_webcgi + 0x220 (UCr)\n  die + 0x320 (UCr)\n  inflate_request + 0x520 (UCr)\n  run_service + 0xC20 (UCr)\n  service_rpc + 0x530 (UCr)\n  cmd_main + 0xD00 (UCr)\n  main + 0x190 (UCr)\n\ngit (one of them):\n  read64_ + 0x140 (SLr)\n  $n_EnterPriv + 0x280 (Milli)\n  xread + 0x130 (UCr)\n  read_in_full + 0x130 (UCr)\n  get_packet_data + 0x4B0 (UCr)\n  packet_read_with_status + 0x230 (UCr)\n  packet_reader_read + 0x310 (UCr)\n  receive_needs + 0x300 (UCr)\n  upload_pack + 0x680 (UCr)\n  cmd_upload_pack + 0x830 (UCr)\n  run_builtin + 0x980 (UCr)\n  handle_builtin + 0x570 (UCr)\n  run_argv + 0x210 (UCr)\n  cmd_main + 0x710 (UCr)\n  main + 0x190 (UCr)\n\nbash:\n  waitpid + 0x130 (SLr)\n  $n_EnterPriv + 0x280 (Milli)\n  waitchld + 0x1F0 (UCr)\n  wait_for + 0xFD0 (UCr)\n  execute_command_internal + 0x1990 (UCr)\n  execute_command + 0xC0 (UCr)\n  reader_loop + 0x4F0 (UCr)\n  main + 0x1140 (UCr)\n\ngit (the other one):\n  waitpid + 0x130 (SLr)\n  $n_EnterPriv + 0x280 (Milli)\n  wait_or_whine + 0xE0 (UCr)\n  finish_command + 0x100 (UCr)\n  run_command + 0x1F0 (UCr)\n  execv_dashed_external + 0x800 (UCr)\n  run_argv + 0x250 (UCr)\n  cmd_main + 0x710 (UCr)\n  main + 0x190 (UCr)\n\n\n"},{"id":"369364","messageId":"20190215034735.GF3064@jessie.local","threadId":"50514","inReplyTo":"005b01d4c4bd$c5026ac0$4f074040$@nexbridge.com","subject":"Re: [PATCH 0/1] Fix hang in t5562, introduced in v2.21.0-rc1 (stack traces inside)","fromName":"Max Kirillov","fromEmail":"max@max630.net","sentAt":"2019-02-15T03:47:35Z","receivedAt":"2019-02-15T03:48:03Z","isPatch":true,"sender":{"key":"max@max630.net","avatar":"https://avatars.githubusercontent.com/u/381560?v=4"},"body":"On Thu, Feb 14, 2019 at 06:33:56PM -0500, Randall S. Becker wrote:\n> Here is the full set of traces (from subtest 6, which just hung). There are\n> no I/O errors reported on any pipe or file descriptor. There is one git\n> process waiting for a read to occur but no one is doing any writing. Most\n> processes are sitting in waitpid, except for the initiating git, which is\n> waiting on a read that never receives data, so everyone is asleep and hung.\n> The git process sitting in read is reading from a PIPE, not a file.\n> \n> There are no other processes involved in the test that I can see.\n> \n> Perl (waiting for output to be read):\n>   waitpid + 0x130 (SLr)\n>   $n_EnterPriv + 0x280 (Milli)\n>   Perl_wait4pid + 0x130 (UCr)\n>   Perl_my_pclose + 0x4C0 (UCr)\n>   Perl_io_close + 0x180 (UCr)\n>   Perl_do_close + 0x620 (UCr)\n>   Perl_pp_close + 0xA70 (UCr)\n>   Perl_runops_standard + 0xF0 (UCr)\n>   S_run_body + 0x870 (UCr)\n>   perl_run + 0x2D0 (UCr)\n>   main + 0x3D0 (UCr)\n> \n> git-http-backend:\n>   waitpid + 0x320 (SLr)\n>   $n_EnterPriv + 0x280 (Milli)\n>   cleanup_children + 0x5D0 (UCr)\n>   cleanup_children_on_exit + 0x70 (UCr)\n>   git_atexit_dispatch + 0x200 (UCr)\n>   __process_atexit_functions + 0xA0 (DLL zcredll)\n>   CRE_TERMINATOR_ + 0xB50 (DLL zcredll)\n>   exit + 0x2A0 (DLL zcrtldll)\n>   die_webcgi + 0x240 (UCr)\n>   die_errno + 0x360 (UCr)\n>   write_or_die + 0x1C0 (UCr)\n>   end_headers + 0x1A0 (UCr)\n>   die_webcgi + 0x220 (UCr)\n>   die + 0x320 (UCr)\n>   inflate_request + 0x520 (UCr)\n>   run_service + 0xC20 (UCr)\n>   service_rpc + 0x530 (UCr)\n>   cmd_main + 0xD00 (UCr)\n>   main + 0x190 (UCr)\n> \n> git (one of them):\n>   read64_ + 0x140 (SLr)\n>   $n_EnterPriv + 0x280 (Milli)\n>   xread + 0x130 (UCr)\n>   read_in_full + 0x130 (UCr)\n>   get_packet_data + 0x4B0 (UCr)\n>   packet_read_with_status + 0x230 (UCr)\n>   packet_reader_read + 0x310 (UCr)\n>   receive_needs + 0x300 (UCr)\n>   upload_pack + 0x680 (UCr)\n>   cmd_upload_pack + 0x830 (UCr)\n>   run_builtin + 0x980 (UCr)\n>   handle_builtin + 0x570 (UCr)\n>   run_argv + 0x210 (UCr)\n>   cmd_main + 0x710 (UCr)\n>   main + 0x190 (UCr)\n> \n> bash:\n>   waitpid + 0x130 (SLr)\n>   $n_EnterPriv + 0x280 (Milli)\n>   waitchld + 0x1F0 (UCr)\n>   wait_for + 0xFD0 (UCr)\n>   execute_command_internal + 0x1990 (UCr)\n>   execute_command + 0xC0 (UCr)\n>   reader_loop + 0x4F0 (UCr)\n>   main + 0x1140 (UCr)\n> \n> git (the other one):\n>   waitpid + 0x130 (SLr)\n>   $n_EnterPriv + 0x280 (Milli)\n>   wait_or_whine + 0xE0 (UCr)\n>   finish_command + 0x100 (UCr)\n>   run_command + 0x1F0 (UCr)\n>   execv_dashed_external + 0x800 (UCr)\n>   run_argv + 0x250 (UCr)\n>   cmd_main + 0x710 (UCr)\n>   main + 0x190 (UCr)\n\nThis list does not say which process whose child but it\nseems like #3 is child of #2 and #2 waits for #3, but #3\ndoes not exit. Which is strange because it should have send\nSIGTERM to it. Could the git-upload-pack somehow be masking\nSIGTERM?\n"},{"id":"369380","messageId":"000501d4c52e$4d485320$e7d8f960$@nexbridge.com","threadId":"50514","inReplyTo":"20190215034735.GF3064@jessie.local","subject":"RE: [PATCH 0/1] Fix hang in t5562, introduced in v2.21.0-rc1 (stack traces inside)","fromName":"Randall S. Becker","fromEmail":"rsbecker@nexbridge.com","sentAt":"2019-02-15T12:59:29Z","receivedAt":"2019-02-15T12:59:41Z","isPatch":true,"sender":{"key":"randall.becker@nexbridge.ca","avatar":"https://avatars.githubusercontent.com/u/28956764?v=4"},"body":"On February 14, 2019 22:48, Max Kirillov wrote:\n> To: Randall S. Becker <rsbecker@nexbridge.com>\n> Cc: 'Max Kirillov' <max@max630.net>; 'Johannes Schindelin via\nGitGitGadget'\n> <gitgitgadget@gmail.com>; git@vger.kernel.org; 'Junio C Hamano'\n> <gitster@pobox.com>\n> Subject: Re: [PATCH 0/1] Fix hang in t5562, introduced in v2.21.0-rc1\n(stack\n> traces inside)\n> \n> On Thu, Feb 14, 2019 at 06:33:56PM -0500, Randall S. Becker wrote:\n> > Here is the full set of traces (from subtest 6, which just hung).\n> > There are no I/O errors reported on any pipe or file descriptor. There\n> > is one git process waiting for a read to occur but no one is doing any\n> > writing. Most processes are sitting in waitpid, except for the\n> > initiating git, which is waiting on a read that never receives data, so\n> everyone is asleep and hung.\n> > The git process sitting in read is reading from a PIPE, not a file.\n> >\n> > There are no other processes involved in the test that I can see.\n> >\n> > Perl (waiting for output to be read):\n> >   waitpid + 0x130 (SLr)\n> >   $n_EnterPriv + 0x280 (Milli)\n> >   Perl_wait4pid + 0x130 (UCr)\n> >   Perl_my_pclose + 0x4C0 (UCr)\n> >   Perl_io_close + 0x180 (UCr)\n> >   Perl_do_close + 0x620 (UCr)\n> >   Perl_pp_close + 0xA70 (UCr)\n> >   Perl_runops_standard + 0xF0 (UCr)\n> >   S_run_body + 0x870 (UCr)\n> >   perl_run + 0x2D0 (UCr)\n> >   main + 0x3D0 (UCr)\n> >\n> > git-http-backend:\n> >   waitpid + 0x320 (SLr)\n> >   $n_EnterPriv + 0x280 (Milli)\n> >   cleanup_children + 0x5D0 (UCr)\n> >   cleanup_children_on_exit + 0x70 (UCr)\n> >   git_atexit_dispatch + 0x200 (UCr)\n> >   __process_atexit_functions + 0xA0 (DLL zcredll)\n> >   CRE_TERMINATOR_ + 0xB50 (DLL zcredll)\n> >   exit + 0x2A0 (DLL zcrtldll)\n> >   die_webcgi + 0x240 (UCr)\n> >   die_errno + 0x360 (UCr)\n> >   write_or_die + 0x1C0 (UCr)\n> >   end_headers + 0x1A0 (UCr)\n> >   die_webcgi + 0x220 (UCr)\n> >   die + 0x320 (UCr)\n> >   inflate_request + 0x520 (UCr)\n> >   run_service + 0xC20 (UCr)\n> >   service_rpc + 0x530 (UCr)\n> >   cmd_main + 0xD00 (UCr)\n> >   main + 0x190 (UCr)\n> >\n> > git (one of them):\n> >   read64_ + 0x140 (SLr)\n> >   $n_EnterPriv + 0x280 (Milli)\n> >   xread + 0x130 (UCr)\n> >   read_in_full + 0x130 (UCr)\n> >   get_packet_data + 0x4B0 (UCr)\n> >   packet_read_with_status + 0x230 (UCr)\n> >   packet_reader_read + 0x310 (UCr)\n> >   receive_needs + 0x300 (UCr)\n> >   upload_pack + 0x680 (UCr)\n> >   cmd_upload_pack + 0x830 (UCr)\n> >   run_builtin + 0x980 (UCr)\n> >   handle_builtin + 0x570 (UCr)\n> >   run_argv + 0x210 (UCr)\n> >   cmd_main + 0x710 (UCr)\n> >   main + 0x190 (UCr)\n> >\n> > bash:\n> >   waitpid + 0x130 (SLr)\n> >   $n_EnterPriv + 0x280 (Milli)\n> >   waitchld + 0x1F0 (UCr)\n> >   wait_for + 0xFD0 (UCr)\n> >   execute_command_internal + 0x1990 (UCr)\n> >   execute_command + 0xC0 (UCr)\n> >   reader_loop + 0x4F0 (UCr)\n> >   main + 0x1140 (UCr)\n> >\n> > git (the other one):\n> >   waitpid + 0x130 (SLr)\n> >   $n_EnterPriv + 0x280 (Milli)\n> >   wait_or_whine + 0xE0 (UCr)\n> >   finish_command + 0x100 (UCr)\n> >   run_command + 0x1F0 (UCr)\n> >   execv_dashed_external + 0x800 (UCr)\n> >   run_argv + 0x250 (UCr)\n> >   cmd_main + 0x710 (UCr)\n> >   main + 0x190 (UCr)\n> \n> This list does not say which process whose child but it seems like #3 is\nchild of\n> #2 and #2 waits for #3, but #3 does not exit. Which is strange because it\n> should have send SIGTERM to it. Could the git-upload-pack somehow be\n> masking SIGTERM?\n\nSIGTERM cannot be masked or easily caught on the platform, so I don't think\nthat's it. waitpid fails if the supplied pid is invalid, so it's not that\neither. However, I am not certain SIGPIPE is raised if a waited read is\nposted on a different pipe.\n\n"}]}