sled agent may need workaround for illumos#17940

In trying to set up a4x2 today, I found a situation where:

First, sled agent was hung: I couldn't even complete GET /baseboard requests to the bootstrap agent, even though this request doesn't even await. This turned out to be #9619.

The blocked thread was trying to start sled agent:

                 libc.so.1`poll+0x5a
                 std::sys::pal::unix::pipe::read2::h6f9003600c6927da+0xcb
                 std::process::Command::output::hd8363acfe5718a30+0x111
                 smf::smf::AdmDisable::run::hfc5b1626bd62e180+0x2a7
                 omicron_sled_agent::sled_agent::SledAgent::new::{{closure}}::h01eb5888852e0027+0xcc87
                 omicron_sled_agent::bootstrap::server::start_sled_agent::{{closure}}::h20a2b8ce43aa69c9+0x1344
                 omicron_sled_agent::bootstrap::server::Inner::run::_$u7b$$u7b$closure$u7d$$u7d$::he2efb4130259b3ce +0xdd1
                 tokio::runtime::task::harness::Harness<T,S>::poll::h1a117f1a9f364895+0x74
                 tokio::runtime::scheduler::multi_thread::worker::Context::run_task::h5d3357afec2ef515+0x131
                 tokio::runtime::scheduler::multi_thread::worker::Context::run::h60ff8f384a9f88c7+0xafe
                 tokio::runtime::context::scoped::Scoped<T>::set::h1d0b0e57a95f14a0+0x2a
                 tokio::runtime::context::runtime::enter_runtime::hdc340399bf487a97+0x1c1
                 tokio::runtime::scheduler::multi_thread::worker::run::h6800c8e06dbedcc4+0xa0
                 tokio::runtime::task::core::Core<T,S>::poll::hf3ee517af1a280fa+0x70
                 tokio::runtime::task::harness::Harness<T,S>::poll::he6ac78c5ffdcc0ee+0x8a
                 tokio::runtime::blocking::pool::Inner::run::h5adfbf224460a600+0xf5
                 std::sys::backtrace::__rust_begin_short_backtrace::ha91cfb8864cbd59b+0x3e
                 core::ops::function::FnOnce::call_once{{vtable.shim}}::hdcfd7fe2f122aaae+0xa8
                 std::sys::thread::unix::Thread::new::thread_start::ha097fb815024401f+0x2f
                 libc.so.1`_thrp_setup+0x77
                 libc.so.1`_lwp_start  

and starting sled agent is blocked invoking svcadm disable of fmd, which is done as part of setting up backing filesystems. More specifically, it's blocked here:

> 5::findstack -tv
stack pointer for thread 5 [tokio-runtime-worker]: fffffc7fed1fcd70
[ fffffc7fed1fcd70 libc.so.1`__pollsys+0xa() ]
  fffffc7fed1fcdb0 int libc.so.1`poll+0x5a((struct pollfd *)fffffc7fed1fcdc0, (nfds_t)2, (int)ffffffff)
  fffffc7fed1fce00 std::sys::pal::unix::pipe::read2::h6f9003600c6927da+0xcb()
  fffffc7fed1fceb0 std::process::Command::output::hd8363acfe5718a30+0x111()
  fffffc7fed1fd140 smf::smf::AdmDisable::run::hfc5b1626bd62e180+0x2a7()
  fffffc7fed1fe370 omicron_sled_agent::sled_agent::SledAgent::new::{{closure}}::h01eb5888852e0027+0xcc87()
  fffffc7fed1ff200 omicron_sled_agent::bootstrap::server::start_sled_agent::{{closure}}::h20a2b8ce43aa69c9+0x1344()
  fffffc7fed1ffa40 omicron_sled_agent::bootstrap::server::Inner::run::_$u7b$$u7b$closure$u7d$$u7d$::he2efb4130259b3ce +0xdd1()
  fffffc7fed1ffad0 tokio::runtime::task::harness::Harness<T,S>::poll::h1a117f1a9f364895+0x74()
  fffffc7fed1ffb30 tokio::runtime::scheduler::multi_thread::worker::Context::run_task::h5d3357afec2ef515+0x131()
  fffffc7fed1ffbc0 tokio::runtime::scheduler::multi_thread::worker::Context::run::h60ff8f384a9f88c7+0xafe()
  fffffc7fed1ffc20 tokio::runtime::context::scoped::Scoped<T>::set::h1d0b0e57a95f14a0+0x2a()
  fffffc7fed1ffce0 tokio::runtime::context::runtime::enter_runtime::hdc340399bf487a97+0x1c1()
  fffffc7fed1ffd20 tokio::runtime::scheduler::multi_thread::worker::run::h6800c8e06dbedcc4+0xa0()
  fffffc7fed1ffd80 tokio::runtime::task::core::Core<T,S>::poll::hf3ee517af1a280fa+0x70()
  fffffc7fed1ffdd0 tokio::runtime::task::harness::Harness<T,S>::poll::he6ac78c5ffdcc0ee+0x8a()
  fffffc7fed1ffea0 tokio::runtime::blocking::pool::Inner::run::h5adfbf224460a600+0xf5()
  fffffc7fed1ffee0 std::sys::backtrace::__rust_begin_short_backtrace::ha91cfb8864cbd59b+0x3e()
  fffffc7fed1fff80 core::ops::function::FnOnce::call_once{{vtable.shim}}::hdcfd7fe2f122aaae+0xa8()
  fffffc7fed1fffb0 std::sys::thread::unix::Thread::new::thread_start::ha097fb815024401f+0x2f()
  fffffc7fed1fffe0 void * libc.so.1`_thrp_setup+0x77((ulwp_t *)fffffc7feef01a40)
  fffffc7fed1ffff0 libc.so.1`_lwp_start()
> fffffc7fed1fcdc0::array struct pollfd 2
fffffc7fed1fcdc0
fffffc7fed1fcdc8
> fffffc7fed1fcdc0::array struct pollfd 2 | ::print struct pollfd
{
    fd = 0x1e
    events = 0x1
    revents = 0
}
{
    fd = 0x20
    events = 0x1
    revents = 0
}
> 0x1e=E
                30                   
> 0x20=E
                32                   

# pfiles 1601 
1601:	/opt/oxide/sled-agent/sled-agent run /opt/oxide/sled-agent/pkg/config.
  Current rlimit: 65536 file descriptors
...
  30: S_IFIFO mode:0000 dev:545,0 ino:3343 uid:0 gid:0 rdev:0,0
      O_RDWR|O_NONBLOCK|O_CLOEXEC
  32: S_IFIFO mode:0000 dev:545,0 ino:3344 uid:0 gid:0 rdev:0,0
      O_RDWR|O_NONBLOCK|O_CLOEXEC

We can see the child process that sled agent has launched and is waiting for here:

root@g0:~# svcs -p sled-agent
STATE          STIME    FMRI
online         17:01:47 svc:/oxide/sled-agent:default
               17:01:47     1600 ctrun
root@g0:~# ptree 1600
1600   ctrun -l child -o noorphan,regent /opt/oxide/sled-agent/sled-agent run /opt/oxi
  1601   /opt/oxide/sled-agent/sled-agent run /opt/oxide/sled-agent/pkg/config.toml
    1702   /opt/oxide/sled-agent/tofino-monitor
    3042   /usr/sbin/svcadm disable -s -t svc:/system/fmd:default
root@g0:~# pfiles 3042
3042:	/usr/sbin/svcadm disable -s -t svc:/system/fmd:default
  Current rlimit: 65536 file descriptors
   0: S_IFCHR mode:0666 dev:547,0 ino:70778888 uid:0 gid:3 rdev:135,2
      O_RDONLY|O_LARGEFILE
      /devices/pseudo/mm@0:null
      offset:0
   1: S_IFIFO mode:0000 dev:545,0 ino:3343 uid:0 gid:0 rdev:0,0
      O_RDWR
   2: S_IFIFO mode:0000 dev:545,0 ino:3344 uid:0 gid:0 rdev:0,0
      O_RDWR
   3: S_IFIFO mode:0000 dev:545,0 ino:327047 uid:0 gid:0 rdev:0,0
      O_RDWR
   4: S_IFDOOR mode:0777 dev:551,0 ino:0 uid:0 gid:0 rdev:551,0
      O_RDWR|O_CLOEXEC  door to svc.configd[11]
  11: S_IFREG mode:0444 dev:552,1 ino:65538 uid:0 gid:0 rdev:0,0
      O_RDONLY|O_LARGEFILE
      /system/contract/process/pbundle

That's trying to disable fmd. But fmd is in maintenance:

root@g0:~# svcs fmd
STATE          STIME    FMRI
maintenance    17:04:36 svc:/system/fmd:default

Why?

root@g0:~# cat $(svcs -L fmd)
[ Mar 11 16:40:41 Enabled. ]
[ Mar 11 16:40:47 Executing start method ("/usr/lib/fm/fmd/fmd"). ]
[ Mar 11 16:40:47 Method "start" exited with status 0. ]
[ Mar 11 16:56:08 Enabled. ]
[ Mar 11 16:56:12 Executing start method ("/usr/lib/fm/fmd/fmd"). ]
[ Mar 11 16:56:15 Method "start" exited with status 0. ]
[ Mar 11 17:03:35 Stopping because service disabled. ]
[ Mar 11 17:03:35 Executing stop method (:kill). ]
[ Mar 11 17:04:35 Method or service exit timed out.  Killing contract 77. ]

I don't know why that happened here but I think the ship sailed on debugging it. SMF method timeouts are known to be virtually undebuggable because the process is gone and no core file is saved or anything.

I think svcadm disable should not block in this case and I've filed illumos bug 17940 for it. We may want to just fix that (and do nothing here), but if we choose not to for whatever reason, then sled agent should better handle this situation so that it doesn't block indefinitely when this happens.

Start with smf::smf::AdmDisable::run and SledAgent::new, then reproduce the blocking svcadm disable -s -t svc:/system/fmd:default scenario on illumos. Review illumos bug 17940 and decide whether the fix belongs in illumos or sled agent. Done means sled agent no longer blocks indefinitely when disabling fmd encounters this condition.