1st signal interrupt is caught by the Tor process, and ignored by the go process

[mh-cbon]

Hi,

A small issue here regarding the signal capture and exit sequence.

Upon receiving the interrupt signal, i can see the Tor process handles it (there is a log line, and the onion respond with 0xF2). But the Go program, it is not notified, an additional signal is required to get it done.

I also tried to wait, in the hope some timeout would occur, but no luck.

I am a bit concerned by this behavior in the perspective of a service setup (but maybe I should not).

Some logs and data, stripped for clarity.

System

[mh-cbon@Host-001 bootstrap]$ uname -a
Linux Host-001 5.18.17-200.fc36.x86_64 #1 SMP PREEMPT_DYNAMIC Thu Aug 11 14:36:06 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
[mh-cbon@Host-001 bootstrap]$ cat /etc/fedora-release
Fedora release 36 (Thirty Six)
[mh-cbon@Host-001 bootstrap]$ go version
go version go1.19 linux/amd64

require (
    github.com/cretz/bine v0.2.0
    github.com/ipsn/go-libtor v1.0.380
)

The Program output

$ go run .
  INFO[0002] upnp: found 1 clients    
  INFO[0002] upnp: configured 192.168.1.78:40003 => 80 for 10h0m0s on device http://192.168.1.254:42990/rootDesc.xml
Using embedded control connection
Starting tor with args [--DataDirectory /tmp/tor --CookieAuthentication 1 --DisableNetwork 1 --SocksPort auto -f /tmp/tor/torrc-1589576849]
Write line: PROTOCOLINFO
Aug 14 20:47:22.967 [notice] Tor 0.3.5.14-dev (git-da728e36f4579907) running on Linux with Libevent 2.2.0-alpha-dev, OpenSSL 1.1.1l-dev, Zlib 1.2.11, Liblzma N/A, and Libzstd N/A.
Aug 14 20:47:22.967 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Aug 14 20:47:22.967 [notice] Read configuration file "/tmp/tor/torrc-1589576849".
....
$568B6913AE5123EDBA304909A569AFE8F9E73C4C~OrwellianNightmare
Write line: SETEVENTS
Read line: 250 OK
  INFO[0009] bootstrap: Onion ready at http://vq7emfluv5meujjc5gzs2gad632mnxclmhxwcgkba476hlkx4srkpdyd.onion
  INFO[0011] upnp: found 1 clients    
  INFO[0011] bootstrap: Website ready at http://notshownhere/
  INFO[0011] bootstrap: static website running at http://127.0.0.1:40895/
^CAug 14 20:48:53.000 [notice] Interrupt: exiting cleanly.
^C ERROR[0409] bootstrap: Quitting...   
Closing onion vq7emfluv5meujjc5gzs2gad632mnxclmhxwcgkba476hlkx4srkpdyd.onion:80
Write line: DEL_ONION vq7emfluv5meujjc5gzs2gad632mnxclmhxwcgkba476hlkx4srkpdyd
  INFO[0409] bootstrap: accept tcp 127.0.0.1:36877: use of closed network connection
Failed closing onion: write unix @->@: write: broken pipe
Closing Tor
Write line: SIGNAL HALT
Write line: QUIT
Error while closing Tor: Unable to signal halt: write unix @->@: write: broken pipe
  INFO[0409] bootstrap: accept tcp 192.168.1.78:40003: use of closed network connection
  INFO[0412] upnp: found 1 clients    
  INFO[0412] upnp: deleted the port mapping for device http://192.168.1.254:42990/rootDesc.xml

In that log i waited like 5 minutes before giving up.

My code is super boring, I have a small func, which mostly copy paste your examples, with a small wrapper, and some calling code relying on the stdlib to capture the signal and a context to wait on.

package main

import (
    "bytes"
    "context"
    "crypto"
    "crypto/ed25519"
    "fmt"
    "net"
    "os"
    "path/filepath"

    "github.com/cretz/bine/tor"
    "github.com/hashicorp/go-multierror"
    "github.com/ipsn/go-libtor"
)

