[PATCH 0/1] Avoid problem with Git fetcher hanging

[PATCH 0/1] Avoid problem with Git fetcher hanging

[Peter Kjellerstedt]

This fixes a problem we have had for a long time where a build on rare
occasions hangs. The problem was due to the Git fetcher trying to use
git ls-remote to determine the SHA-1 for a tag. If this happened when
pseudo was active, git (or rather ssh) would hang indefinitely.

//Peter

The following changes since commit 54562006c1327c5b99daa4cc05a3ba7e38412da1:

  image_types.bbclass: Fix tar IMAGE_CMD to not change directories (2014-02-18 08:38:52 +0000)

are available in the git repository at:

  git://git.yoctoproject.org/poky-contrib pkj/no_pseudo_for_git
  http://git.yoctoproject.org/cgit.cgi/poky-contrib/log/?h=pkj/no_pseudo_for_git

Peter Kjellerstedt (1):
  bitbake: Disable pseudo in runfetchcmd()

 bitbake/lib/bb/fetch2/__init__.py | 3 +++
 1 file changed, 3 insertions(+)

-- 
1.8.4

[PATCH 1/1] bitbake: Disable pseudo in runfetchcmd()

[Peter Kjellerstedt]

If a fetcher, e.g., git, is run when pseudo is active it will think it
is running as root. If it in turn uses ssh (as git does), ssh too will
think it is running as root. This will cause it to try to read root's
ssh configuration from /root/.ssh which will fail. If ssh then needs to
ask for credentials it will hang indefinitely as there is nowhere for it
to ask the user for them (and even if there was it would not access the
correct private keys).

The solution to the above is to temporarily disable pseudo while
executing any fetcher commands. There should be no reason for them to be
executed under pseudo anyway so this should not be a problem.

Signed-off-by: Peter Kjellerstedt <peter.kjellerstedt@axis.com>
---
 bitbake/lib/bb/fetch2/__init__.py | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/bitbake/lib/bb/fetch2/__init__.py b/bitbake/lib/bb/fetch2/__init__.py
index de95074..1c3ee4f 100644
--- a/bitbake/lib/bb/fetch2/__init__.py
+++ b/bitbake/lib/bb/fetch2/__init__.py
@@ -680,6 +680,9 @@ def runfetchcmd(cmd, d, quiet = False, cleanup = []):
         if val:
             cmd = 'export ' + var + '=\"%s\"; %s' % (val, cmd)
 
+    # Disable pseudo as it may affect ssh, potentially causing it to hang.
+    cmd = 'export PSEUDO_DISABLED=1; ' + cmd
+
     logger.debug(1, "Running %s", cmd)
 
     success = False
-- 
1.8.4

Re: [PATCH 1/1] bitbake: Disable pseudo in runfetchcmd()

[Mark Hatle]

On 2/20/14, 8:55 AM, Peter Kjellerstedt wrote:
> If a fetcher, e.g., git, is run when pseudo is active it will think it
> is running as root. If it in turn uses ssh (as git does), ssh too will
> think it is running as root. This will cause it to try to read root's
> ssh configuration from /root/.ssh which will fail. If ssh then needs to
> ask for credentials it will hang indefinitely as there is nowhere for it
> to ask the user for them (and even if there was it would not access the
> correct private keys).
>
> The solution to the above is to temporarily disable pseudo while
> executing any fetcher commands. There should be no reason for them to be
> executed under pseudo anyway so this should not be a problem.
>
> Signed-off-by: Peter Kjellerstedt <peter.kjellerstedt@axis.com>
> ---
>   bitbake/lib/bb/fetch2/__init__.py | 3 +++
>   1 file changed, 3 insertions(+)
>
> diff --git a/bitbake/lib/bb/fetch2/__init__.py b/bitbake/lib/bb/fetch2/__init__.py
> index de95074..1c3ee4f 100644
> --- a/bitbake/lib/bb/fetch2/__init__.py
> +++ b/bitbake/lib/bb/fetch2/__init__.py
> @@ -680,6 +680,9 @@ def runfetchcmd(cmd, d, quiet = False, cleanup = []):
>           if val:
>               cmd = 'export ' + var + '=\"%s\"; %s' % (val, cmd)
>
> +    # Disable pseudo as it may affect ssh, potentially causing it to hang.
> +    cmd = 'export PSEUDO_DISABLED=1; ' + cmd
> +

