Bootstrap freezes - jammy controller

[Jordan Barrett]

On Juju v3.0-beta1 (revision 829bda9), I cannot bootstrap a Jammy controller.
```
$ juju bootstrap lxd c --bootstrap-series jammy
```
freezes on the step
```
Attempting to connect to 10.67.163.115:22
```
and hangs for ~20 mins before timing out.

Looking at the logs (/var/log) inside the LXD container, I see stuff like this:
```
...
Jun 28 04:55:28 juju-19c090-0 systemd[1]: Started Session 881 of User ubuntu.
Jun 28 04:55:28 juju-19c090-0 systemd[1]: session-881.scope: Deactivated successfully.
Jun 28 04:55:33 juju-19c090-0 systemd[1]: Started Session 882 of User ubuntu.
Jun 28 04:55:33 juju-19c090-0 systemd[1]: session-882.scope: Deactivated successfully.
Jun 28 04:55:38 juju-19c090-0 systemd[1]: Started Session 883 of User ubuntu.
Jun 28 04:55:39 juju-19c090-0 systemd[1]: session-883.scope: Deactivated successfully.
...
```
auth.log contains a bit more detail:
```
Jun 28 04:55:49 juju-19c090-0 systemd-logind[344]: New session 885 of user ubuntu.
Jun 28 04:55:49 juju-19c090-0 sshd[12338]: Received disconnect from 10.67.163.1 port 59208:11: disconnected by user
Jun 28 04:55:49 juju-19c090-0 sshd[12338]: Disconnected from user ubuntu 10.67.163.1 port 59208
Jun 28 04:55:49 juju-19c090-0 sshd[12285]: pam_unix(sshd:session): session closed for user ubuntu
Jun 28 04:55:49 juju-19c090-0 systemd-logind[344]: Session 885 logged out. Waiting for processes to exit.
Jun 28 04:55:49 juju-19c090-0 systemd-logind[344]: Removed session 885.
Jun 28 04:55:54 juju-19c090-0 sshd[12341]: Accepted publickey for ubuntu from 10.67.163.1 port 59210 ssh2: RSA SHA256:24/YhtdZLDjZVvuQqHh27Gb9y7k90TSWLezB8O6oQ5M
Jun 28 04:55:54 juju-19c090-0 sshd[12341]: pam_unix(sshd:session): session opened for user ubuntu(uid=1000) by (uid=0)
```

I found this (possibly relevant) section in the cloud-init.log:
```
2022-06-28 05:10:30,389 - subp.py[DEBUG]: Running command ['/var/lib/cloud/instance/scripts
/runcmd'] with allowed return codes [0] (shell=False, capture=False)
2022-06-28 05:10:30,412 - subp.py[DEBUG]: Unexpected error while running command.
Command: ['/var/lib/cloud/instance/scripts/runcmd']
Exit code: 2
Reason: -
Stdout: -
Stderr: -
2022-06-28 05:10:30,412 - cc_scripts_user.py[WARNING]: Failed to run module scripts-user (s
cripts in /var/lib/cloud/instance/scripts)
2022-06-28 05:10:30,412 - handlers.py[DEBUG]: finish: modules-final/config-scripts-user: FA
IL: running config-scripts-user with frequency once-per-instance
2022-06-28 05:10:30,413 - util.py[WARNING]: Running module scripts-user (<module 'cloudinit
.config.cc_scripts_user' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_u
ser.py'>) failed
2022-06-28 05:10:30,413 - util.py[DEBUG]: Running module scripts-user (<module 'cloudinit.c
onfig.cc_scripts_user' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_use
r.py'>) failed
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/cloudinit/config/modules.py", line 231, in _run_modu
les
    ran, _r = cc.run(
  File "/usr/lib/python3/dist-packages/cloudinit/cloud.py", line 67, in run
    return self._runners.run(name, functor, args, freq, clear_on_fail)
  File "/usr/lib/python3/dist-packages/cloudinit/helpers.py", line 185, in run
    results = functor(*args)
  File "/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_user.py", line 48, in handle
    subp.runparts(runparts_path)
  File "/usr/lib/python3/dist-packages/cloudinit/subp.py", line 427, in runparts
    raise RuntimeError(
RuntimeError: Runparts: 1 failures (runcmd) in 1 attempted commands
```

Bootstrapping works fine with a focal controller.

[Vitaly Antonenko (anvial)]

Hi Jordan,

I tried to reproduce this bug on develop branch (3.0-beta2), looks like there is no such problem.

https://pastebin.ubuntu.com/p/YwsVmcBjQS/

[Vitaly Antonenko (anvial)]

The same happened to 3.0-beta1

```
anvial@ubuntu-pc:~/Projects/juju$ juju version
3.0-beta1-genericlinux-amd64
anvial@ubuntu-pc:~/Projects/juju$ juju bootstrap lxd lxd --bootstrap-series jammy
Creating Juju controller "lxd" on lxd/default
Looking for packaged Juju agent version 3.0-beta1 for amd64
Located Juju agent version 3.0-beta1-ubuntu-amd64 at https://streams.canonical.com/juju/tools/agent/3.0-beta1/juju-3.0-beta1-linux-amd64.tgz
To configure your system to better support LXD containers, please see: https://github.com/lxc/lxd/blob/master/doc/production-setup.md
Launching controller instance(s) on lxd/default...
 - juju-28530a-0 (arch=amd64)
Installing Juju agent on bootstrap instance
Waiting for address
Attempting to connect to 10.209.4.26:22
Connected to 10.209.4.26
Running machine configuration script...
Bootstrap agent now started
Contacting Juju controller at 10.209.4.26 to verify accessibility...

Bootstrap complete, controller "lxd" is now available
Controller machines are in the "controller" model

Now you can run
 juju add-model <model-name>
to create a new model to deploy workloads.
anvial@ubuntu-pc:~/Projects/juju$
```

[John A Meinel (jameinel)]

Other things to investigate:
What series the Host machine is running (jammy, focal, etc)
What version of LXD is being used? (4.x track, 5.x track)

On Tue, Jun 28, 2022 at 1:50 AM Jordan Barrett <email address hidden>
wrote:

> Public bug reported:
>
> On Juju v3.0-beta1 (revision 829bda9), I cannot bootstrap a Jammy
> controller.
> ```
> $ juju bootstrap lxd c --bootstrap-series jammy
> ```
> freezes on the step
> ```
> Attempting to connect to 10.67.163.115:22
> ```
> and hangs for ~20 mins before timing out.
>
> Looking at the logs (/var/log) inside the LXD container, I see stuff like
> this:
> ```
> ...
> Jun 28 04:55:28 juju-19c090-0 systemd[1]: Started Session 881 of User
> ubuntu.
> Jun 28 04:55:28 juju-19c090-0 systemd[1]: session-881.scope: Deactivated
> successfully.
> Jun 28 04:55:33 juju-19c090-0 systemd[1]: Started Session 882 of User
> ubuntu.
> Jun 28 04:55:33 juju-19c090-0 systemd[1]: session-882.scope: Deactivated
> successfully.
> Jun 28 04:55:38 juju-19c090-0 systemd[1]: Started Session 883 of User
> ubuntu.
> Jun 28 04:55:39 juju-19c090-0 systemd[1]: session-883.scope: Deactivated
> successfully.
> ...
> ```
> auth.log contains a bit more detail:
> ```
> Jun 28 04:55:49 juju-19c090-0 systemd-logind[344]: New session 885 of user
> ubuntu.
> Jun 28 04:55:49 juju-19c090-0 sshd[12338]: Received disconnect from
> 10.67.163.1 port 59208:11: disconnected by user
> Jun 28 04:55:49 juju-19c090-0 sshd[12338]: Disconnected from user ubuntu
> 10.67.163.1 port 59208
> Jun 28 04:55:49 juju-19c090-0 sshd[12285]: pam_unix(sshd:session): session
> closed for user ubuntu
> Jun 28 04:55:49 juju-19c090-0 systemd-logind[344]: Session 885 logged out.
> Waiting for processes to exit.
> Jun 28 04:55:49 juju-19c090-0 systemd-logind[344]: Removed session 885.
> Jun 28 04:55:54 juju-19c090-0 sshd[12341]: Accepted publickey for ubuntu
> from 10.67.163.1 port 59210 ssh2: RSA
> SHA256:24/YhtdZLDjZVvuQqHh27Gb9y7k90TSWLezB8O6oQ5M
> Jun 28 04:55:54 juju-19c090-0 sshd[12341]: pam_unix(sshd:session): session
> opened for user ubuntu(uid=1000) by (uid=0)
> ```
>
> I found this (possibly relevant) section in the cloud-init.log:
> ```
> 2022-06-28 05:10:30,389 - subp.py[DEBUG]: Running command
> ['/var/lib/cloud/instance/scripts
> /runcmd'] with allowed return codes [0] (shell=False, capture=False)
> 2022-06-28 05:10:30,412 - subp.py[DEBUG]: Unexpected error while running
> command.
> Command: ['/var/lib/cloud/instance/scripts/runcmd']
> Exit code: 2
> Reason: -
> Stdout: -
> Stderr: -
> 2022-06-28 05:10:30,412 - cc_scripts_user.py[WARNING]: Failed to run
> module scripts-user (s
> cripts in /var/lib/cloud/instance/scripts)
> 2022-06-28 05:10:30,412 - handlers.py[DEBUG]: finish:
> modules-final/config-scripts-user: FA
> IL: running config-scripts-user with frequency once-per-instance
> 2022-06-28 05:10:30,413 - util.py[WARNING]: Running module scripts-user
> (<module 'cloudinit
> .config.cc_scripts_user' from
> '/usr/lib/python3/dist-packages/cloudinit/config/cc_scripts_u
> ser.py'>) failed
> 2022-06-28 05:10:30,413 - util.py[DEBUG]: Running module scripts-user
> (<module 'cloudinit.c
> onfig.cc_scripts_user' from
> '/usr/lib/python3/dist-packages/cloud...

[Jordan Barrett (barrettj12)]

My machine is running Ubuntu 20.04 (focal).
```
$ lxc version
Client version: 4.0.9
Server version: 4.0.9
```

[Jordan Barrett (barrettj12)]

I've updated Juju to v3.0-beta3 (SHA 5c25721) and this issue no longer seems to happen.