Hanging Proccesses?

[lee-aaron]

👋 I found this out a while ago and am playing around with it. However, I noticed some processes are hanging when I switched from zsh to fish.

~ 
❯ ps aux | grep atuin
aaronlee         69641   0.0  0.0 408626896   1328 s002  S+   10:08AM   0:00.00 grep --color=auto atuin
aaronlee         69535   0.0  0.1 409139200  18768 s002  S    10:08AM   0:00.12 atuin history end --exit 0 -- 0188017cc71e79a4b25d53b2f1bb8353
aaronlee         69275   0.0  0.1 409287584  19936   ??  S    10:08AM   0:00.12 atuin history end --exit 0 -- 0188017c9ee970a98a36f666a2b9f6dc
aaronlee         69029   0.0  0.1 409400224  19120   ??  S    10:08AM   0:00.11 atuin history end --exit 0 -- 0188017c761474fe956353a2a5d4f4e7
aaronlee         68893   0.0  0.1 409114528  18896   ??  S    10:08AM   0:00.11 atuin history end --exit 0 -- 0188017c61567f469382b4ba650de807

I just opened a new terminal and typed ls before this. It's a bit annoying when I close the terminal tab but are there any solutions to this?

[TilBlechschmidt]

I just ran into the same issue. Same symptoms of the shell hanging for a good few seconds after a command finishes execution (and ps shows atuin history end running so this is likely the _atuin_pre_prompt hook from the atuin init). Interestingly enough this does not happen all the time but either every now and then or after a fixed count. Not quite sure which one of the two.

I suspect this is related to the fact that I recently imported a large zsh history file with ~50k entries and use sync (with my own server, although it is in the local network). Manually running atuin sync takes about the same time as the hanging prompt rendering (~7sec in my case).

Either way, this is pretty annoying and I would consider it pretty much a critical bug (a history augmentation plugin should not get in the way of shell execution but rather do its dirty work in the background — although this seems like a bug to me).

If there is anything I could try to get you more debug info, let me know!

[conradludgate]

This would be the automated periodic sync running. It's supposed to run in the background.

How have you configured your atuin shell installs? That would help narrow down the root cause

[TilBlechschmidt]

Hey Conrad,

I am not quite sure what details you are asking for so here is a general collection of setup details – let me know if you are looking for anything more specific.

Versions

• macOS Ventura 13.6 (22G120)
• iTerm2 (3.4.20)
  • nu is configured as the startup shell with a manually injected $env.PATH to make stuff work
    (in case it matters, setup scripts in the repo at the bottom)
• nushell 0.85.0
• atuin 16.0.0
  • self-hosted sync server uses the same version but from the docker file

Both nushell and atuin were installed with cargo install.

Atuin setup

Atuin was initialised by running atuin init nu --disable-up-arrow > ~/.local/share/atuin/init.nu which is subsequently sourced in a file referenced by the one at $nu.config-path.

File contents

~/.config/atuin/config.toml

## where to store your database, default is your system data directory
## linux/mac: ~/.local/share/atuin/history.db
## windows: %USERPROFILE%/.local/share/atuin/history.db
# db_path = "~/.history.db"

## where to store your encryption key, default is your system data directory
## linux/mac: ~/.local/share/atuin/key
## windows: %USERPROFILE%/.local/share/atuin/key
# key_path = "~/.key"

## where to store your auth session token, default is your system data directory
## linux/mac: ~/.local/share/atuin/session
## windows: %USERPROFILE%/.local/share/atuin/session
# session_path = "~/.session"

## date format used, either "us" or "uk"
# dialect = "us"

## enable or disable automatic sync
auto_sync = true

## enable or disable automatic update checks
# update_check = true

## address of the sync server
sync_address = "https://shell.tibl.dev"

## how often to sync history. note that this is only triggered when a command
## is ran, so sync intervals may well be longer
## set it to 0 to sync after every command
# sync_frequency = "1h"

## which search mode to use
## possible values: prefix, fulltext, fuzzy, skim
# search_mode = "fuzzy"

## which filter mode to use
## possible values: global, host, session, directory
# filter_mode = "global"