This may be a reasonable workaround... but is there any way we can identify the 
offending command and create a reproducer for pseudo?  It would be nice to 
identify what the actual problem is -- as something else in the system may 
encounter it.

--Mark

>       logger.debug(1, "Running %s", cmd)
>
>       success = False
>

Re: [PATCH 1/1] bitbake: Disable pseudo in runfetchcmd()

[Richard Purdie]

On Thu, 2014-02-20 at 15:55 +0100, Peter Kjellerstedt wrote:
> If a fetcher, e.g., git, is run when pseudo is active it will think it
> is running as root. If it in turn uses ssh (as git does), ssh too will
> think it is running as root. This will cause it to try to read root's
> ssh configuration from /root/.ssh which will fail. If ssh then needs to
> ask for credentials it will hang indefinitely as there is nowhere for it
> to ask the user for them (and even if there was it would not access the
> correct private keys).
> 
> The solution to the above is to temporarily disable pseudo while
> executing any fetcher commands. There should be no reason for them to be
> executed under pseudo anyway so this should not be a problem.
> 
> Signed-off-by: Peter Kjellerstedt <peter.kjellerstedt@axis.com>
> ---
>  bitbake/lib/bb/fetch2/__init__.py | 3 +++
>  1 file changed, 3 insertions(+)

I'm more than a little concerned about why pseudo is active during
do_patch. It shouldn't be. Are you doing anything different with pseudo
in your build?

Cheers,

Richard

> diff --git a/bitbake/lib/bb/fetch2/__init__.py b/bitbake/lib/bb/fetch2/__init__.py
> index de95074..1c3ee4f 100644
> --- a/bitbake/lib/bb/fetch2/__init__.py
> +++ b/bitbake/lib/bb/fetch2/__init__.py
> @@ -680,6 +680,9 @@ def runfetchcmd(cmd, d, quiet = False, cleanup = []):
>          if val:
>              cmd = 'export ' + var + '=\"%s\"; %s' % (val, cmd)
>  
> +    # Disable pseudo as it may affect ssh, potentially causing it to hang.
> +    cmd = 'export PSEUDO_DISABLED=1; ' + cmd
> +
>      logger.debug(1, "Running %s", cmd)
>  
>      success = False

Re: [PATCH 1/1] bitbake: Disable pseudo in runfetchcmd()

[Olof Johansson]

On 14-02-22 12:24 +0100, Richard Purdie wrote:
> On Thu, 2014-02-20 at 15:55 +0100, Peter Kjellerstedt wrote:
> > If a fetcher, e.g., git, is run when pseudo is active it will think it
> > is running as root. If it in turn uses ssh (as git does), ssh too will
> > think it is running as root. This will cause it to try to read root's
> > ssh configuration from /root/.ssh which will fail. If ssh then needs to
> > ask for credentials it will hang indefinitely as there is nowhere for it
> > to ask the user for them (and even if there was it would not access the
> > correct private keys).
> > 
> > The solution to the above is to temporarily disable pseudo while
> > executing any fetcher commands. There should be no reason for them to be
> > executed under pseudo anyway so this should not be a problem.
> > 
> > Signed-off-by: Peter Kjellerstedt <peter.kjellerstedt@axis.com>
> > ---
> >  bitbake/lib/bb/fetch2/__init__.py | 3 +++
> >  1 file changed, 3 insertions(+)

I work with Peter, and I'm seeing this issue as well. Sorry for
the delay in response.

> I'm more than a little concerned about why pseudo is active during
> do_patch. It shouldn't be. Are you doing anything different with pseudo
> in your build?

No, not as far as I know. This is the output I'm seeing
currently, where I temporarily replaced "git" with a small shell
script that runs whoami and exits with failure (normally, it
would just hang at this point) (somewhat trimmed for brevity):


