user-data autoinstall config with apt `geoip: false` not work

[lvii]

Hi, I have tried to install Ubuntu 22.04.1 in a private network server.

autoinstall apt-config stage failed with error log NOT request geoip.ubuntu.com.

I have disabled `geoip: false` in user-data autointall config, but it was not worked.

    # grep -A10 apt: /autoinstall.yaml
    apt:
        disable_components:
        - non-free
        - restricted
        geoip: false
        preserve_sources_list: false
        primary:
        - arches:
            - default
            uri: http://mirrors.private.com/ubuntu
    debug: true

user-data config `geoip: false` was removed in /var/log/installer/subiquity-curtin-apt.conf

    # Autogenerated by Subiquity: 2022-10-28 15:57:27.895920 UTC
    apt:
      disable_components:
      - non-free
      - restricted
      preserve_sources_list: false
      primary:
      - arches:
        - default
        uri: http://mirrors.private.com/ubuntu

------------------------------------------------------------------
/var/log/installer/subiquity-server-debug.log ERROR log:
------------------------------------------------------------------

2022-10-28 15:57:36,669 ERROR root:39 finish: subiquity/Install/install/configure_apt: FAIL: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3786', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/subiquity/3698/bin:/snap/subiquity/3698/usr/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:/snap/subiquity/3698/bin', '--setenv', 'PYTHONPATH=:/snap/subiquity/3698/lib/python3.8/site-packages', '--setenv', 'PYTHON=/snap/subiquity/3698/usr/bin/python3.8', '--setenv', 'SNAP=/snap/subiquity/3698', '--', '/snap/subiquity/3698/usr/bin/python3.8', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3786.2"}}', 'in-target', '-t', '/tmp/tmpzrthyaql/mount', '--', 'apt-get', 'update']' returned non-zero exit status 100.
2022-10-28 15:57:36,669 DEBUG subiquitycore.common.errorreport:384 generating crash report
2022-10-28 15:57:36,678 INFO subiquitycore.common.errorreport:406 saving crash report 'install failed crashed with CalledProcessError' to /var/crash/1666972656.669968843.install_fail.crash
2022-10-28 15:57:36,678 ERROR root:39 finish: subiquity/Install/install: FAIL: Command '['systemd-run', '--wait', '--same-dir', '--property', 'SyslogIdentifier=subiquity_log.3786', '--property', 'PrivateMounts=yes', '--setenv', 'PATH=/snap/subiquity/3698/bin:/snap/subiquity/3698/usr/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:/snap/subiquity/3698/bin', '--setenv', 'PYTHONPATH=:/snap/subiquity/3698/lib/python3.8/site-packages', '--setenv', 'PYTHON=/snap/subiquity/3698/usr/bin/python3.8', '--setenv', 'SNAP=/snap/subiquity/3698', '--', '/snap/subiquity/3698/usr/bin/python3.8', '-m', 'curtin', '--showtrace', '-vvv', '--set', 'json:reporting={"subiquity": {"type": "journald", "identifier": "curtin_event.3786.2"}}', 'in-target', '-t', '/tmp/tmpzrthyaql/mount', '--', 'apt-get', 'update']' returned non-zero exit status 100.
2022-10-28 15:57:36,679 INFO root:39 start: subiquity/ErrorReporter/1666972656.669968843.install_fail/add_info:
2022-10-28 15:57:36,680 ERROR subiquity.server.server:416 top level error
Traceback (most recent call last):
  File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquity/server/controllers/cmdlist.py", line 104, in _run
    await Install.install_task
  File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquitycore/context.py", line 148, in decorated_async
    return await meth(self, **kw)
  File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquity/server/controllers/install.py", line 160, in install
    for_install_path = await self.configure_apt(context=context)
  File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquitycore/context.py", line 148, in decorated_async
    return await meth(self, **kw)
  File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquity/server/controllers/install.py", line 131, in configure_apt
    return await configurer.configure_for_install(context)
  File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquity/server/apt.py", line 225, in configure_for_install
    await run_curtin_command(
  File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquity/server/curtin.py", line 181, in run_curtin_command
    return await cmd.wait()
  File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquity/server/curtin.py", line 118, in wait
    result = await self.runner.wait(self.proc)
  File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquity/server/runner.py", line 81, in wait
    raise subprocess.CalledProcessError(proc.returncode, proc.args)

------------------------------------------------------------------
/var/crash/1666972656.669968843.install_fail.crash more about geoip.ubuntu.com connect failed log:
------------------------------------------------------------------

2022-10-28 15:57:17,607 ERROR subiquity.common.geoip:119 geoip lookup failed
 Traceback (most recent call last):
   File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connection.py", line 174, in _new_conn
     conn = connection.create_connection(
   File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/util/connection.py", line 72, in create_connection
     for res in socket.getaddrinfo(host, port, family, socket.SOCK_STREAM):
   File "/snap/subiquity/3698/usr/lib/python3.8/socket.py", line 918, in getaddrinfo
     for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
 socket.gaierror: [Errno -3] Temporary failure in name resolution

 During handling of the above exception, another exception occurred:

 Traceback (most recent call last):
   File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connectionpool.py", line 703, in urlopen
     httplib_response = self._make_request(
   File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connectionpool.py", line 386, in _make_request
     self._validate_conn(conn)
   File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connectionpool.py", line 1042, in _validate_conn
     conn.connect()
   File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connection.py", line 358, in connect
     self.sock = conn = self._new_conn()
   File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connection.py", line 186, in _new_conn
     raise NewConnectionError(
 urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x7f8f2c713370>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution

 During handling of the above exception, another exception occurred:

 Traceback (most recent call last):
   File "/snap/subiquity/3698/lib/python3.8/site-packages/requests/adapters.py", line 489, in send
     resp = conn.urlopen(
   File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connectionpool.py", line 787, in urlopen
     retries = retries.increment(
   File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/util/retry.py", line 592, in increment
     raise MaxRetryError(_pool, url, error or ResponseError(cause))
 urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='geoip.ubuntu.com', port=443): Max retries exceeded with url: /lookup (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f8f2c713370>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution'))

 During handling of the above exception, another exception occurred:

 Traceback (most recent call last):
   File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquity/server/geoip.py", line 80, in get_response
     response = await run_in_thread(
   File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquitycore/async_helpers.py", line 46, in run_in_thread
     return await loop.run_in_executor(None, func, *args)
   File "/snap/subiquity/3698/usr/lib/python3.8/concurrent/futures/thread.py", line 57, in run
     result = self.fn(*self.args, **self.kwargs)
   File "/snap/subiquity/3698/lib/python3.8/site-packages/requests/api.py", line 73, in get
     return request("get", url, params=params, **kwargs)
   File "/snap/subiquity/3698/lib/python3.8/site-packages/requests/api.py", line 59, in request
     return session.request(method=method, url=url, **kwargs)
   File "/snap/subiquity/3698/lib/python3.8/site-packages/requests/sessions.py", line 587, in request
     resp = self.send(prep, **send_kwargs)
   File "/snap/subiquity/3698/lib/python3.8/site-packages/requests/sessions.py", line 701, in send
     r = adapter.send(request, **kwargs)
   File "/snap/subiquity/3698/lib/python3.8/site-packages/requests/adapters.py", line 565, in send
     raise ConnectionError(e, request=request)
 requests.exceptions.ConnectionError: HTTPSConnectionPool(host='geoip.ubuntu.com', port=443): Max retries exceeded with url: /lookup (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0x7f8f2c713370>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution'))

 The above exception was the direct cause of the following exception:

 Traceback (most recent call last):
   File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquity/server/geoip.py", line 117, in _lookup
     self.response_text = await self.strategy.get_response()
   File "/snap/subiquity/3698/lib/python3.8/site-packages/subiquity/server/geoip.py", line 84, in get_response
     raise LookupError from e
 subiquity.server.geoip.LookupError

[Dan Bungert (dbungert)]

Hi, thanks for the report.

I think I know what's going on here and I regret that the logs don't make it terribly clear.

There is another item in Subiquity asking about geoip, timezone handling, which is why you still see it being requested. You can try setting
```
timezone: UTC
```
to bypass that part, but it's harmless.

While the geoip errors are creating tracebacks, they aren't the reason the install halted. The install halted on apt-get update. If you check /var/log/install/curtin-install.log it'll have more output from apt. Please check that and see if mirror / network / proxy / system time needs to be tweaked.

[Launchpad Janitor (janitor)]

[Expired for subiquity (Ubuntu) because there has been no activity for 60 days.]

[lvii (57lvii)]

Hi, @dbungert

After I changed `timezone: UTC` in `user-data` config, there was still same error.

It still can NOT stop request `geoip.ubuntu.com`

```
2023-01-04 07:55:51,745 DEBUG root:39 finish: subiquity/Network/_send_update: SUCCESS: CHANGE eth0
2023-01-04 07:55:51,745 DEBUG root:39 finish: subiquity/Filesystem/_probe: SUCCESS:·
2023-01-04 07:55:51,752 DEBUG urllib3.connectionpool:1003 Starting new HTTPS connection (1): geoip.ubuntu.com:443
2023-01-04 07:55:51,753 DEBUG urllib3.connectionpool:1003 Starting new HTTPS connection (1): geoip.ubuntu.com:443
2023-01-04 07:55:51,755 DEBUG subiquitycore.utils:101 arun_command ['netplan', 'apply'] exited with code 0
2023-01-04 07:55:51,759 DEBUG urllib3.connectionpool:1003 Starting new HTTPS connection (1): geoip.ubuntu.com:443
2023-01-04 07:55:51,759 DEBUG urllib3.connectionpool:1003 Starting new HTTPS connection (1): geoip.ubuntu.com:443
2023-01-04 07:55:51,761 ERROR subiquity.common.geoip:119 geoip lookup failed
Traceback (most recent call last):
  File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
  File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/util/connection.py", line 72, in create_connection
    for res in socket.getaddrinfo(host, port, family, socket.SOCK_STREAM):
  File "/snap/subiquity/3698/usr/lib/python3.8/socket.py", line 918, in getaddrinfo
    for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
socket.gaierror: [Errno -3] Temporary failure in name resolution

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connectionpool.py", line 703, in urlopen
    httplib_response = self._make_request(
  File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connectionpool.py", line 386, in _make_request
    self._validate_conn(conn)
  File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connectionpool.py", line 1042, in _validate_conn
    conn.connect()
  File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connection.py", line 358, in connect
    self.sock = conn = self._new_conn()
  File "/snap/subiquity/3698/lib/python3.8/site-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0x7fbfa816a4f0>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution

During handling of the above exception, another exception occurred:
```

[lvii (57lvii)]

This was my user-data config file:

```
---
apt:
    disable_components:
    - non-free
    - restricted
    geoip: false
    preserve_sources_list: false
    primary:
    - arches:
        - default
        uri: http://mirrors.private.com/ubuntu
debug: true
early-commands:
- 'sed -i.bak -E ''s/^#(PermitRootLogin).*/\1 yes/g'' /etc/ssh/sshd_config

    service ssh restart

    mkdir -m 700 -pv /root/.ssh

    echo "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBv1Luihh3r4WA..."
    > /root/.ssh/authorized_keys

    DISKS="$(lsblk -o NAME,TYPE,SIZE,MODEL -Pp)"

    BOOTDISK=$(echo "$DISKS" | awk -F\" ''/disk/{print $2}'' | sort -V | head -n 1)

    printf "__INFO: lsblk:\n${DISKS}\n__INFO: bootdisk: ${BOOTDISK}\n"

    sed -i.bak "s|/dev/nvme0n1|${BOOTDISK}|g" /autoinstall.yaml

    '
identity:
    hostname: ubuntu
    password: $6$C1Ayr5cSYQe0ptVH$gV40sA5e...
    username: root
keyboard:
    layout: us
late-commands:
- 'umount -v /run/snapd/ns/lxd.mnt

    lsblk -o NAME,TYPE,SIZE,MODEL,MOUNTPOINT -Pp

    cp -iv /proc/cmdline /target/var/log/installer/

    cp -iv /autoinstall* /target/var/log/installer/

    rsync -av /root/.ssh /target/root/

    curl -m 5 -fksSL http://10.1.../late.sh -o /target/var/log/installer/late.sh

    curtin in-target --target=/target -- bash /var/log/installer/late.sh

    '
locale: en_US.UTF-8
network:
    ethernets:
        eth0:
            dhcp-identifier: mac
            dhcp4: true
    version: 2
ssh:
    allow-pw: false
    authorized-keys:
    - ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBv1Luihh3r4WA...
    install-server: true
storage:
    config:
    - grub_device: false
        id: disk-boot
        name: ''
        path: /dev/nvme0n1
        preserve: false
        ptable: gpt
        type: disk
        wipe: superblock-recursive
    - device: disk-boot
        flag: boot
        grub_device: true
        id: partition-uefi
        number: 1
        size: 256MB
        type: partition
    - device: disk-boot
        flag: linux
        grub_device: false
        id: partition-root
        number: 2
        size: -1
        type: partition
    - fstype: vfat
        id: format-uefi
        label: ubuntu-uefi
        preserve: false
        type: format
        volume: partition-uefi
    - fstype: xfs
        id: format-root
        label: ubuntu-root
        preserve: false
        type: format
        volume: partition-root
    - device: format-uefi
        id: mount-uefi
        path: /boot/efi
        type: mount
    - device: format-root
        id: mount-root
        options: defaults,noatime
        path: /
        type: mount
    swap:
        size: 0
timezone: UTC
user-data:
    disable_root: false
version: 1
...

```

[Dan Bungert (dbungert)]

Please ignore the geoip tracebacks, they are a red herring and not fatal.

In the original description, is the following line:
{"subiquity": {"type": "journald", "identifier": "curtin_event.3786.2"}}', 'in-target', '-t', '/tmp/tmpzrthyaql/mount', '--', 'apt-get', 'update']' returned non-zero exit status 100.

Apt is failing and this bug report doesn't have enough info to say why.