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

Basic window support in subprocess mode #14

Merged
merged 12 commits into from
Jun 15, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 27 additions & 0 deletions .github/workflows/ci.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,33 @@ jobs:
- run: "go version"
- run: "go build ./cmd/..."
- run: "./behavioral-tests/run.sh"
x-build-windows:
runs-on: ubuntu-latest
timeout-minutes: 10
name: "Simple build binary for MS Windows"
steps:
- uses: actions/checkout@v4
- uses: actions/setup-go@v5
with:
go-version: "1.22"
- run: "go version"
- run: "go build ./cmd/..."
env:
GOOS: windows
GOARCH: amd64
- run: "file pplog.exe"
windows:
runs-on: windows-latest
timeout-minutes: 10
name: "Build on MS Windows"
steps:
- uses: actions/checkout@v4
- run: "go version" # go1.21.11 # https://github.com/actions/runner-images/blob/main/images/windows/Windows2022-Readme.md
- run: "go build ./cmd/..."
- run: "dir"
- run: "./pplog.exe -v"
- shell: bash # naked `echo` won't work on windows
run: "./pplog.exe -d bash -c 'echo \\{\\\"time\\\":\\\"2024-12-02T12:00:00Z\\\",\\\"level\\\":\\\"INFO\\\",\\\"msg\\\":\\\"Hello\\\"\\}'"
test:
runs-on: ubuntu-latest
timeout-minutes: 10
Expand Down
54 changes: 54 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -147,6 +147,7 @@ We makes `message` green. Keep shaping your logs field by field.
- In `PPLOG_ERRLINE` template:
- `TEXT`
- `BINARY` — does TEXT contains control characters
- If `PPLOG_CHILD_MODE` not empty `pplog` runs in child mode as if it has `-c` switch

## Most common colors