....
DEBUG: Starting bitbake-worker
DEBUG: Using cache in '/oe/master/build/cache/bb_codeparser.dat'
ERROR: Failure expanding variable do_patch: ExpansionError: Failure expanding variable do_patch, expression was         cd /oe/master/build/tmp/work/p3367-poky-linux/linux-porky/3.10+axis12-r4.1.1/linux
        export KMETA=${KMETA}

        # if kernel tools are available in-tree, they are preferred
        # and are placed on the path before any external tools. Unless
        # the external tools flag is set, in that case we do nothing.
        if [ -f "/oe/master/build/tmp/work/p3367-poky-linux/linux-porky/3.10+axis12-r4.1.1/linux/scripts/util/configme" ]; then
                if [ -z "${EXTERNAL_KERNEL_TOOLS}" ]; then
                        PATH=/oe/master/build/tmp/work/p3367-poky-linux/linux-porky/3.10+axis12-r4.1.1/linux/scripts/util:/oe/master/scripts:/oe/master/build/tmp/sysroots/x86_64-linux/usr/bin/mipsel-nf-poky-linux:/oe/master/build/tmp/sysroots/p3367/usr/bin/crossscripts:/oe/master/build/tmp/sysroots/x86_64-linux/usr/sbin:/oe/master/build/tmp/sysroots/x86_64-linux/usr/bin:/oe/master/build/tmp/sysroots/x86_64-linux/sbin:/oe/master/build/tmp/sysroots/x86_64-linux/bin:/oe/master/scripts:/oe/master/bitbake/bin:/home/olofjn/bin:/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/sbin:/usr/local/bin:/var/cfengine/bin:/usr/local/mipsisa32r2el/r23/bin
                fi
        fi

        machine_branch="${@ get_machine_branch(d, "master" )}"

        # ...
        # trimmed down output
        # ...
 which triggered exception FetchError: Fetcher failure: Fetch command failed with exit code 1, output:
+ whoami
+ : whoami = root
+ id
+ : id = uid=0(root) gid=0(root) groups=0(root)
+ exit 1

ERROR: Task 100 (/oe/master/meta-porky/recipes-kernel/linux/linux-porky_3.10.bb, do_package_write_rpm) failed with exit code '1'


Note that bitbake complains about do_patch, but the executed task
is actually do_package_write_rpm. I'm not sure what this means.

Any ideas?

-- 
olofjn

Re: [PATCH 1/1] bitbake: Disable pseudo in runfetchcmd()

[Richard Purdie]

On Thu, 2014-03-20 at 16:03 +0100, Olof Johansson wrote:
>I work with Peter, and I'm seeing this issue as well. Sorry for
> the delay in response.
> 
> > I'm more than a little concerned about why pseudo is active during
> > do_patch. It shouldn't be. Are you doing anything different with pseudo
> > in your build?
> 
> No, not as far as I know. This is the output I'm seeing
> currently, where I temporarily replaced "git" with a small shell
> script that runs whoami and exits with failure (normally, it
> would just hang at this point) (somewhat trimmed for brevity):
> 
> 
> ....
> DEBUG: Starting bitbake-worker
> DEBUG: Using cache in '/oe/master/build/cache/bb_codeparser.dat'
> ERROR: Failure expanding variable do_patch: ExpansionError: Failure expanding variable do_patch, expression was         cd /oe/master/build/tmp/work/p3367-poky-linux/linux-porky/3.10+axis12-r4.1.1/linux
>         export KMETA=${KMETA}
> 
>         # if kernel tools are available in-tree, they are preferred
>         # and are placed on the path before any external tools. Unless
>         # the external tools flag is set, in that case we do nothing.
>         if [ -f "/oe/master/build/tmp/work/p3367-poky-linux/linux-porky/3.10+axis12-r4.1.1/linux/scripts/util/configme" ]; then
>                 if [ -z "${EXTERNAL_KERNEL_TOOLS}" ]; then
>                         PATH=/oe/master/build/tmp/work/p3367-poky-linux/linux-porky/3.10+axis12-r4.1.1/linux/scripts/util:/oe/master/scripts:/oe/master/build/tmp/sysroots/x86_64-linux/usr/bin/mipsel-nf-poky-linux:/oe/master/build/tmp/sysroots/p3367/usr/bin/crossscripts:/oe/master/build/tmp/sysroots/x86_64-linux/usr/sbin:/oe/master/build/tmp/sysroots/x86_64-linux/usr/bin:/oe/master/build/tmp/sysroots/x86_64-linux/sbin:/oe/master/build/tmp/sysroots/x86_64-linux/bin:/oe/master/scripts:/oe/master/bitbake/bin:/home/olofjn/bin:/sbin:/bin:/usr/sbin:/usr/bin:/usr/local/sbin:/usr/local/bin:/var/cfengine/bin:/usr/local/mipsisa32r2el/r23/bin
>                 fi
>         fi
> 
>         machine_branch="${@ get_machine_branch(d, "master" )}"
> 
>         # ...
>         # trimmed down output
>         # ...
>  which triggered exception FetchError: Fetcher failure: Fetch command failed with exit code 1, output:
> + whoami
> + : whoami = root
> + id
> + : id = uid=0(root) gid=0(root) groups=0(root)
> + exit 1
> 
> ERROR: Task 100 (/oe/master/meta-porky/recipes-kernel/linux/linux-porky_3.10.bb, do_package_write_rpm) failed with exit code '1'
> 
> 
> Note that bitbake complains about do_patch, but the executed task
> is actually do_package_write_rpm. I'm not sure what this means.
> 
> Any ideas?

