Traceback bug in artifact fetch

[staehle]

Hello:

Evaluating BuildStream as a meta build system for an embedded Linux OS, one of the users in my evaluation group attempted to do a first-time build and got this BuildStream traceback/bug. I can't share too much unfortunately, but this is a from-scratch project and is currently using a temporary BuildBarn instance as a caching server only using the instructions here: https://docs.buildstream.build/1.95/using_configuring_cache_server.html / https://github.com/apache/buildstream/tree/1.95.2/.github/compose

This "components/target/rsync" element is fairly far down the element dependency list

    [00:00:00][e062aa1a][   fetch:components/target/rsync.bst   ] BUG     Fetch

        An unhandled exception occured:
    
        Traceback (most recent call last):
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/_scheduler/jobs/job.py", line 441, in child_action
            result = self.child_process()  # pylint: disable=assignment-from-no-return
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/_scheduler/jobs/elementjob.py", line 92, in child_process
            return self._action_cb(self._element)
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/_scheduler/queues/fetchqueue.py", line 77, in _fetch_not_original
            element._fetch(fetch_original=False)
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/element.py", line 2210, in _fetch
            self.__sources.fetch()
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/_elementsources.py", line 225, in fetch
            self.fetch_sources()
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/_elementsources.py", line 254, in fetch_sources
            self._fetch_source(source)
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/_elementsources.py", line 435, in _fetch_source
            source._fetch()
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/source.py", line 911, in _fetch
            self.__do_fetch()
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/source.py", line 1404, in __do_fetch
            self.fetch(**kwargs)
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/downloadablefilesource.py", line 183, in fetch
            sha256 = self._ensure_mirror(
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/downloadablefilesource.py", line 223, in _ensure_mirror
            local_file, new_etag = self.blocking_activity(
          File "/home/builduser/.local/lib/python3.9/site-packages/buildstream/plugin.py", line 653, in blocking_activity
            proc.start()
          File "/usr/lib/python3.9/multiprocessing/process.py", line 121, in start
            self._popen = self._Popen(self)
          File "/usr/lib/python3.9/multiprocessing/context.py", line 291, in _Popen
            return Popen(process_obj)
          File "/usr/lib/python3.9/multiprocessing/popen_forkserver.py", line 35, in __init__
            super().__init__(process_obj)
          File "/usr/lib/python3.9/multiprocessing/popen_fork.py", line 19, in __init__
            self._launch(process_obj)
          File "/usr/lib/python3.9/multiprocessing/popen_forkserver.py", line 47, in _launch
            reduction.dump(process_obj, buf)
          File "/usr/lib/python3.9/multiprocessing/reduction.py", line 60, in dump
            ForkingPickler(file, protocol).dump(obj)
        AttributeError: Can't pickle local object 'ProxyHandler.__init__.<locals>.<lambda>'

I don't see anything amiss in the Docker logs of the BuildBarn server for this component, or around the timestamp this would have happened.

BuildStream version used is 1.95.2.dev0, and unfortunately my user cannot reproduce it, so it might have been a one-time thing. Regardless, thought you should know :)

Is there any other information I can provide about this?

Thanks!

[nanonyme]

I'm worried this has same root as #1761 that bst2 is throwing blocking_activity indiscriminately to a child process. This can result in quite a lot of corner cases.

[cheese]

I met the same error when bst 2.0.0 is run with http{,s}_proxy environment variables set.

[cheese]

Tested 3778522 but the issue still persists.

[nanonyme]

It looks like this is bug is in the other end, hence unrelated to change by @abderrahim

[nanonyme]

@abderrahim I think the problem is we should not be instantiating opener class before child process. The instance is not picklable. The class probably is.

[nanonyme]

Looks like the problem is here:

https://github.com/python/cpython/blob/main/Lib/urllib/request.py#L799

lambda is not picklable.

[nanonyme]

downloadable source probably needs quite invasive redesign to avoid the issue

[nanonyme]

@staehle do you have HTTPS_PROXY or HTTP_PROXY set?

[cheese]

Tested #1820 and bst now runs with http{,s}_proxy environment variables set.

[nanonyme]

I think the work by @abderrahim is still important because if there's exception raised from blocking_activity, it will currently silently debug in a way that is more or less impossible to debug. But my submission should fix your problem. Latest version passes netrc tests as well.

[staehle]

@staehle do you have HTTPS_PROXY or HTTP_PROXY set?

Oh hey, no, we did not.

[nanonyme]

Interesting. The pickling error clearly is related to usage of proxy. Maybe this code in standard library has changed. Anyhow, I did quite a bit of effort to make sure as little as possible of the urllib.request logic happens in parent process which improves picklability.

[staehle]

I can share this now, it's nothing big, but this is the only thing that was in project.conf relating to the BuildBarn artifact server, which was just on a docker container on a dev machine on the internal corp network:

artifacts:
- url: http://10.14.99.50:7981
  type: index
  push: true
- url: http://10.14.99.50:7982
  type: storage
  push: true

This did only happen that one time though like I mentioned -- never saw it again