Expand All @@ -163,9 +164,56 @@ Text colors Text High Background Hi Background
\e[37mWhite \e[0m \e[97mWhite \e[0m \e[47mWhite \e[0m \e[107mWhite \e[0m
```

## Run modes explanation

### Pipe mode

The most confident mode. In this mode your shell cares about all your processes. Just do

```sh
./service | pplog
# or with redirections if you need to take both stderr and stdout
./service 2>&1 | pplog
# or the same redirections in modern shells
./service |& pplog
```

### Simple subprocess mode

If you say just like that:

```sh
pplog ./service
```

`pplog` runs `./servcie` as a child process and tries to manage it.

If you press Ctrl-C, `pplog` sends `SIGINT`, `SIGTERM`, `SIGKILL` to its child consequently with 1s delay in between.

`pplog` tries to wait child process exited and returns its exit code transparently.

Obvious disadvantage is that `pplog` doesn't try to manage children of child (if any), daemons etc.

### Child (or coprocess) mode

In this mode `pplog` starts as a child of `./service`

```sh
pplog -c ./service
```

So, `./service` itself obtains all signals and Ctrl-Cs directly.

However, there are disadvantages here too. `pplog` can not get `./service`s exit code. And this mode unavailable under MS Windows.

## TODO

- Usage: show templates in debug mode
- Behavior tests:
- `-c`
- `PPLOG_CHILD_MODE` environment variable
- basic `runs-on: windows-latest`
- passing exit code
- Docs: explain main features of binary: modes etc.
- Docs: link to console control codes info
- Docs: write template functions guide and examples
Expand All @@ -181,6 +229,12 @@ this tool provides `io.Writer` to pipe log stream. It is easiest way to modify b
it leads to overhead for extra marshaling/unmarshaling. However, as well as we use human readable logs in
local environment only, it is acceptable to have a little overhead.

### Subprocesses handling issues

The problem is that many processes have to be synchronized: shell-process, pplog-process, target-process with all its children.

You are able to choose one of three modes: pipe-, subprocess- and child-mode. Each of them has its own disadvantages.

### Line-by-line processing

This tool processes input stream line by line. It means, that it won't work with multiline JSONs in logs like that
Expand Down
2 changes: 1 addition & 1 deletion behavioral-tests/args-and-signals/custom-fake-server.sh
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@

xtrap() {
echo "Getting SIGNAL $1. Exiting"
exit
exit 0 # it must to be forced 0; some shells can return 130 by default
}

trap "xtrap SIGINT" 2 # graceful shutdown handler
Expand Down
2 changes: 1 addition & 1 deletion behavioral-tests/args-and-signals/custom-run.sh
Original file line number Diff line number Diff line change
@@ -1,3 +1,3 @@
#!/bin/sh

go run ../../cmd/... ./custom-fake-server.sh ARG1 ARG2 | tee output.log
go run ../../cmd/... -c ./custom-fake-server.sh ARG1 ARG2 | tee output.log
3 changes: 2 additions & 1 deletion behavioral-tests/run.sh
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,7 @@ trap cleanup EXIT

cd "$(dirname $0)"

for cs in $(find . -mindepth 1 -maxdepth 1 -type d)
for cs in $(find . -mindepth 1 -maxdepth 1 -type d | sort)
do
(
cd $cs
Expand All @@ -23,5 +23,6 @@ do
fi
diff expected.log output.log # will cause interruption due to -e
rm output.log
echo "OK: $cs"
)
done
3 changes: 3 additions & 0 deletions cmd/pplog/const.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
package main

const buffSize = 32768
91 changes: 25 additions & 66 deletions cmd/pplog/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -20,14 +20,9 @@ import (
var (
debugFlag = false
showVersionFlag = false
childModeFlag = false
)

func init() {
flag.BoolVar(&debugFlag, "d", false, "debug mode")
flag.BoolVar(&showVersionFlag, "v", false, "show version and exit")
flag.Parse()
}

func deb(m string) {
if debugFlag {
fmt.Println("DEBUG: " + m)
Expand Down Expand Up @@ -79,7 +74,7 @@ func showBuildInfo() {
fmt.Println(info.String())
}

func prepareFormatters() (func([]slogtotext.Pair) error, func([]slogtotext.Pair) error) {
func readEnvs() (string, string, bool) {
c := sdenv.NewCollectsion()
c.PushStd(os.Environ())
envFile := lookupEnvFile()
Expand All @@ -97,91 +92,55 @@ func prepareFormatters() (func([]slogtotext.Pair) error, func([]slogtotext.Pair)

logLine := `{{ .time }} [{{ .level }}] {{ .msg }}{{ range .ALL | rm "time" "level" "msg" }} {{.K}}={{.V}}{{end}}`
errLine := `INVALID JSON: {{ .TEXT | printf "%q" }}`
childMode := false
for _, p := range c.Collection() {
switch p[0] {
case "PPLOG_LOGLINE":
logLine = p[1]
case "PPLOG_ERRLINE":
errLine = p[1]
case "PPLOG_CHILD_MODE":
childMode = true
}
}
logLine = normLine(logLine)
errLine = normLine(errLine)
return slogtotext.MustFormatter(os.Stdout, logLine), slogtotext.MustFormatter(os.Stdout, errLine)
}

func runSubprocessMode() {
deb("run subprocess mode")

target := flag.Args()
binary, err := exec.LookPath(target[0])
if err != nil {
panic(err)
}

r, w, err := os.Pipe()
if err != nil {
panic(err)
}

chFiles := make([]uintptr, 3) // in, out, err
chFiles[0] = r.Fd()
chFiles[1] = os.Stdout.Fd()
chFiles[2] = os.Stderr.Fd()

selfBinaty, err := exec.LookPath(os.Args[0])
if err != nil {
panic(err)
}
cwd, err := os.Getwd()
if err != nil {
panic(err)
}
pid, err := syscall.ForkExec(selfBinaty, os.Args[:1], &syscall.ProcAttr{
Dir: cwd,
Env: os.Environ(),
Files: chFiles,
Sys: nil,
})
if err != nil {
panic(selfBinaty + ": " + err.Error())
}
deb(fmt.Sprintf("subprocess pid: %d", pid))

err = syscall.Dup2(int(w.Fd()), syscall.Stdout) // os.Stdout = w
if err != nil {
panic(err)
}
err = syscall.Dup2(int(w.Fd()), syscall.Stderr) // os.Stderr = w
if err != nil {
panic(err)
}

err = syscall.Exec(binary, target, os.Environ())
if err != nil {
panic(binary + ": " + err.Error())
}
return logLine, errLine, childMode
}

func runPipeMode() {
func runPipeMode(lineFmt, errFmt func([]slogtotext.Pair) error) {
deb("run pipe mode")
f, g := prepareFormatters()
err := slogtotext.Read(os.Stdin, f, g, 32768)
err := slogtotext.Read(os.Stdin, lineFmt, errFmt, buffSize)
if err != nil {
printError(err)
return
}
}

func main() {
flag.BoolVar(&debugFlag, "d", false, "debug mode")
flag.BoolVar(&showVersionFlag, "v", false, "show version and exit")
flag.BoolVar(&childModeFlag, "c", false, "child mode. pplog runs as child of target process")
flag.Parse()

deb(fmt.Sprintf("flags: debug=%t, showVersion=%t, childMode=%t", debugFlag, showVersionFlag, childModeFlag))

if showVersionFlag {
showBuildInfo()
return
}

lineTemplate, errTemplate, childMode := readEnvs()
outputStream := os.Stdout // TODO make it tunable

if flag.NArg() >= 1 {
runSubprocessMode()
if childModeFlag || childMode {
runSubprocessModeChild()
} else {
runSubprocessMode(slogtotext.MustFormatter(outputStream, lineTemplate), slogtotext.MustFormatter(outputStream, errTemplate))
}
} else {
runPipeMode()
runPipeMode(slogtotext.MustFormatter(outputStream, lineTemplate), slogtotext.MustFormatter(outputStream, errTemplate))
}
}

Expand Down
65 changes: 65 additions & 0 deletions cmd/pplog/run.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,65 @@
//go:build !windows
// +build !windows

package main

import (
"flag"
"fmt"
"os"
"os/exec"
"syscall"
)

func runSubprocessModeChild() {
deb("run child mode")

target := flag.Args()
binary, err := exec.LookPath(target[0])
if err != nil {
panic(err)
}

r, w, err := os.Pipe()
if err != nil {
panic(err)
}

chFiles := make([]uintptr, 3) //nolint:mnd // in, out, err
chFiles[0] = r.Fd()
chFiles[1] = os.Stdout.Fd()
chFiles[2] = os.Stderr.Fd()

selfBinaty, err := exec.LookPath(os.Args[0])
if err != nil {
panic(err)
}
cwd, err := os.Getwd()
if err != nil {
panic(err)
}
pid, err := syscall.ForkExec(selfBinaty, os.Args[:1], &syscall.ProcAttr{
Dir: cwd,
Env: os.Environ(),
Files: chFiles,
Sys: nil,
})
if err != nil {
panic(selfBinaty + ": " + err.Error())
}
deb(fmt.Sprintf("subprocess pid: %d", pid))

err = syscall.Dup2(int(w.Fd()), syscall.Stdout) // os.Stdout = w
if err != nil {
panic(err)
}
err = syscall.Dup2(int(w.Fd()), syscall.Stderr) // os.Stderr = w
if err != nil {
panic(err)
}

err = syscall.Exec(binary, target, os.Environ())
if err != nil {
panic(binary + ": " + err.Error())
}
}
Loading