The log helps immensely since it shows its "Failure expanding variable
do_patch" so its not running do_patch, it is trying to expand the
variable for some reason when writing the rpm in do_package_write_rpm. 

Are you generating some kind of srpm differently from the normal
usecases?

Cheers,

Richard

Re: [PATCH 1/1] bitbake: Disable pseudo in runfetchcmd()

[Olof Johansson]

Thanks for you quick reply,

On 14-03-20 16:14 +0100, Richard Purdie wrote:
> The log helps immensely since it shows its "Failure expanding variable
> do_patch" so its not running do_patch, it is trying to expand the
> variable for some reason when writing the rpm in do_package_write_rpm. 
> 
> Are you generating some kind of srpm differently from the normal
> usecases?

No we don't, as far as I know (is there something I should look
for?). If this isn't something we are doing, what makes it a
problem for us is the fetching of kernel sources from git over
ssh with key authentication. Not sure how common that is.

-- 
olofjn

Re: [PATCH 1/1] bitbake: Disable pseudo in runfetchcmd()

[Richard Purdie]

On Fri, 2014-03-21 at 09:27 +0100, Olof Johansson wrote:
> On 14-03-20 16:14 +0100, Richard Purdie wrote:
> > The log helps immensely since it shows its "Failure expanding variable
> > do_patch" so its not running do_patch, it is trying to expand the
> > variable for some reason when writing the rpm in do_package_write_rpm. 
> > 
> > Are you generating some kind of srpm differently from the normal
> > usecases?
> 
> No we don't, as far as I know (is there something I should look
> for?). If this isn't something we are doing, what makes it a
> problem for us is the fetching of kernel sources from git over
> ssh with key authentication. Not sure how common that is.

Are you using the archiver classes?

I'm wondering if

http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=2c7d20ce3849aba84e0552f0fc4bde649d96faa9

might resolve the issue.  Somehow you're referencing do_patch in the rpm
write task and I'd like to figure out how. We should not be hitting the
network during anything other than do_fetch...

Cheers,

Richard

Re: [PATCH 1/1] bitbake: Disable pseudo in runfetchcmd()

[Olof Johansson]

On 14-03-22 11:12 +0100, Richard Purdie wrote:
> On Fri, 2014-03-21 at 09:27 +0100, Olof Johansson wrote:
> > On 14-03-20 16:14 +0100, Richard Purdie wrote:
> > > The log helps immensely since it shows its "Failure expanding variable
> > > do_patch" so its not running do_patch, it is trying to expand the
> > > variable for some reason when writing the rpm in do_package_write_rpm. 
> > > 
> > > Are you generating some kind of srpm differently from the normal
> > > usecases?
> > 
> > No we don't, as far as I know (is there something I should look
> > for?). If this isn't something we are doing, what makes it a
> > problem for us is the fetching of kernel sources from git over
> > ssh with key authentication. Not sure how common that is.
> 
> Are you using the archiver classes?

> I'm wondering if
> 
> http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=2c7d20ce3849aba84e0552f0fc4bde649d96faa9
> 
> might resolve the issue.

We don't; grepping for 'archive' in our layer gives me zero hits.
And I can still reproduce the issue.

> Somehow you're referencing do_patch in the rpm write task and
> I'd like to figure out how. We should not be hitting the
> network during anything other than do_fetch...

I added an exit(1) in the git fetcher to get a traceback:

Traceback (most recent call last):
  File "/var/opt/builds/olofjn/oe/master/bitbake/bin/bitbake-worker", line 365, in <module>
    worker.serve()
  File "/var/opt/builds/olofjn/oe/master/bitbake/bin/bitbake-worker", line 267, in serve
    self.handle_item("runtask", self.handle_runtask)
  File "/var/opt/builds/olofjn/oe/master/bitbake/bin/bitbake-worker", line 283, in handle_item
    func(self.queue[(len(item) + 2):index])
  File "/var/opt/builds/olofjn/oe/master/bitbake/bin/bitbake-worker", line 317, in handle_runtask
    pid, pipein, pipeout = fork_off_task(self.cookercfg, self.data, self.workerdata, fn, task, taskname, appends, taskdepdata, quieterrors)
  File "/var/opt/builds/olofjn/oe/master/bitbake/bin/bitbake-worker", line 160, in fork_off_task
    the_data = bb.cache.Cache.loadDataFull(fn, appends, data)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/cache.py", line 398, in loadDataFull
    bb_data = cls.load_bbfile(fn, appends, cfgData)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/cache.py", line 673, in load_bbfile
    bb_data = parse.handle(bbfile, bb_data)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/parse/__init__.py", line 99, in handle
    return h['handle'](fn, data, include)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/parse/parse_py/BBHandler.py", line 169, in handle
    return ast.multi_finalize(fn, d)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/parse/ast.py", line 386, in multi_finalize
    finalize(fn, d)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/parse/ast.py", line 334, in finalize
    bb.parse.siggen.finalise(fn, d, variant)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/siggen.py", line 139, in finalise
    taskdeps = self._build_data(fn, d)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/siggen.py", line 92, in _build_data
    tasklist, gendeps, lookupcache = bb.data.generate_dependencies(d)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/data.py", line 382, in generate_dependencies
    deps[task], values[task] = build_dependencies(task, keys, shelldeps, varflagsexcl, d)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/data.py", line 329, in build_dependencies
    parsedvar = d.expandWithRefs(value, key)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/data_smart.py", line 332, in expandWithRefs
    s = __expand_python_regexp__.sub(varparse.python_sub, s)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/data_smart.py", line 129, in python_sub
    value = utils.better_eval(codeobj, DataContext(self.d))
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/utils.py", line 378, in better_eval
    return eval(source, get_context(), locals)
  File "do_patch", line 1, in <module>
  File "kernel-yocto.bbclass", line 2, in get_machine_branch
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/fetch2/__init__.py", line 1336, in __init__
    self.ud[url] = FetchData(url, d, localonly)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/fetch2/__init__.py", line 1038, in __init__
    self.method.urldata_init(self, d)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/fetch2/git.py", line 137, in urldata_init
    ud.revisions[name] = self.latest_revision(ud, d, name)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/fetch2/__init__.py", line 1307, in latest_revision
    revs[key] = rev = self._latest_revision(ud, d, name)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/fetch2/git.py", line 345, in _latest_revision
    output = self._lsremote(ud, d, search)
  File "/var/opt/builds/olofjn/oe/master/bitbake/lib/bb/fetch2/git.py", line 329, in _lsremote
    exit(1)
  File "/usr/lib/python2.7/site.py", line 374, in __call__
    raise SystemExit(code)
SystemExit: 1
1NOTE: Tasks Summary: Attempted 373 tasks of which 372 didn't need to be rerun and all succeeded.


I also print out the tasklist (__BBTASKS) as seen in data.py's generate_dependencies:

ERROR: tasklist = ['do_patch', 'do_populate_sysroot',
    'do_populate_sysroot_setscene', 'do_listtasks', 'do_clean',
    'do_checkuri', 'do_checkuriall', 'do_fetchall', 'do_fetch',
    'do_unpack', 'do_configure', 'do_compile', 'do_install',
    'do_build', 'do_cleansstate', 'do_cleanall', 'do_package',
    'do_package_setscene', 'do_packagedata',
    'do_packagedata_setscene', 'do_package_write_rpm_setscene',
    'do_package_write_rpm', 'do_devshell', 'do_populate_lic',
    'do_populate_lic_setscene', 'do_deploy_setscene',
    'do_bundle_initramfs', 'do_compile_kernelmodules',
    'do_savedefconfig', 'do_menuconfig', 'do_diffconfig', 'do_strip',
    'do_sizecheck', 'do_uboot_mkimage', 'do_deploy',
    'do_kernel_configme', 'do_kernel_checkout',
    'do_kernel_link_vmlinux', 'do_validate_branches',
    'do_kernel_configcheck', 'do_kernel_link_vmlinuz']

I still don't get why do_patch is expanded, but afaict it tries
to do expansion of all of the tasks in __BBTASKS, and the mere
expansion of the do_patch variable triggers the fetcher to get
things from the network.


-- 
olofjn