## which filter mode to use when atuin is invoked from a shell up-key binding
## the accepted values are identical to those of "filter_mode"
## leave unspecified to use same mode set in "filter_mode"
# filter_mode_shell_up_key_binding = "global"

## which style to use
## possible values: auto, full, compact
# style = "auto"

## the maximum number of lines the interface should take up
## set it to 0 to always go full screen
# inline_height = 0

## enable or disable showing a preview of the selected command
## useful when the command is longer than the terminal width and is cut off
# show_preview = false

## what to do when the escape key is pressed when searching
## possible values: return-original, return-query
# exit_mode = "return-original"

## possible values: emacs, subl
# word_jump_mode = "emacs"

## characters that count as a part of a word
# word_chars = "abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789"

## number of context lines to show when scrolling by pages
# scroll_context_lines = 1

## use ctrl instead of alt as the shortcut modifier key for numerical UI shortcuts
## alt-0 .. alt-9
# ctrl_n_shortcuts = true

## prevent commands matching any of these regexes from being written to history.
## Note that these regular expressions are unanchored, i.e. if they don't start
## with ^ or end with $, they'll match anywhere in the command.
## For details on the supported regular expression syntax, see
## https://docs.rs/regex/latest/regex/#syntax
# history_filter = [
#   "^secret-cmd",
#   "^innocuous-cmd .*--secret=.+"
# ]

## prevent commands run with cwd matching any of these regexes from being written
## to history. Note that these regular expressions are unanchored, i.e. if they don't
## start with ^ or end with $, they'll match anywhere in CWD.
## For details on the supported regular expression syntax, see
## https://docs.rs/regex/latest/regex/#syntax
# cwd_filter = [
#   "^/very/secret/area"
# ]

workspaces = true
show_help = false

~/.local/share/atuin/init.nu

# Source this in your ~/.config/nushell/config.nu
$env.ATUIN_SESSION = (atuin uuid)

# Magic token to make sure we don't record commands run by keybindings
let ATUIN_KEYBINDING_TOKEN = $"# (random uuid)"

let _atuin_pre_execution = {||
    let cmd = (commandline)
    if ($cmd | is-empty) {
        return
    }
    if not ($cmd | str starts-with $ATUIN_KEYBINDING_TOKEN) {
        $env.ATUIN_HISTORY_ID = (atuin history start -- $cmd)
    }
}

let _atuin_pre_prompt = {||
    let last_exit = $env.LAST_EXIT_CODE
    if 'ATUIN_HISTORY_ID' not-in $env {
        return
    }
    with-env { RUST_LOG: error } {
        atuin history end $'--exit=($last_exit)' -- $env.ATUIN_HISTORY_ID | null
    }
}

def _atuin_search_cmd [...flags: string] {
    [
        $ATUIN_KEYBINDING_TOKEN,
        ([
            `commandline (RUST_LOG=error run-external --redirect-stderr atuin search`,
            ($flags | append [--interactive, --] | each {|e| $'"($e)"'}),
            `(commandline) | complete | $in.stderr | str substring ..-1)`,
        ] | flatten | str join ' '),
    ] | str join "\n"
}

$env.config = ($env | default {} config).config
$env.config = ($env.config | default {} hooks)
$env.config = (
    $env.config | upsert hooks (
        $env.config.hooks
        | upsert pre_execution (
            $env.config.hooks | get -i pre_execution | default [] | append $_atuin_pre_execution)
        | upsert pre_prompt (
            $env.config.hooks | get -i pre_prompt | default [] | append $_atuin_pre_prompt)
    )
)

$env.config = (
    $env.config | upsert keybindings (
        $env.config.keybindings
        | append {
            name: atuin
            modifier: control
            keycode: char_r
            mode: [emacs, vi_normal, vi_insert]
            event: { send: executehostcommand cmd: (_atuin_search_cmd) }
        }
    )
)

Remaining shell configuration

[TilBlechschmidt]

If it helps I could change the _atuin_pre_prompt hook so that it appends the output of atuin history end to a file (and increase the log level to debug).

EDIT: I can confirm that changing the sync_frequency config option to 0 does indeed cause the shell to hang after every command. However, setting RUST_LOG to debug and removing the | null does not produce any additional output 😢

let _atuin_pre_prompt = {||
    let last_exit = $env.LAST_EXIT_CODE
    if 'ATUIN_HISTORY_ID' not-in $env {
        return
    }
    with-env { RUST_LOG: debug } {
        echo "hello world"
        atuin history end $'--exit=($last_exit)' -- $env.ATUIN_HISTORY_ID
    }
}

[TilBlechschmidt]

After analysing it for a bit longer, it seems that it is not the actual atuin history end call which hangs but rather a side-effect it causes. I have modified the pre-prompt hook to display time-stamps before and after said command which complete instantly:

with-env { RUST_LOG: error } {
    echo post-start (date now | to text)
    atuin history end $'--exit=($last_exit)' -- $env.ATUIN_HISTORY_ID | null
    echo post-finsh (date now | to text)
}

However, after this block completes the shell still hangs for a couple of seconds before the prompt is rendered again. Based on the output from ps and the fact that removing the atuin history end "solves" this delay, I would assume that this is caused by a side-effect triggered by that command.

[TilBlechschmidt]

Digging deeper, it looks like the shell process tree consumes 100% CPU (presumably while running the side-effect of history end) — may this be the culprit? If the background task caused by atuin and the prompt rendering run in the same process, then maybe that's what blocks the prompt? This would be consistent with other behaviour like CTRL+C not working (although that may just be an intrinsic of nu, haven't used it long enough to judge that).

cpuload.mov

[TilBlechschmidt]

Digging into the code, it seems that it is not actually RUST_LOG which has to be set but ATUIN_LOG (inconsistency with the shell init script?). Setting that immediately produces a metric ton of output which I have appended below. Unfortunately it has been mildly butchered by the shell for some reason ☹️

Original
atuin_log.txt

Cleaned (s/ +/ /g)
atuin_log_clean.txt

This excludes the hyper and h2 debug logs because my god do they take debug liberally :D
_{(if you need them let me know)}

[conradludgate]

Digging into the code, it seems that it is not actually RUST_LOG which has to be set but ATUIN_LOG

Yeah, I spotted that too #1263

[conradludgate]

Atuin was initialised by running atuin init nu --disable-up-arrow > ~/.local/share/atuin/init.nu which is subsequently sourced in a file referenced by the one at $nu.config-path.

Ah yes, nu, I was looking at the shell init script earlier and it doesn't see we use background processing in nu on end. This means that it will pause while it syncs

[conradludgate]

Setting that immediately produces a metric ton of output which I have appended below

Ok from your logfile I have a bit more context into what's going on here. It looks like your client is attempting to do a full sync everytime. I see 48 rows returned: 1100 lines and a final rows returned: 278, this adds up to reported we have 53078 rows.

I also see that you self host your sync server. Can you confirm what version that's running on?

[conradludgate]

Anyway, besides what is causing this issue here I think I'm going to set a 1s timeout on background sync. wdyt @ellie ?

[TilBlechschmidt]

Ah, I see, for bash the process is deferred as a background task! It seems that nu does not support that natively?

I can think of two possible solutions:

1. Fork internally (there is fork but I'm not sure about OS support)
2. Conditionally use pueue if available (although checking whether the daemon is actually running might be required to prevent accidental non-sync)

P.S.: Is there any particular reason that the sync takes this long and consumes that much CPU?

[ellie]

Anyway, besides what is causing this issue here I think I'm going to set a 1s timeout on background sync. wdyt @ellie ?

I'd go for something more like 3-5s, bearing in mind some setups will have a higher network latency + there's a few calls going on. But it makes sense!

[ellie]

P.S.: Is there any particular reason that the sync takes this long and consumes that much CPU?

This is probably the issue here, and I'm unsure if it's an issue with the code or your current setup.

If you could confirm whether you're running a tagged release on the server, or a commit sha - and also if there are any error logs on the server. It's usually pretty descriptive if there's something going on that aborts sync.

One such example would be where you have a very large history item. The server is generally pretty defensive about this by default, you may wish to configure the size allowed there