type torConfig struct {
    Enabled       bool
    RemotePort    int    `yaml:"remote-port"`
    Key           string `yaml:"key-path"`
    CreateDataDir bool   `yaml:"create-data-dir"`
    DataDir       string `yaml:"data-dir"`
    // KeyFormat  string `yaml:"key-format"` // unclear what are the storing formats.
}

func torSocket(ctx context.Context, config torConfig) (*torListener, error) {

    if !config.Enabled {
        return nil, nil
    }

    var key crypto.PrivateKey
    if keypath := config.Key; keypath != "" {
        s, err := os.Stat(keypath)
        if err != nil {
            return nil, fmt.Errorf("tor could not load the private key at %v: %v", config.Key, err)
        }
        if s.IsDir() {
            keypath = filepath.Join(keypath, "hs_ed25519_secret_key")
        }
        d, err := os.ReadFile(keypath)
        if err != nil {
            return nil, fmt.Errorf("tor could not load the private key at %v: %v", config.Key, err)
        }
        d = bytes.TrimPrefix(d, []byte("== ed25519v1-secret: type0 ==\x00\x00\x00"))
        key = ed25519.PrivateKey(d)
    }

    if config.CreateDataDir {
        err := os.MkdirAll(config.DataDir, os.ModePerm)
        if err != nil {
            return nil, err
        }
    }

    t, err := tor.Start(ctx, &tor.StartConf{
        ProcessCreator:         libtor.Creator,
        DebugWriter:            os.Stderr,
        UseEmbeddedControlConn: true,
        DataDir:                config.DataDir,
        NoHush:                 true,
    })
    if err != nil {
        return nil, fmt.Errorf("failed to start tor: %v", err)
    }

    onion, err := t.Listen(ctx, &tor.ListenConf{
        RemotePorts: []int{config.RemotePort},
        Key:         key,
        Version3:    true,
    })
    if err != nil {
        return nil, fmt.Errorf("failed to create onion service: %v", err)
    }

    return &torListener{Listener: onion, torProcess: t}, nil
}

type torListener struct {
    net.Listener
    torProcess *tor.Tor
}

func (t *torListener) URL() string {
    if t.Listener == nil {
        return ""
    }
    return "http://" + t.Listener.(*tor.OnionService).ID + ".onion"
}

func (t *torListener) Close() (out error) {
    if t.Listener != nil {
        if err := t.Listener.Close(); err != nil {
            out = multierror.Append(out, err)
        }
    }
    if t.torProcess != nil {
        if err := t.torProcess.Close(); err != nil {
            out = multierror.Append(out, err)
        }
    }
    return
}

The caller code is like

// some pile of things here.

    ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt)
    defer stop()

// some pile of things here.

    torln, err := torSocket(context.Background(), config.Tor)
    if err != nil {
        Logger.Errorf("tor not set up: %v", err)
    } else if torln != nil {
        Logger.Infof("Onion ready at %v", torln.URL())
        defer torln.Close()
    }

// some pile of things here.

    <-ctx.Done()
    Logger.Error("Quitting...")

// return,return,return

[mh-cbon]

FTR, while looking again, I noticed too, i had left an undesired context.Background() in my code.

In torln, err := torSocket(context.Background(), config.Tor), passing the ctx variable, like in torln, err := torSocket(ctx, config.Tor) did not change the behavior.

Maybe it is related to github.com/ipsn/go-libtor ? no idea sorry..

[mh-cbon]

Hurrah... I should have tested before w/t libtor... It is the culprit.

Though, when I tried the embedded process, it failed with cgo error.

[mh-cbon@Host-001 bootstrap]$ go run .
# github.com/cretz/bine/process/embedded/tor-0.3.5
../../.gvm/pkgsets/go1.19/global/pkg/mod/github.com/cretz/bine@v0.2.0/process/embedded/tor-0.3.5/process.go:35:10: fatal error: tor_api.h: No such file or directory
   35 | #include <tor_api.h>
      |          ^~~~~~~~~~~
compilation terminated.

I guess I am missing the header files, no such tor-devel package found... that's all unfortunate.

Only when using the non embedded process it all worked fine and smoothly.