Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Localhost ipv6 mappings still get written into /etc/hosts file even when the container was started in a --ipv6=false network or dockerd has ipv6 disabled altogether #250

Open
1 of 3 tasks
luckcolors opened this issue Mar 8, 2018 · 2 comments

Comments

@luckcolors
Copy link

  • This is a bug report
  • This is a feature request
  • I searched existing issues before opening this one

Expected behavior

When a container is started in a network with ipv6 support disabled all /etc/hosts must not contain ipv6 mappings.

contents of /etc/hosts:

127.0.0.1       localhost
172.1.0.1      4aed2b44d95d

Actual behavior

The hosts file keeps having ipv6 mappings.
contents of /etc/hosts:

127.0.0.1       localhost
::1     localhost ip6-localhost ip6-loopback
fe00::0 ip6-localnet
ff00::0 ip6-mcastprefix
ff02::1 ip6-allnodes
ff02::2 ip6-allrouters
172.1.0.1      4aed2b44d95d

Steps to reproduce the behavior

  1. create a newtwork with the --ipv6=false option.
  2. Start a container in that network.
  3. Look at the /etc/hosts file inside the container.

Output of docker version:

Client:
 Version:       17.12.0-ce
 API version:   1.35
 Go version:    go1.9.2
 Git commit:    c97c6d6
 Built: Wed Dec 27 20:11:19 2017
 OS/Arch:       linux/amd64

Server:
 Engine:
  Version:      17.12.0-ce
  API version:  1.35 (minimum version 1.12)
  Go version:   go1.9.2
  Git commit:   c97c6d6
  Built:        Wed Dec 27 20:09:54 2017
  OS/Arch:      linux/amd64
  Experimental: false

Output of docker info:

Server Version: 17.12.0-ce
Storage Driver: overlay2
 Backing Filesystem: extfs
 Supports d_type: true
 Native Overlay Diff: true
Logging Driver: json-file
Cgroup Driver: cgroupfs
Plugins:
 Volume: local
 Network: bridge host macvlan null overlay
 Log: awslogs fluentd gcplogs gelf journald json-file logentries splunk syslog
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 89623f28b87a6004d4b785663257362d1658a729
runc version: b2567b37d7b75eb4cf325b77297b140ea686ce8f
init version: 949e6fa
Security Options:
 seccomp
  Profile: default
Kernel Version: 4.10.8-std-1
Operating System: Debian GNU/Linux 9 (stretch)
OSType: linux
Architecture: x86_64
CPUs: 6
Total Memory: 7.789GiB
Name: REDACTED
ID: REDACTED
Docker Root Dir: /var/lib/docker
Debug Mode (client): false
Debug Mode (server): false
Registry: https://index.docker.io/v1/
Labels:
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

WARNING: No cpu cfs quota support
WARNING: No cpu cfs period support

Additional environment details (AWS, VirtualBox, physical, etc.)

Scaleway instance based on the docker image.

NOTE: If this is actually working as intended, please consider this issue as a fature request for an option for disabling ipv6 localhost mappings.

@luckcolors luckcolors changed the title Localhost ipv6 mappings still get written into /etc/hosts file even when the container was started in a --ipv6=false network Localhost ipv6 mappings still get written into /etc/hosts file even when the container was started in a --ipv6=false network or docker has ipv6 disabled altoghether Mar 15, 2018
@luckcolors luckcolors changed the title Localhost ipv6 mappings still get written into /etc/hosts file even when the container was started in a --ipv6=false network or docker has ipv6 disabled altoghether Localhost ipv6 mappings still get written into /etc/hosts file even when the container was started in a --ipv6=false network or dockerd has ipv6 disabled altogether Mar 15, 2018
@bdarnell
Copy link

This is problematic because getaddrinfo("localhost", ..., AI_PASSIVE), which is supposed to be used to find addresses to be used with bind(), will return ::1 but bind(::1) will fail with EADDRNOTAVAIL. There's no clean way to distinguish this failure because ipv6 is disabled (which should probably pass silently) from something else like a typo in the requested address (which should raise an exception or otherwise be brought to the user's attention).

I'm not sure whether it's better to fix this by rewriting /etc/hosts to remove ipv6 addresses or for the resolver to do this filtering (or ipv6 should be enabled by default; it's 2019 after all), but either way getaddrinfo shouldn't be returning addresses that won't work.

Note that the AI_ADDRCONFIG flag looks like it might help here, but it's not quite the right thing. It's designed for connect() rather than bind() and will return ipv6 addresses only if there is a non-loopback ipv6 address configured. That means on systems with ipv6 loopback but no external ipv6 connectivity (common outside of docker), the loopback ipv6 address would be incorrectly excluded.

halstead pushed a commit to openembedded/bitbake that referenced this issue Aug 30, 2021
* When using PRSERV_HOST = "localhost:0" inside
  Docker container (tested with ubuntu 20.04 and 21.04) the
  self.loop.run_until_complete never completed, so self.address
  wasn't ever assigned few lines bellow and then
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
  in lib/prserv/serv.py caused a bit ugly exception:

bitbake@599696cd20aa:~/nodistro/honister$ bitbake -k pkgconfig-native
Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/bin/bitbake", line 35, in <module>
    sys.exit(bitbake_main(BitBakeConfigParameters(sys.argv),
  File "/OE/nodistro/honister/bitbake/lib/bb/main.py", line 385, in bitbake_main
    return ui_module.main(server_connection.connection, server_connection.events,
  File "/OE/nodistro/honister/bitbake/lib/bb/ui/knotty.py", line 397, in main
    params.updateToServer(server, os.environ.copy())
  File "/OE/nodistro/honister/bitbake/lib/bb/cookerdata.py", line 75, in updateToServer
    raise Exception("Unable to update the server configuration with local parameters: %s" % error)
Exception: Unable to update the server configuration with local parameters: Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 90, in runCommand
    result = command_method(self, commandline)
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 286, in updateConfig
    command.cooker.updateConfigOpts(options, environment, cmdline)
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 491, in updateConfigOpts
    self.reset()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 1717, in reset
    self.handlePRServ()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 383, in handlePRServ
    self.prhost = prserv.serv.auto_start(self.data)
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 318, in auto_start
    singleton.start()
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 133, in start
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
AttributeError: 'NoneType' object has no attribute 'rsplit'

* the issue was caused by "localhost" being resolved as IPv6 address ::1
  and then asyncio failing to bind it, the same is reproducible with hashserv, but
  hashserve at least shows nice error message:
    bitbake$ bitbake-hashserv -l DEBUG -b localhost:0
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 59, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 53, in main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address

* or by bitbake-prserv in prserv.log:
    bitbake$ bitbake-prserv --start --host=localhost --port=42005
    bitbake$ cat prserv.log
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 55, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 46, in main
        ret=prserv.serv.start_daemon(options.dbfile, options.host, options.port,os.path.abspath(options.logfile), options.read_only)
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 226, in start_daemon
        run_as_daemon(daemon_main, pidfile, os.path.abspath(logfile))
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 202, in run_as_daemon
        func()
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 224, in daemon_main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 42005, 0, 0): cannot assign requested address

* while 127.0.0.1 works fine:
    bitbake$ bitbake-prserv --start --host=127.0.0.1 --port=42005
    bitbake$ cat prserv.log
    DEBUG: Listening on ('127.0.0.1', 42005)
    2021-08-26 22:28:05,828 Listening on ('127.0.0.1', 42005)
    DEBUG: Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    2021-08-26 22:28:05,829 Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    NOTE: Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39
    2021-08-26 22:28:05,831 Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39

  but 127.0.0.1:0 wasn't handled as "autostart" like localhost:0 is
  update is_local_special to allow that

* /etc/hosts file generated by docker contails localhost for both IPv4 and IPv6:
  $ grep localhost /etc/hosts
  127.0.0.1       localhost
  ::1     localhost ip6-localhost ip6-loopback

  even when ipv6 is disabled in dockerd as reported in:
  docker/for-linux#250

* add a check for self.prserv.address to provide better error message:
  ERROR: Unable to start PR Server, exitting
  when something bad happens, but in this case you still need to read
  bitbake-cookerdaemon.log to see the actuall error, in this case:

90 22:30:39.008441 --- Starting bitbake server pid 90 at 2021-08-26 22:30:39.008419 ---
90 22:30:39.023734 Started bitbake server pid 90
90 22:30:39.024286 Entering server connection loop
90 22:30:39.024753 Accepting [<socket.socket fd=6, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0, laddr=bitbake.sock>] ([])
90 22:30:39.026314 Processing Client
90 22:30:39.026456 Connecting Client
90 22:30:39.027509 Running command ['setFeatures', [2]]
90 22:30:39.027757 Command Completed
90 22:30:39.028711 Running command ['updateConfig', {'abort': False, 'force': False, 'invalidate_stamp': None, 'dry_run': False, 'dump_signatures': [], 'extra_assume_provided': [], 'profile': False, 'prefile': [], 'postfile': [], 'server_timeout': None, 'nosetscene': False, 'setsceneonly': False, 'skipsetscene': False, 'runall': None, 'runonly': None, 'writeeventlog': None, 'build_verbose_shell': False, 'build_verbose_stdout': False, 'default_loglevel': 20, 'debug_domains': {}}, {'DISTRO': '', 'PWD': '/OE/nodistro/honister', 'HOME': '/OE', 'MACHINE': 'qemux86', 'BB_ENV_EXTRAWHITE': 'MACHINE DISTRO TCMODE TCLIBC http_proxy ftp_proxy https_proxy all_proxy ALL_PROXY no_proxy SSH_AGENT_PID SSH_AUTH_SOCK BB_SRCREV_POLICY SDKMACHINE BB_NUMBER_THREADS PARALLEL_MAKE GIT_PROXY_COMMAND GIT_PROXY_IGNORE SOCKS5_PASSWD SOCKS5_USER WEBOS_DISTRO_BUILD_ID PSEUDO_DISABLED PSEUDO_BUILD', 'PATH': '/OE/nodistro/honister/oe-core/scripts:/OE/nodistro/honister/bitbake/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', 'LC_ALL': 'en_US.UTF-8', 'MACHINES': 'qemux86', 'HOSTNAME': '6a439759e3c6', 'TOPDIR': '/OE/nodistro/honister', 'LANG': 'en_US.UTF-8', 'TERM': 'xterm', 'SHLVL': '1', 'BITBAKE_HOME': '/OE', 'BUILDDIR': '/OE/nodistro/honister/BUILD', 'OLDPWD': '/OE/nodistro/honister/bitbake', '_': '/OE/nodistro/honister/bitbake/bin/bitbake'}, ['/OE/nodistro/honister/bitbake/bin/bitbake', '-k', 'zlib-native']]
Process Process-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 255, in run
    self.start()
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
    self.server = self.loop.run_until_complete(server_coro)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
    return await loop.create_server(factory, host, port, **kwds)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
    raise OSError(err.errno, 'error while attempting '
OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address
90 22:30:39.530037 Command Completed
90 22:30:39.530913 Processing Client
90 22:30:39.531023 Disconnecting Client
90 22:30:39.531638 No timeout, exiting.
90 22:30:39.632137 Exiting
90 22:30:39.637562 Original lockfile contents: ['90\n']
90 22:30:39.638107 Exiting as we could obtain the lock

Signed-off-by: Martin Jansa <[email protected]>
Signed-off-by: Richard Purdie <[email protected]>
jpuhlman pushed a commit to MontaVista-OpenSourceTechnology/poky that referenced this issue Aug 31, 2021
…lhost:0"

* When using PRSERV_HOST = "localhost:0" inside
  Docker container (tested with ubuntu 20.04 and 21.04) the
  self.loop.run_until_complete never completed, so self.address
  wasn't ever assigned few lines bellow and then
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
  in lib/prserv/serv.py caused a bit ugly exception:

bitbake@599696cd20aa:~/nodistro/honister$ bitbake -k pkgconfig-native
Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/bin/bitbake", line 35, in <module>
    sys.exit(bitbake_main(BitBakeConfigParameters(sys.argv),
  File "/OE/nodistro/honister/bitbake/lib/bb/main.py", line 385, in bitbake_main
    return ui_module.main(server_connection.connection, server_connection.events,
  File "/OE/nodistro/honister/bitbake/lib/bb/ui/knotty.py", line 397, in main
    params.updateToServer(server, os.environ.copy())
  File "/OE/nodistro/honister/bitbake/lib/bb/cookerdata.py", line 75, in updateToServer
    raise Exception("Unable to update the server configuration with local parameters: %s" % error)
Exception: Unable to update the server configuration with local parameters: Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 90, in runCommand
    result = command_method(self, commandline)
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 286, in updateConfig
    command.cooker.updateConfigOpts(options, environment, cmdline)
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 491, in updateConfigOpts
    self.reset()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 1717, in reset
    self.handlePRServ()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 383, in handlePRServ
    self.prhost = prserv.serv.auto_start(self.data)
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 318, in auto_start
    singleton.start()
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 133, in start
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
AttributeError: 'NoneType' object has no attribute 'rsplit'

* the issue was caused by "localhost" being resolved as IPv6 address ::1
  and then asyncio failing to bind it, the same is reproducible with hashserv, but
  hashserve at least shows nice error message:
    bitbake$ bitbake-hashserv -l DEBUG -b localhost:0
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 59, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 53, in main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address

* or by bitbake-prserv in prserv.log:
    bitbake$ bitbake-prserv --start --host=localhost --port=42005
    bitbake$ cat prserv.log
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 55, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 46, in main
        ret=prserv.serv.start_daemon(options.dbfile, options.host, options.port,os.path.abspath(options.logfile), options.read_only)
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 226, in start_daemon
        run_as_daemon(daemon_main, pidfile, os.path.abspath(logfile))
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 202, in run_as_daemon
        func()
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 224, in daemon_main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 42005, 0, 0): cannot assign requested address

* while 127.0.0.1 works fine:
    bitbake$ bitbake-prserv --start --host=127.0.0.1 --port=42005
    bitbake$ cat prserv.log
    DEBUG: Listening on ('127.0.0.1', 42005)
    2021-08-26 22:28:05,828 Listening on ('127.0.0.1', 42005)
    DEBUG: Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    2021-08-26 22:28:05,829 Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    NOTE: Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39
    2021-08-26 22:28:05,831 Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39

  but 127.0.0.1:0 wasn't handled as "autostart" like localhost:0 is
  update is_local_special to allow that

* /etc/hosts file generated by docker contails localhost for both IPv4 and IPv6:
  $ grep localhost /etc/hosts
  127.0.0.1       localhost
  ::1     localhost ip6-localhost ip6-loopback

  even when ipv6 is disabled in dockerd as reported in:
  docker/for-linux#250

* add a check for self.prserv.address to provide better error message:
  ERROR: Unable to start PR Server, exitting
  when something bad happens, but in this case you still need to read
  bitbake-cookerdaemon.log to see the actuall error, in this case:

90 22:30:39.008441 --- Starting bitbake server pid 90 at 2021-08-26 22:30:39.008419 ---
90 22:30:39.023734 Started bitbake server pid 90
90 22:30:39.024286 Entering server connection loop
90 22:30:39.024753 Accepting [<socket.socket fd=6, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0, laddr=bitbake.sock>] ([])
90 22:30:39.026314 Processing Client
90 22:30:39.026456 Connecting Client
90 22:30:39.027509 Running command ['setFeatures', [2]]
90 22:30:39.027757 Command Completed
90 22:30:39.028711 Running command ['updateConfig', {'abort': False, 'force': False, 'invalidate_stamp': None, 'dry_run': False, 'dump_signatures': [], 'extra_assume_provided': [], 'profile': False, 'prefile': [], 'postfile': [], 'server_timeout': None, 'nosetscene': False, 'setsceneonly': False, 'skipsetscene': False, 'runall': None, 'runonly': None, 'writeeventlog': None, 'build_verbose_shell': False, 'build_verbose_stdout': False, 'default_loglevel': 20, 'debug_domains': {}}, {'DISTRO': '', 'PWD': '/OE/nodistro/honister', 'HOME': '/OE', 'MACHINE': 'qemux86', 'BB_ENV_EXTRAWHITE': 'MACHINE DISTRO TCMODE TCLIBC http_proxy ftp_proxy https_proxy all_proxy ALL_PROXY no_proxy SSH_AGENT_PID SSH_AUTH_SOCK BB_SRCREV_POLICY SDKMACHINE BB_NUMBER_THREADS PARALLEL_MAKE GIT_PROXY_COMMAND GIT_PROXY_IGNORE SOCKS5_PASSWD SOCKS5_USER WEBOS_DISTRO_BUILD_ID PSEUDO_DISABLED PSEUDO_BUILD', 'PATH': '/OE/nodistro/honister/oe-core/scripts:/OE/nodistro/honister/bitbake/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', 'LC_ALL': 'en_US.UTF-8', 'MACHINES': 'qemux86', 'HOSTNAME': '6a439759e3c6', 'TOPDIR': '/OE/nodistro/honister', 'LANG': 'en_US.UTF-8', 'TERM': 'xterm', 'SHLVL': '1', 'BITBAKE_HOME': '/OE', 'BUILDDIR': '/OE/nodistro/honister/BUILD', 'OLDPWD': '/OE/nodistro/honister/bitbake', '_': '/OE/nodistro/honister/bitbake/bin/bitbake'}, ['/OE/nodistro/honister/bitbake/bin/bitbake', '-k', 'zlib-native']]
Process Process-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 255, in run
    self.start()
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
    self.server = self.loop.run_until_complete(server_coro)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
    return await loop.create_server(factory, host, port, **kwds)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
    raise OSError(err.errno, 'error while attempting '
OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address
90 22:30:39.530037 Command Completed
90 22:30:39.530913 Processing Client
90 22:30:39.531023 Disconnecting Client
90 22:30:39.531638 No timeout, exiting.
90 22:30:39.632137 Exiting
90 22:30:39.637562 Original lockfile contents: ['90\n']
90 22:30:39.638107 Exiting as we could obtain the lock

(Bitbake rev: 31df93017b82510d25ced80ee66317d77e4b3ebf)

Signed-off-by: Martin Jansa <[email protected]>
Signed-off-by: Richard Purdie <[email protected]>
kraj pushed a commit to YoeDistro/poky-old that referenced this issue Sep 1, 2021
…lhost:0"

* When using PRSERV_HOST = "localhost:0" inside
  Docker container (tested with ubuntu 20.04 and 21.04) the
  self.loop.run_until_complete never completed, so self.address
  wasn't ever assigned few lines bellow and then
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
  in lib/prserv/serv.py caused a bit ugly exception:

bitbake@599696cd20aa:~/nodistro/honister$ bitbake -k pkgconfig-native
Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/bin/bitbake", line 35, in <module>
    sys.exit(bitbake_main(BitBakeConfigParameters(sys.argv),
  File "/OE/nodistro/honister/bitbake/lib/bb/main.py", line 385, in bitbake_main
    return ui_module.main(server_connection.connection, server_connection.events,
  File "/OE/nodistro/honister/bitbake/lib/bb/ui/knotty.py", line 397, in main
    params.updateToServer(server, os.environ.copy())
  File "/OE/nodistro/honister/bitbake/lib/bb/cookerdata.py", line 75, in updateToServer
    raise Exception("Unable to update the server configuration with local parameters: %s" % error)
Exception: Unable to update the server configuration with local parameters: Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 90, in runCommand
    result = command_method(self, commandline)
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 286, in updateConfig
    command.cooker.updateConfigOpts(options, environment, cmdline)
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 491, in updateConfigOpts
    self.reset()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 1717, in reset
    self.handlePRServ()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 383, in handlePRServ
    self.prhost = prserv.serv.auto_start(self.data)
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 318, in auto_start
    singleton.start()
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 133, in start
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
AttributeError: 'NoneType' object has no attribute 'rsplit'

* the issue was caused by "localhost" being resolved as IPv6 address ::1
  and then asyncio failing to bind it, the same is reproducible with hashserv, but
  hashserve at least shows nice error message:
    bitbake$ bitbake-hashserv -l DEBUG -b localhost:0
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 59, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 53, in main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address

* or by bitbake-prserv in prserv.log:
    bitbake$ bitbake-prserv --start --host=localhost --port=42005
    bitbake$ cat prserv.log
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 55, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 46, in main
        ret=prserv.serv.start_daemon(options.dbfile, options.host, options.port,os.path.abspath(options.logfile), options.read_only)
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 226, in start_daemon
        run_as_daemon(daemon_main, pidfile, os.path.abspath(logfile))
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 202, in run_as_daemon
        func()
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 224, in daemon_main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 42005, 0, 0): cannot assign requested address

* while 127.0.0.1 works fine:
    bitbake$ bitbake-prserv --start --host=127.0.0.1 --port=42005
    bitbake$ cat prserv.log
    DEBUG: Listening on ('127.0.0.1', 42005)
    2021-08-26 22:28:05,828 Listening on ('127.0.0.1', 42005)
    DEBUG: Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    2021-08-26 22:28:05,829 Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    NOTE: Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39
    2021-08-26 22:28:05,831 Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39

  but 127.0.0.1:0 wasn't handled as "autostart" like localhost:0 is
  update is_local_special to allow that

* /etc/hosts file generated by docker contails localhost for both IPv4 and IPv6:
  $ grep localhost /etc/hosts
  127.0.0.1       localhost
  ::1     localhost ip6-localhost ip6-loopback

  even when ipv6 is disabled in dockerd as reported in:
  docker/for-linux#250

* add a check for self.prserv.address to provide better error message:
  ERROR: Unable to start PR Server, exitting
  when something bad happens, but in this case you still need to read
  bitbake-cookerdaemon.log to see the actuall error, in this case:

90 22:30:39.008441 --- Starting bitbake server pid 90 at 2021-08-26 22:30:39.008419 ---
90 22:30:39.023734 Started bitbake server pid 90
90 22:30:39.024286 Entering server connection loop
90 22:30:39.024753 Accepting [<socket.socket fd=6, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0, laddr=bitbake.sock>] ([])
90 22:30:39.026314 Processing Client
90 22:30:39.026456 Connecting Client
90 22:30:39.027509 Running command ['setFeatures', [2]]
90 22:30:39.027757 Command Completed
90 22:30:39.028711 Running command ['updateConfig', {'abort': False, 'force': False, 'invalidate_stamp': None, 'dry_run': False, 'dump_signatures': [], 'extra_assume_provided': [], 'profile': False, 'prefile': [], 'postfile': [], 'server_timeout': None, 'nosetscene': False, 'setsceneonly': False, 'skipsetscene': False, 'runall': None, 'runonly': None, 'writeeventlog': None, 'build_verbose_shell': False, 'build_verbose_stdout': False, 'default_loglevel': 20, 'debug_domains': {}}, {'DISTRO': '', 'PWD': '/OE/nodistro/honister', 'HOME': '/OE', 'MACHINE': 'qemux86', 'BB_ENV_EXTRAWHITE': 'MACHINE DISTRO TCMODE TCLIBC http_proxy ftp_proxy https_proxy all_proxy ALL_PROXY no_proxy SSH_AGENT_PID SSH_AUTH_SOCK BB_SRCREV_POLICY SDKMACHINE BB_NUMBER_THREADS PARALLEL_MAKE GIT_PROXY_COMMAND GIT_PROXY_IGNORE SOCKS5_PASSWD SOCKS5_USER WEBOS_DISTRO_BUILD_ID PSEUDO_DISABLED PSEUDO_BUILD', 'PATH': '/OE/nodistro/honister/oe-core/scripts:/OE/nodistro/honister/bitbake/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', 'LC_ALL': 'en_US.UTF-8', 'MACHINES': 'qemux86', 'HOSTNAME': '6a439759e3c6', 'TOPDIR': '/OE/nodistro/honister', 'LANG': 'en_US.UTF-8', 'TERM': 'xterm', 'SHLVL': '1', 'BITBAKE_HOME': '/OE', 'BUILDDIR': '/OE/nodistro/honister/BUILD', 'OLDPWD': '/OE/nodistro/honister/bitbake', '_': '/OE/nodistro/honister/bitbake/bin/bitbake'}, ['/OE/nodistro/honister/bitbake/bin/bitbake', '-k', 'zlib-native']]
Process Process-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 255, in run
    self.start()
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
    self.server = self.loop.run_until_complete(server_coro)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
    return await loop.create_server(factory, host, port, **kwds)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
    raise OSError(err.errno, 'error while attempting '
OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address
90 22:30:39.530037 Command Completed
90 22:30:39.530913 Processing Client
90 22:30:39.531023 Disconnecting Client
90 22:30:39.531638 No timeout, exiting.
90 22:30:39.632137 Exiting
90 22:30:39.637562 Original lockfile contents: ['90\n']
90 22:30:39.638107 Exiting as we could obtain the lock

(Bitbake rev: 31df93017b82510d25ced80ee66317d77e4b3ebf)

Signed-off-by: Martin Jansa <[email protected]>
Signed-off-by: Richard Purdie <[email protected]>
jpuhlman pushed a commit to MontaVista-OpenSourceTechnology/poky that referenced this issue Sep 1, 2021
…lhost:0"

* When using PRSERV_HOST = "localhost:0" inside
  Docker container (tested with ubuntu 20.04 and 21.04) the
  self.loop.run_until_complete never completed, so self.address
  wasn't ever assigned few lines bellow and then
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
  in lib/prserv/serv.py caused a bit ugly exception:

bitbake@599696cd20aa:~/nodistro/honister$ bitbake -k pkgconfig-native
Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/bin/bitbake", line 35, in <module>
    sys.exit(bitbake_main(BitBakeConfigParameters(sys.argv),
  File "/OE/nodistro/honister/bitbake/lib/bb/main.py", line 385, in bitbake_main
    return ui_module.main(server_connection.connection, server_connection.events,
  File "/OE/nodistro/honister/bitbake/lib/bb/ui/knotty.py", line 397, in main
    params.updateToServer(server, os.environ.copy())
  File "/OE/nodistro/honister/bitbake/lib/bb/cookerdata.py", line 75, in updateToServer
    raise Exception("Unable to update the server configuration with local parameters: %s" % error)
Exception: Unable to update the server configuration with local parameters: Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 90, in runCommand
    result = command_method(self, commandline)
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 286, in updateConfig
    command.cooker.updateConfigOpts(options, environment, cmdline)
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 491, in updateConfigOpts
    self.reset()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 1717, in reset
    self.handlePRServ()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 383, in handlePRServ
    self.prhost = prserv.serv.auto_start(self.data)
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 318, in auto_start
    singleton.start()
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 133, in start
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
AttributeError: 'NoneType' object has no attribute 'rsplit'

* the issue was caused by "localhost" being resolved as IPv6 address ::1
  and then asyncio failing to bind it, the same is reproducible with hashserv, but
  hashserve at least shows nice error message:
    bitbake$ bitbake-hashserv -l DEBUG -b localhost:0
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 59, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 53, in main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address

* or by bitbake-prserv in prserv.log:
    bitbake$ bitbake-prserv --start --host=localhost --port=42005
    bitbake$ cat prserv.log
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 55, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 46, in main
        ret=prserv.serv.start_daemon(options.dbfile, options.host, options.port,os.path.abspath(options.logfile), options.read_only)
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 226, in start_daemon
        run_as_daemon(daemon_main, pidfile, os.path.abspath(logfile))
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 202, in run_as_daemon
        func()
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 224, in daemon_main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 42005, 0, 0): cannot assign requested address

* while 127.0.0.1 works fine:
    bitbake$ bitbake-prserv --start --host=127.0.0.1 --port=42005
    bitbake$ cat prserv.log
    DEBUG: Listening on ('127.0.0.1', 42005)
    2021-08-26 22:28:05,828 Listening on ('127.0.0.1', 42005)
    DEBUG: Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    2021-08-26 22:28:05,829 Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    NOTE: Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39
    2021-08-26 22:28:05,831 Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39

  but 127.0.0.1:0 wasn't handled as "autostart" like localhost:0 is
  update is_local_special to allow that

* /etc/hosts file generated by docker contails localhost for both IPv4 and IPv6:
  $ grep localhost /etc/hosts
  127.0.0.1       localhost
  ::1     localhost ip6-localhost ip6-loopback

  even when ipv6 is disabled in dockerd as reported in:
  docker/for-linux#250

* add a check for self.prserv.address to provide better error message:
  ERROR: Unable to start PR Server, exitting
  when something bad happens, but in this case you still need to read
  bitbake-cookerdaemon.log to see the actuall error, in this case:

90 22:30:39.008441 --- Starting bitbake server pid 90 at 2021-08-26 22:30:39.008419 ---
90 22:30:39.023734 Started bitbake server pid 90
90 22:30:39.024286 Entering server connection loop
90 22:30:39.024753 Accepting [<socket.socket fd=6, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0, laddr=bitbake.sock>] ([])
90 22:30:39.026314 Processing Client
90 22:30:39.026456 Connecting Client
90 22:30:39.027509 Running command ['setFeatures', [2]]
90 22:30:39.027757 Command Completed
90 22:30:39.028711 Running command ['updateConfig', {'abort': False, 'force': False, 'invalidate_stamp': None, 'dry_run': False, 'dump_signatures': [], 'extra_assume_provided': [], 'profile': False, 'prefile': [], 'postfile': [], 'server_timeout': None, 'nosetscene': False, 'setsceneonly': False, 'skipsetscene': False, 'runall': None, 'runonly': None, 'writeeventlog': None, 'build_verbose_shell': False, 'build_verbose_stdout': False, 'default_loglevel': 20, 'debug_domains': {}}, {'DISTRO': '', 'PWD': '/OE/nodistro/honister', 'HOME': '/OE', 'MACHINE': 'qemux86', 'BB_ENV_EXTRAWHITE': 'MACHINE DISTRO TCMODE TCLIBC http_proxy ftp_proxy https_proxy all_proxy ALL_PROXY no_proxy SSH_AGENT_PID SSH_AUTH_SOCK BB_SRCREV_POLICY SDKMACHINE BB_NUMBER_THREADS PARALLEL_MAKE GIT_PROXY_COMMAND GIT_PROXY_IGNORE SOCKS5_PASSWD SOCKS5_USER WEBOS_DISTRO_BUILD_ID PSEUDO_DISABLED PSEUDO_BUILD', 'PATH': '/OE/nodistro/honister/oe-core/scripts:/OE/nodistro/honister/bitbake/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', 'LC_ALL': 'en_US.UTF-8', 'MACHINES': 'qemux86', 'HOSTNAME': '6a439759e3c6', 'TOPDIR': '/OE/nodistro/honister', 'LANG': 'en_US.UTF-8', 'TERM': 'xterm', 'SHLVL': '1', 'BITBAKE_HOME': '/OE', 'BUILDDIR': '/OE/nodistro/honister/BUILD', 'OLDPWD': '/OE/nodistro/honister/bitbake', '_': '/OE/nodistro/honister/bitbake/bin/bitbake'}, ['/OE/nodistro/honister/bitbake/bin/bitbake', '-k', 'zlib-native']]
Process Process-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 255, in run
    self.start()
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
    self.server = self.loop.run_until_complete(server_coro)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
    return await loop.create_server(factory, host, port, **kwds)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
    raise OSError(err.errno, 'error while attempting '
OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address
90 22:30:39.530037 Command Completed
90 22:30:39.530913 Processing Client
90 22:30:39.531023 Disconnecting Client
90 22:30:39.531638 No timeout, exiting.
90 22:30:39.632137 Exiting
90 22:30:39.637562 Original lockfile contents: ['90\n']
90 22:30:39.638107 Exiting as we could obtain the lock

(Bitbake rev: 31df93017b82510d25ced80ee66317d77e4b3ebf)

Signed-off-by: Martin Jansa <[email protected]>
Signed-off-by: Richard Purdie <[email protected]>
kraj pushed a commit to YoeDistro/poky-old that referenced this issue Sep 1, 2021
…lhost:0"

* When using PRSERV_HOST = "localhost:0" inside
  Docker container (tested with ubuntu 20.04 and 21.04) the
  self.loop.run_until_complete never completed, so self.address
  wasn't ever assigned few lines bellow and then
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
  in lib/prserv/serv.py caused a bit ugly exception:

bitbake@599696cd20aa:~/nodistro/honister$ bitbake -k pkgconfig-native
Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/bin/bitbake", line 35, in <module>
    sys.exit(bitbake_main(BitBakeConfigParameters(sys.argv),
  File "/OE/nodistro/honister/bitbake/lib/bb/main.py", line 385, in bitbake_main
    return ui_module.main(server_connection.connection, server_connection.events,
  File "/OE/nodistro/honister/bitbake/lib/bb/ui/knotty.py", line 397, in main
    params.updateToServer(server, os.environ.copy())
  File "/OE/nodistro/honister/bitbake/lib/bb/cookerdata.py", line 75, in updateToServer
    raise Exception("Unable to update the server configuration with local parameters: %s" % error)
Exception: Unable to update the server configuration with local parameters: Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 90, in runCommand
    result = command_method(self, commandline)
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 286, in updateConfig
    command.cooker.updateConfigOpts(options, environment, cmdline)
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 491, in updateConfigOpts
    self.reset()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 1717, in reset
    self.handlePRServ()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 383, in handlePRServ
    self.prhost = prserv.serv.auto_start(self.data)
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 318, in auto_start
    singleton.start()
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 133, in start
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
AttributeError: 'NoneType' object has no attribute 'rsplit'

* the issue was caused by "localhost" being resolved as IPv6 address ::1
  and then asyncio failing to bind it, the same is reproducible with hashserv, but
  hashserve at least shows nice error message:
    bitbake$ bitbake-hashserv -l DEBUG -b localhost:0
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 59, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 53, in main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address

* or by bitbake-prserv in prserv.log:
    bitbake$ bitbake-prserv --start --host=localhost --port=42005
    bitbake$ cat prserv.log
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 55, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 46, in main
        ret=prserv.serv.start_daemon(options.dbfile, options.host, options.port,os.path.abspath(options.logfile), options.read_only)
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 226, in start_daemon
        run_as_daemon(daemon_main, pidfile, os.path.abspath(logfile))
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 202, in run_as_daemon
        func()
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 224, in daemon_main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 42005, 0, 0): cannot assign requested address

* while 127.0.0.1 works fine:
    bitbake$ bitbake-prserv --start --host=127.0.0.1 --port=42005
    bitbake$ cat prserv.log
    DEBUG: Listening on ('127.0.0.1', 42005)
    2021-08-26 22:28:05,828 Listening on ('127.0.0.1', 42005)
    DEBUG: Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    2021-08-26 22:28:05,829 Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    NOTE: Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39
    2021-08-26 22:28:05,831 Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39

  but 127.0.0.1:0 wasn't handled as "autostart" like localhost:0 is
  update is_local_special to allow that

* /etc/hosts file generated by docker contails localhost for both IPv4 and IPv6:
  $ grep localhost /etc/hosts
  127.0.0.1       localhost
  ::1     localhost ip6-localhost ip6-loopback

  even when ipv6 is disabled in dockerd as reported in:
  docker/for-linux#250

* add a check for self.prserv.address to provide better error message:
  ERROR: Unable to start PR Server, exitting
  when something bad happens, but in this case you still need to read
  bitbake-cookerdaemon.log to see the actuall error, in this case:

90 22:30:39.008441 --- Starting bitbake server pid 90 at 2021-08-26 22:30:39.008419 ---
90 22:30:39.023734 Started bitbake server pid 90
90 22:30:39.024286 Entering server connection loop
90 22:30:39.024753 Accepting [<socket.socket fd=6, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0, laddr=bitbake.sock>] ([])
90 22:30:39.026314 Processing Client
90 22:30:39.026456 Connecting Client
90 22:30:39.027509 Running command ['setFeatures', [2]]
90 22:30:39.027757 Command Completed
90 22:30:39.028711 Running command ['updateConfig', {'abort': False, 'force': False, 'invalidate_stamp': None, 'dry_run': False, 'dump_signatures': [], 'extra_assume_provided': [], 'profile': False, 'prefile': [], 'postfile': [], 'server_timeout': None, 'nosetscene': False, 'setsceneonly': False, 'skipsetscene': False, 'runall': None, 'runonly': None, 'writeeventlog': None, 'build_verbose_shell': False, 'build_verbose_stdout': False, 'default_loglevel': 20, 'debug_domains': {}}, {'DISTRO': '', 'PWD': '/OE/nodistro/honister', 'HOME': '/OE', 'MACHINE': 'qemux86', 'BB_ENV_EXTRAWHITE': 'MACHINE DISTRO TCMODE TCLIBC http_proxy ftp_proxy https_proxy all_proxy ALL_PROXY no_proxy SSH_AGENT_PID SSH_AUTH_SOCK BB_SRCREV_POLICY SDKMACHINE BB_NUMBER_THREADS PARALLEL_MAKE GIT_PROXY_COMMAND GIT_PROXY_IGNORE SOCKS5_PASSWD SOCKS5_USER WEBOS_DISTRO_BUILD_ID PSEUDO_DISABLED PSEUDO_BUILD', 'PATH': '/OE/nodistro/honister/oe-core/scripts:/OE/nodistro/honister/bitbake/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', 'LC_ALL': 'en_US.UTF-8', 'MACHINES': 'qemux86', 'HOSTNAME': '6a439759e3c6', 'TOPDIR': '/OE/nodistro/honister', 'LANG': 'en_US.UTF-8', 'TERM': 'xterm', 'SHLVL': '1', 'BITBAKE_HOME': '/OE', 'BUILDDIR': '/OE/nodistro/honister/BUILD', 'OLDPWD': '/OE/nodistro/honister/bitbake', '_': '/OE/nodistro/honister/bitbake/bin/bitbake'}, ['/OE/nodistro/honister/bitbake/bin/bitbake', '-k', 'zlib-native']]
Process Process-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 255, in run
    self.start()
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
    self.server = self.loop.run_until_complete(server_coro)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
    return await loop.create_server(factory, host, port, **kwds)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
    raise OSError(err.errno, 'error while attempting '
OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address
90 22:30:39.530037 Command Completed
90 22:30:39.530913 Processing Client
90 22:30:39.531023 Disconnecting Client
90 22:30:39.531638 No timeout, exiting.
90 22:30:39.632137 Exiting
90 22:30:39.637562 Original lockfile contents: ['90\n']
90 22:30:39.638107 Exiting as we could obtain the lock

(Bitbake rev: 31df93017b82510d25ced80ee66317d77e4b3ebf)

Signed-off-by: Martin Jansa <[email protected]>
Signed-off-by: Richard Purdie <[email protected]>
halstead pushed a commit to openembedded/bitbake that referenced this issue Sep 1, 2021
* When using PRSERV_HOST = "localhost:0" inside
  Docker container (tested with ubuntu 20.04 and 21.04) the
  self.loop.run_until_complete never completed, so self.address
  wasn't ever assigned few lines bellow and then
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
  in lib/prserv/serv.py caused a bit ugly exception:

bitbake@599696cd20aa:~/nodistro/honister$ bitbake -k pkgconfig-native
Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/bin/bitbake", line 35, in <module>
    sys.exit(bitbake_main(BitBakeConfigParameters(sys.argv),
  File "/OE/nodistro/honister/bitbake/lib/bb/main.py", line 385, in bitbake_main
    return ui_module.main(server_connection.connection, server_connection.events,
  File "/OE/nodistro/honister/bitbake/lib/bb/ui/knotty.py", line 397, in main
    params.updateToServer(server, os.environ.copy())
  File "/OE/nodistro/honister/bitbake/lib/bb/cookerdata.py", line 75, in updateToServer
    raise Exception("Unable to update the server configuration with local parameters: %s" % error)
Exception: Unable to update the server configuration with local parameters: Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 90, in runCommand
    result = command_method(self, commandline)
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 286, in updateConfig
    command.cooker.updateConfigOpts(options, environment, cmdline)
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 491, in updateConfigOpts
    self.reset()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 1717, in reset
    self.handlePRServ()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 383, in handlePRServ
    self.prhost = prserv.serv.auto_start(self.data)
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 318, in auto_start
    singleton.start()
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 133, in start
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
AttributeError: 'NoneType' object has no attribute 'rsplit'

* the issue was caused by "localhost" being resolved as IPv6 address ::1
  and then asyncio failing to bind it, the same is reproducible with hashserv, but
  hashserve at least shows nice error message:
    bitbake$ bitbake-hashserv -l DEBUG -b localhost:0
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 59, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 53, in main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address

* or by bitbake-prserv in prserv.log:
    bitbake$ bitbake-prserv --start --host=localhost --port=42005
    bitbake$ cat prserv.log
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 55, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 46, in main
        ret=prserv.serv.start_daemon(options.dbfile, options.host, options.port,os.path.abspath(options.logfile), options.read_only)
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 226, in start_daemon
        run_as_daemon(daemon_main, pidfile, os.path.abspath(logfile))
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 202, in run_as_daemon
        func()
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 224, in daemon_main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 42005, 0, 0): cannot assign requested address

* while 127.0.0.1 works fine:
    bitbake$ bitbake-prserv --start --host=127.0.0.1 --port=42005
    bitbake$ cat prserv.log
    DEBUG: Listening on ('127.0.0.1', 42005)
    2021-08-26 22:28:05,828 Listening on ('127.0.0.1', 42005)
    DEBUG: Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    2021-08-26 22:28:05,829 Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    NOTE: Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39
    2021-08-26 22:28:05,831 Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39

  but 127.0.0.1:0 wasn't handled as "autostart" like localhost:0 is
  update is_local_special to allow that

* /etc/hosts file generated by docker contails localhost for both IPv4 and IPv6:
  $ grep localhost /etc/hosts
  127.0.0.1       localhost
  ::1     localhost ip6-localhost ip6-loopback

  even when ipv6 is disabled in dockerd as reported in:
  docker/for-linux#250

* add a check for self.prserv.address to provide better error message:
  ERROR: Unable to start PR Server, exitting
  when something bad happens, but in this case you still need to read
  bitbake-cookerdaemon.log to see the actuall error, in this case:

90 22:30:39.008441 --- Starting bitbake server pid 90 at 2021-08-26 22:30:39.008419 ---
90 22:30:39.023734 Started bitbake server pid 90
90 22:30:39.024286 Entering server connection loop
90 22:30:39.024753 Accepting [<socket.socket fd=6, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0, laddr=bitbake.sock>] ([])
90 22:30:39.026314 Processing Client
90 22:30:39.026456 Connecting Client
90 22:30:39.027509 Running command ['setFeatures', [2]]
90 22:30:39.027757 Command Completed
90 22:30:39.028711 Running command ['updateConfig', {'abort': False, 'force': False, 'invalidate_stamp': None, 'dry_run': False, 'dump_signatures': [], 'extra_assume_provided': [], 'profile': False, 'prefile': [], 'postfile': [], 'server_timeout': None, 'nosetscene': False, 'setsceneonly': False, 'skipsetscene': False, 'runall': None, 'runonly': None, 'writeeventlog': None, 'build_verbose_shell': False, 'build_verbose_stdout': False, 'default_loglevel': 20, 'debug_domains': {}}, {'DISTRO': '', 'PWD': '/OE/nodistro/honister', 'HOME': '/OE', 'MACHINE': 'qemux86', 'BB_ENV_EXTRAWHITE': 'MACHINE DISTRO TCMODE TCLIBC http_proxy ftp_proxy https_proxy all_proxy ALL_PROXY no_proxy SSH_AGENT_PID SSH_AUTH_SOCK BB_SRCREV_POLICY SDKMACHINE BB_NUMBER_THREADS PARALLEL_MAKE GIT_PROXY_COMMAND GIT_PROXY_IGNORE SOCKS5_PASSWD SOCKS5_USER WEBOS_DISTRO_BUILD_ID PSEUDO_DISABLED PSEUDO_BUILD', 'PATH': '/OE/nodistro/honister/oe-core/scripts:/OE/nodistro/honister/bitbake/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', 'LC_ALL': 'en_US.UTF-8', 'MACHINES': 'qemux86', 'HOSTNAME': '6a439759e3c6', 'TOPDIR': '/OE/nodistro/honister', 'LANG': 'en_US.UTF-8', 'TERM': 'xterm', 'SHLVL': '1', 'BITBAKE_HOME': '/OE', 'BUILDDIR': '/OE/nodistro/honister/BUILD', 'OLDPWD': '/OE/nodistro/honister/bitbake', '_': '/OE/nodistro/honister/bitbake/bin/bitbake'}, ['/OE/nodistro/honister/bitbake/bin/bitbake', '-k', 'zlib-native']]
Process Process-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 255, in run
    self.start()
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
    self.server = self.loop.run_until_complete(server_coro)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
    return await loop.create_server(factory, host, port, **kwds)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
    raise OSError(err.errno, 'error while attempting '
OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address
90 22:30:39.530037 Command Completed
90 22:30:39.530913 Processing Client
90 22:30:39.531023 Disconnecting Client
90 22:30:39.531638 No timeout, exiting.
90 22:30:39.632137 Exiting
90 22:30:39.637562 Original lockfile contents: ['90\n']
90 22:30:39.638107 Exiting as we could obtain the lock

Signed-off-by: Martin Jansa <[email protected]>
Signed-off-by: Richard Purdie <[email protected]>
seambot pushed a commit to seamapi/poky that referenced this issue Sep 1, 2021
…lhost:0"

* When using PRSERV_HOST = "localhost:0" inside
  Docker container (tested with ubuntu 20.04 and 21.04) the
  self.loop.run_until_complete never completed, so self.address
  wasn't ever assigned few lines bellow and then
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
  in lib/prserv/serv.py caused a bit ugly exception:

bitbake@599696cd20aa:~/nodistro/honister$ bitbake -k pkgconfig-native
Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/bin/bitbake", line 35, in <module>
    sys.exit(bitbake_main(BitBakeConfigParameters(sys.argv),
  File "/OE/nodistro/honister/bitbake/lib/bb/main.py", line 385, in bitbake_main
    return ui_module.main(server_connection.connection, server_connection.events,
  File "/OE/nodistro/honister/bitbake/lib/bb/ui/knotty.py", line 397, in main
    params.updateToServer(server, os.environ.copy())
  File "/OE/nodistro/honister/bitbake/lib/bb/cookerdata.py", line 75, in updateToServer
    raise Exception("Unable to update the server configuration with local parameters: %s" % error)
Exception: Unable to update the server configuration with local parameters: Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 90, in runCommand
    result = command_method(self, commandline)
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 286, in updateConfig
    command.cooker.updateConfigOpts(options, environment, cmdline)
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 491, in updateConfigOpts
    self.reset()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 1717, in reset
    self.handlePRServ()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 383, in handlePRServ
    self.prhost = prserv.serv.auto_start(self.data)
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 318, in auto_start
    singleton.start()
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 133, in start
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
AttributeError: 'NoneType' object has no attribute 'rsplit'

* the issue was caused by "localhost" being resolved as IPv6 address ::1
  and then asyncio failing to bind it, the same is reproducible with hashserv, but
  hashserve at least shows nice error message:
    bitbake$ bitbake-hashserv -l DEBUG -b localhost:0
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 59, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 53, in main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address

* or by bitbake-prserv in prserv.log:
    bitbake$ bitbake-prserv --start --host=localhost --port=42005
    bitbake$ cat prserv.log
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 55, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 46, in main
        ret=prserv.serv.start_daemon(options.dbfile, options.host, options.port,os.path.abspath(options.logfile), options.read_only)
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 226, in start_daemon
        run_as_daemon(daemon_main, pidfile, os.path.abspath(logfile))
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 202, in run_as_daemon
        func()
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 224, in daemon_main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 42005, 0, 0): cannot assign requested address

* while 127.0.0.1 works fine:
    bitbake$ bitbake-prserv --start --host=127.0.0.1 --port=42005
    bitbake$ cat prserv.log
    DEBUG: Listening on ('127.0.0.1', 42005)
    2021-08-26 22:28:05,828 Listening on ('127.0.0.1', 42005)
    DEBUG: Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    2021-08-26 22:28:05,829 Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    NOTE: Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39
    2021-08-26 22:28:05,831 Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39

  but 127.0.0.1:0 wasn't handled as "autostart" like localhost:0 is
  update is_local_special to allow that

* /etc/hosts file generated by docker contails localhost for both IPv4 and IPv6:
  $ grep localhost /etc/hosts
  127.0.0.1       localhost
  ::1     localhost ip6-localhost ip6-loopback

  even when ipv6 is disabled in dockerd as reported in:
  docker/for-linux#250

* add a check for self.prserv.address to provide better error message:
  ERROR: Unable to start PR Server, exitting
  when something bad happens, but in this case you still need to read
  bitbake-cookerdaemon.log to see the actuall error, in this case:

90 22:30:39.008441 --- Starting bitbake server pid 90 at 2021-08-26 22:30:39.008419 ---
90 22:30:39.023734 Started bitbake server pid 90
90 22:30:39.024286 Entering server connection loop
90 22:30:39.024753 Accepting [<socket.socket fd=6, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0, laddr=bitbake.sock>] ([])
90 22:30:39.026314 Processing Client
90 22:30:39.026456 Connecting Client
90 22:30:39.027509 Running command ['setFeatures', [2]]
90 22:30:39.027757 Command Completed
90 22:30:39.028711 Running command ['updateConfig', {'abort': False, 'force': False, 'invalidate_stamp': None, 'dry_run': False, 'dump_signatures': [], 'extra_assume_provided': [], 'profile': False, 'prefile': [], 'postfile': [], 'server_timeout': None, 'nosetscene': False, 'setsceneonly': False, 'skipsetscene': False, 'runall': None, 'runonly': None, 'writeeventlog': None, 'build_verbose_shell': False, 'build_verbose_stdout': False, 'default_loglevel': 20, 'debug_domains': {}}, {'DISTRO': '', 'PWD': '/OE/nodistro/honister', 'HOME': '/OE', 'MACHINE': 'qemux86', 'BB_ENV_EXTRAWHITE': 'MACHINE DISTRO TCMODE TCLIBC http_proxy ftp_proxy https_proxy all_proxy ALL_PROXY no_proxy SSH_AGENT_PID SSH_AUTH_SOCK BB_SRCREV_POLICY SDKMACHINE BB_NUMBER_THREADS PARALLEL_MAKE GIT_PROXY_COMMAND GIT_PROXY_IGNORE SOCKS5_PASSWD SOCKS5_USER WEBOS_DISTRO_BUILD_ID PSEUDO_DISABLED PSEUDO_BUILD', 'PATH': '/OE/nodistro/honister/oe-core/scripts:/OE/nodistro/honister/bitbake/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', 'LC_ALL': 'en_US.UTF-8', 'MACHINES': 'qemux86', 'HOSTNAME': '6a439759e3c6', 'TOPDIR': '/OE/nodistro/honister', 'LANG': 'en_US.UTF-8', 'TERM': 'xterm', 'SHLVL': '1', 'BITBAKE_HOME': '/OE', 'BUILDDIR': '/OE/nodistro/honister/BUILD', 'OLDPWD': '/OE/nodistro/honister/bitbake', '_': '/OE/nodistro/honister/bitbake/bin/bitbake'}, ['/OE/nodistro/honister/bitbake/bin/bitbake', '-k', 'zlib-native']]
Process Process-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 255, in run
    self.start()
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
    self.server = self.loop.run_until_complete(server_coro)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
    return await loop.create_server(factory, host, port, **kwds)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
    raise OSError(err.errno, 'error while attempting '
OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address
90 22:30:39.530037 Command Completed
90 22:30:39.530913 Processing Client
90 22:30:39.531023 Disconnecting Client
90 22:30:39.531638 No timeout, exiting.
90 22:30:39.632137 Exiting
90 22:30:39.637562 Original lockfile contents: ['90\n']
90 22:30:39.638107 Exiting as we could obtain the lock

(Bitbake rev: c2cdda0e5fc720c60d3b8537fc702cb118981bd2)

Signed-off-by: Martin Jansa <[email protected]>
Signed-off-by: Richard Purdie <[email protected]>
@leenr
Copy link

leenr commented Dec 15, 2022

For reference: it seems to be a duplicate of moby/moby#35954.

daregit pushed a commit to daregit/yocto-combined that referenced this issue May 22, 2024
… as "localhost:0"

* When using PRSERV_HOST = "localhost:0" inside
  Docker container (tested with ubuntu 20.04 and 21.04) the
  self.loop.run_until_complete never completed, so self.address
  wasn't ever assigned few lines bellow and then
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
  in lib/prserv/serv.py caused a bit ugly exception:

bitbake@599696cd20aa:~/nodistro/honister$ bitbake -k pkgconfig-native
Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/bin/bitbake", line 35, in <module>
    sys.exit(bitbake_main(BitBakeConfigParameters(sys.argv),
  File "/OE/nodistro/honister/bitbake/lib/bb/main.py", line 385, in bitbake_main
    return ui_module.main(server_connection.connection, server_connection.events,
  File "/OE/nodistro/honister/bitbake/lib/bb/ui/knotty.py", line 397, in main
    params.updateToServer(server, os.environ.copy())
  File "/OE/nodistro/honister/bitbake/lib/bb/cookerdata.py", line 75, in updateToServer
    raise Exception("Unable to update the server configuration with local parameters: %s" % error)
Exception: Unable to update the server configuration with local parameters: Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 90, in runCommand
    result = command_method(self, commandline)
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 286, in updateConfig
    command.cooker.updateConfigOpts(options, environment, cmdline)
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 491, in updateConfigOpts
    self.reset()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 1717, in reset
    self.handlePRServ()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 383, in handlePRServ
    self.prhost = prserv.serv.auto_start(self.data)
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 318, in auto_start
    singleton.start()
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 133, in start
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
AttributeError: 'NoneType' object has no attribute 'rsplit'

* the issue was caused by "localhost" being resolved as IPv6 address ::1
  and then asyncio failing to bind it, the same is reproducible with hashserv, but
  hashserve at least shows nice error message:
    bitbake$ bitbake-hashserv -l DEBUG -b localhost:0
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 59, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 53, in main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address

* or by bitbake-prserv in prserv.log:
    bitbake$ bitbake-prserv --start --host=localhost --port=42005
    bitbake$ cat prserv.log
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 55, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 46, in main
        ret=prserv.serv.start_daemon(options.dbfile, options.host, options.port,os.path.abspath(options.logfile), options.read_only)
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 226, in start_daemon
        run_as_daemon(daemon_main, pidfile, os.path.abspath(logfile))
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 202, in run_as_daemon
        func()
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 224, in daemon_main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 42005, 0, 0): cannot assign requested address

* while 127.0.0.1 works fine:
    bitbake$ bitbake-prserv --start --host=127.0.0.1 --port=42005
    bitbake$ cat prserv.log
    DEBUG: Listening on ('127.0.0.1', 42005)
    2021-08-26 22:28:05,828 Listening on ('127.0.0.1', 42005)
    DEBUG: Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    2021-08-26 22:28:05,829 Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    NOTE: Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39
    2021-08-26 22:28:05,831 Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39

  but 127.0.0.1:0 wasn't handled as "autostart" like localhost:0 is
  update is_local_special to allow that

* /etc/hosts file generated by docker contails localhost for both IPv4 and IPv6:
  $ grep localhost /etc/hosts
  127.0.0.1       localhost
  ::1     localhost ip6-localhost ip6-loopback

  even when ipv6 is disabled in dockerd as reported in:
  docker/for-linux#250

* add a check for self.prserv.address to provide better error message:
  ERROR: Unable to start PR Server, exitting
  when something bad happens, but in this case you still need to read
  bitbake-cookerdaemon.log to see the actuall error, in this case:

90 22:30:39.008441 --- Starting bitbake server pid 90 at 2021-08-26 22:30:39.008419 ---
90 22:30:39.023734 Started bitbake server pid 90
90 22:30:39.024286 Entering server connection loop
90 22:30:39.024753 Accepting [<socket.socket fd=6, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0, laddr=bitbake.sock>] ([])
90 22:30:39.026314 Processing Client
90 22:30:39.026456 Connecting Client
90 22:30:39.027509 Running command ['setFeatures', [2]]
90 22:30:39.027757 Command Completed
90 22:30:39.028711 Running command ['updateConfig', {'abort': False, 'force': False, 'invalidate_stamp': None, 'dry_run': False, 'dump_signatures': [], 'extra_assume_provided': [], 'profile': False, 'prefile': [], 'postfile': [], 'server_timeout': None, 'nosetscene': False, 'setsceneonly': False, 'skipsetscene': False, 'runall': None, 'runonly': None, 'writeeventlog': None, 'build_verbose_shell': False, 'build_verbose_stdout': False, 'default_loglevel': 20, 'debug_domains': {}}, {'DISTRO': '', 'PWD': '/OE/nodistro/honister', 'HOME': '/OE', 'MACHINE': 'qemux86', 'BB_ENV_EXTRAWHITE': 'MACHINE DISTRO TCMODE TCLIBC http_proxy ftp_proxy https_proxy all_proxy ALL_PROXY no_proxy SSH_AGENT_PID SSH_AUTH_SOCK BB_SRCREV_POLICY SDKMACHINE BB_NUMBER_THREADS PARALLEL_MAKE GIT_PROXY_COMMAND GIT_PROXY_IGNORE SOCKS5_PASSWD SOCKS5_USER WEBOS_DISTRO_BUILD_ID PSEUDO_DISABLED PSEUDO_BUILD', 'PATH': '/OE/nodistro/honister/oe-core/scripts:/OE/nodistro/honister/bitbake/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', 'LC_ALL': 'en_US.UTF-8', 'MACHINES': 'qemux86', 'HOSTNAME': '6a439759e3c6', 'TOPDIR': '/OE/nodistro/honister', 'LANG': 'en_US.UTF-8', 'TERM': 'xterm', 'SHLVL': '1', 'BITBAKE_HOME': '/OE', 'BUILDDIR': '/OE/nodistro/honister/BUILD', 'OLDPWD': '/OE/nodistro/honister/bitbake', '_': '/OE/nodistro/honister/bitbake/bin/bitbake'}, ['/OE/nodistro/honister/bitbake/bin/bitbake', '-k', 'zlib-native']]
Process Process-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 255, in run
    self.start()
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
    self.server = self.loop.run_until_complete(server_coro)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
    return await loop.create_server(factory, host, port, **kwds)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
    raise OSError(err.errno, 'error while attempting '
OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address
90 22:30:39.530037 Command Completed
90 22:30:39.530913 Processing Client
90 22:30:39.531023 Disconnecting Client
90 22:30:39.531638 No timeout, exiting.
90 22:30:39.632137 Exiting
90 22:30:39.637562 Original lockfile contents: ['90\n']
90 22:30:39.638107 Exiting as we could obtain the lock

(Bitbake rev: c2cdda0e5fc720c60d3b8537fc702cb118981bd2)

Signed-off-by: Martin Jansa <[email protected]>
Signed-off-by: Richard Purdie <[email protected]>
daregit pushed a commit to daregit/yocto-combined that referenced this issue May 22, 2024
… as "localhost:0"

* When using PRSERV_HOST = "localhost:0" inside
  Docker container (tested with ubuntu 20.04 and 21.04) the
  self.loop.run_until_complete never completed, so self.address
  wasn't ever assigned few lines bellow and then
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
  in lib/prserv/serv.py caused a bit ugly exception:

bitbake@599696cd20aa:~/nodistro/honister$ bitbake -k pkgconfig-native
Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/bin/bitbake", line 35, in <module>
    sys.exit(bitbake_main(BitBakeConfigParameters(sys.argv),
  File "/OE/nodistro/honister/bitbake/lib/bb/main.py", line 385, in bitbake_main
    return ui_module.main(server_connection.connection, server_connection.events,
  File "/OE/nodistro/honister/bitbake/lib/bb/ui/knotty.py", line 397, in main
    params.updateToServer(server, os.environ.copy())
  File "/OE/nodistro/honister/bitbake/lib/bb/cookerdata.py", line 75, in updateToServer
    raise Exception("Unable to update the server configuration with local parameters: %s" % error)
Exception: Unable to update the server configuration with local parameters: Traceback (most recent call last):
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 90, in runCommand
    result = command_method(self, commandline)
  File "/OE/nodistro/honister/bitbake/lib/bb/command.py", line 286, in updateConfig
    command.cooker.updateConfigOpts(options, environment, cmdline)
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 491, in updateConfigOpts
    self.reset()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 1717, in reset
    self.handlePRServ()
  File "/OE/nodistro/honister/bitbake/lib/bb/cooker.py", line 383, in handlePRServ
    self.prhost = prserv.serv.auto_start(self.data)
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 318, in auto_start
    singleton.start()
  File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 133, in start
    self.port = int(self.prserv.address.rsplit(':', 1)[1])
AttributeError: 'NoneType' object has no attribute 'rsplit'

* the issue was caused by "localhost" being resolved as IPv6 address ::1
  and then asyncio failing to bind it, the same is reproducible with hashserv, but
  hashserve at least shows nice error message:
    bitbake$ bitbake-hashserv -l DEBUG -b localhost:0
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 59, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-hashserv", line 53, in main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address

* or by bitbake-prserv in prserv.log:
    bitbake$ bitbake-prserv --start --host=localhost --port=42005
    bitbake$ cat prserv.log
    Traceback (most recent call last):
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 55, in <module>
        ret = main()
      File "/OE/nodistro/honister/bitbake/bin/bitbake-prserv", line 46, in main
        ret=prserv.serv.start_daemon(options.dbfile, options.host, options.port,os.path.abspath(options.logfile), options.read_only)
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 226, in start_daemon
        run_as_daemon(daemon_main, pidfile, os.path.abspath(logfile))
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 202, in run_as_daemon
        func()
      File "/OE/nodistro/honister/bitbake/lib/prserv/serv.py", line 224, in daemon_main
        server.serve_forever()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 233, in serve_forever
        self.start()
      File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
        self.server = self.loop.run_until_complete(server_coro)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
        return future.result()
      File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
        return await loop.create_server(factory, host, port, **kwds)
      File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
        raise OSError(err.errno, 'error while attempting '
    OSError: [Errno 99] error while attempting to bind on address ('::1', 42005, 0, 0): cannot assign requested address

* while 127.0.0.1 works fine:
    bitbake$ bitbake-prserv --start --host=127.0.0.1 --port=42005
    bitbake$ cat prserv.log
    DEBUG: Listening on ('127.0.0.1', 42005)
    2021-08-26 22:28:05,828 Listening on ('127.0.0.1', 42005)
    DEBUG: Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    2021-08-26 22:28:05,829 Opening PRServ database 'file:/OE/nodistro/honister/prserv.sqlite3'
    NOTE: Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39
    2021-08-26 22:28:05,831 Started PRServer with DBfile: /OE/nodistro/honister/prserv.sqlite3, Address: 127.0.0.1:42005, PID: 39

  but 127.0.0.1:0 wasn't handled as "autostart" like localhost:0 is
  update is_local_special to allow that

* /etc/hosts file generated by docker contails localhost for both IPv4 and IPv6:
  $ grep localhost /etc/hosts
  127.0.0.1       localhost
  ::1     localhost ip6-localhost ip6-loopback

  even when ipv6 is disabled in dockerd as reported in:
  docker/for-linux#250

* add a check for self.prserv.address to provide better error message:
  ERROR: Unable to start PR Server, exitting
  when something bad happens, but in this case you still need to read
  bitbake-cookerdaemon.log to see the actuall error, in this case:

90 22:30:39.008441 --- Starting bitbake server pid 90 at 2021-08-26 22:30:39.008419 ---
90 22:30:39.023734 Started bitbake server pid 90
90 22:30:39.024286 Entering server connection loop
90 22:30:39.024753 Accepting [<socket.socket fd=6, family=AddressFamily.AF_UNIX, type=SocketKind.SOCK_STREAM, proto=0, laddr=bitbake.sock>] ([])
90 22:30:39.026314 Processing Client
90 22:30:39.026456 Connecting Client
90 22:30:39.027509 Running command ['setFeatures', [2]]
90 22:30:39.027757 Command Completed
90 22:30:39.028711 Running command ['updateConfig', {'abort': False, 'force': False, 'invalidate_stamp': None, 'dry_run': False, 'dump_signatures': [], 'extra_assume_provided': [], 'profile': False, 'prefile': [], 'postfile': [], 'server_timeout': None, 'nosetscene': False, 'setsceneonly': False, 'skipsetscene': False, 'runall': None, 'runonly': None, 'writeeventlog': None, 'build_verbose_shell': False, 'build_verbose_stdout': False, 'default_loglevel': 20, 'debug_domains': {}}, {'DISTRO': '', 'PWD': '/OE/nodistro/honister', 'HOME': '/OE', 'MACHINE': 'qemux86', 'BB_ENV_EXTRAWHITE': 'MACHINE DISTRO TCMODE TCLIBC http_proxy ftp_proxy https_proxy all_proxy ALL_PROXY no_proxy SSH_AGENT_PID SSH_AUTH_SOCK BB_SRCREV_POLICY SDKMACHINE BB_NUMBER_THREADS PARALLEL_MAKE GIT_PROXY_COMMAND GIT_PROXY_IGNORE SOCKS5_PASSWD SOCKS5_USER WEBOS_DISTRO_BUILD_ID PSEUDO_DISABLED PSEUDO_BUILD', 'PATH': '/OE/nodistro/honister/oe-core/scripts:/OE/nodistro/honister/bitbake/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', 'LC_ALL': 'en_US.UTF-8', 'MACHINES': 'qemux86', 'HOSTNAME': '6a439759e3c6', 'TOPDIR': '/OE/nodistro/honister', 'LANG': 'en_US.UTF-8', 'TERM': 'xterm', 'SHLVL': '1', 'BITBAKE_HOME': '/OE', 'BUILDDIR': '/OE/nodistro/honister/BUILD', 'OLDPWD': '/OE/nodistro/honister/bitbake', '_': '/OE/nodistro/honister/bitbake/bin/bitbake'}, ['/OE/nodistro/honister/bitbake/bin/bitbake', '-k', 'zlib-native']]
Process Process-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/multiprocessing/process.py", line 315, in _bootstrap
    self.run()
  File "/usr/lib/python3.8/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 255, in run
    self.start()
  File "/OE/nodistro/honister/bitbake/lib/bb/asyncrpc/serv.py", line 144, in start_tcp
    self.server = self.loop.run_until_complete(server_coro)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
    return future.result()
  File "/usr/lib/python3.8/asyncio/streams.py", line 94, in start_server
    return await loop.create_server(factory, host, port, **kwds)
  File "/usr/lib/python3.8/asyncio/base_events.py", line 1463, in create_server
    raise OSError(err.errno, 'error while attempting '
OSError: [Errno 99] error while attempting to bind on address ('::1', 0, 0, 0): cannot assign requested address
90 22:30:39.530037 Command Completed
90 22:30:39.530913 Processing Client
90 22:30:39.531023 Disconnecting Client
90 22:30:39.531638 No timeout, exiting.
90 22:30:39.632137 Exiting
90 22:30:39.637562 Original lockfile contents: ['90\n']
90 22:30:39.638107 Exiting as we could obtain the lock

(Bitbake rev: c2cdda0e5fc720c60d3b8537fc702cb118981bd2)

Signed-off-by: Martin Jansa <[email protected]>
Signed-off-by: Richard Purdie <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants