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

broken pane #178

Open
fawaf opened this issue Feb 27, 2023 · 12 comments
Open

broken pane #178

fawaf opened this issue Feb 27, 2023 · 12 comments

Comments

@fawaf
Copy link

fawaf commented Feb 27, 2023

if i specify 1 or more panes to do work in (e.g. echo 1 2 3), xpanes will have a blank pane that doesn't show anything and does not respond to input. not sure if it is a misconfiguration on my side, or a tmux issue.

see screen capture below for an example of this happening
https://user-images.githubusercontent.com/639565/221677162-56a3dff5-33d2-4a11-8004-ef32664c47ba.mov

@greymd
Copy link
Owner

greymd commented Feb 27, 2023

That's an interesting error.
Could you run the following command and see if it mitigate the issue?

wget https://raw.githubusercontent.com/greymd/tmux-xpanes/v4.1.3/bin/xpanes
sed -i.bak '669s/$/\n    sleep 0.5/' xpanes
chmod +x xpanes
./xpanes --debug -s {1..5}

The above operations inserts sleep command into https://github.com/greymd/tmux-xpanes/blob/v4.1.3/bin/xpanes#L669-L670 , and execute updated ./xpanes.

There is a known issue that particular environments gets problem when processing named pipes in parallel. And the error you reported also seems to be related to named pipes.
The issue said that adding sleep may mitigate the issue.
I would like to know if this is the case in your environment.

After that, could you please share the output of the following command execution?

## For macOS
sysctl kern.version
## For Linux
uname -a
/usr/bin/env bash -c 'type mkfifo'
/usr/bin/env bash --version
xpanes --version
xpanes --debug -s {1..5}

Thanks,

@fawaf
Copy link
Author

fawaf commented Mar 2, 2023

yep, that seems to work. below is the requested info.

anes
xpanes:Debug: [2023-03-01_22:02:07]:xpns_check_cell_size:Window: { Height: 57, Width: 214 }
xpanes:Debug: [2023-03-01_22:02:07]:xpns_check_cell_size:Cell: { Height: 18, Width: 106 }
xpanes:Debug: [2023-03-01_22:02:07]:xpns_check_cell_size:# Of Panes: 5
xpanes:Debug: [2023-03-01_22:02:07]:xpns_check_cell_size:         | Row[0] --...--> Row[MAX]
xpanes:Debug: [2023-03-01_22:02:07]:xpns_check_cell_size:    -----+------------------------...
xpanes:Debug: [2023-03-01_22:02:07]:xpns_check_cell_size:    Col[]| 2 2 1
xpanes:Debug: [2023-03-01_22:02:07]:xpns_check_cell_size:    -----+------------------------...
xpanes:Debug: [2023-03-01_22:02:07]:xpns_execution:Options: '--debug' '-s' '-c' 'echo {} '
xpanes:Debug: [2023-03-01_22:02:08]:xpns_execution:Arguments: '1' '2' '3' '4' '5'
xpanes:Debug: [2023-03-01_22:02:08]:xpns_wait_func:mkfifo /Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-0-6305
xpanes:Debug: [2023-03-01_22:02:09]:xpns_wait_func:grep -q 1 '/Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-0-6305'
xpanes:Debug: [2023-03-01_22:02:09]:xpns_prepare_window:_col=1
xpanes:Debug: [2023-03-01_22:02:09]:xpns_wait_func:mkfifo /Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-4-6305
xpanes:Debug: [2023-03-01_22:02:09]:xpns_wait_func:grep -q 1 '/Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-4-6305'
xpanes:Debug: [2023-03-01_22:02:09]:xpns_prepare_window:_top_pane_height=38 _rest_row=2
xpanes:Debug: [2023-03-01_22:02:09]:xpns_prepare_window:_col=2
xpanes:Debug: [2023-03-01_22:02:10]:xpns_wait_func:mkfifo /Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-2-6305
xpanes:Debug: [2023-03-01_22:02:10]:xpns_wait_func:grep -q 1 '/Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-2-6305'
xpanes:Debug: [2023-03-01_22:02:10]:xpns_wait_func:mkfifo /Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-3-6305
xpanes:Debug: [2023-03-01_22:02:10]:xpns_wait_func:grep -q 1 '/Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-3-6305'
xpanes:Debug: [2023-03-01_22:02:10]:xpns_prepare_window:_top_pane_height=19 _rest_row=1
xpanes:Debug: [2023-03-01_22:02:10]:xpns_wait_func:mkfifo /Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-1-6305
xpanes:Debug: [2023-03-01_22:02:10]:xpns_wait_func:grep -q 1 '/Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-1-6305'
xpanes:Debug: [2023-03-01_22:02:11]:xpns_execution:xpns_is_window_alive:1: After window separation
xpanes:Debug: [2023-03-01_22:02:11]:xpns_execution:xpns_is_window_alive:2: After logging
xpanes:Debug: [2023-03-01_22:02:11]:xpns_notify:Notify to /Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-0-6305
xpanes:Debug: [2023-03-01_22:02:11]:xpns_notify:Notify to /Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-1-6305
xpanes:Debug: [2023-03-01_22:02:12]:xpns_notify:Notify to /Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-2-6305
xpanes:Debug: [2023-03-01_22:02:12]:xpns_notify:Notify to /Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-3-6305
xpanes:Debug: [2023-03-01_22:02:13]:xpns_notify:Notify to /Users/waf/.cache/xpanes/__xpns_sync_312d363330350a-4-6305
xpanes:Debug: [2023-03-01_22:02:13]:xpns_execution:xpns_is_window_alive:3: After setting title
xpanes:Debug: [2023-03-01_22:02:13]:xpns_execution:xpns_is_window_alive:4: After sending commands
xpanes:Debug: [2023-03-01_22:02:14]:xpns_clean_session:file = /Users/waf/.cache/xpanes/socket.*
xpanes:Debug: [2023-03-01_22:02:14]:xpns_clean_session:socket(/Users/waf/.cache/xpanes/socket.*) is not running. Remove it
waf@C02G10TSMD6T in dir /tmp
% sysctl kern.version
kern.version: Darwin Kernel Version 21.6.0: Mon Dec 19 20:44:01 PST 2022; root:xnu-8020.240.18~2/RELEASE_X86_64
waf@C02G1

@greymd
Copy link
Owner

greymd commented Mar 13, 2023

Thank you @fawaf for providing logs.

I wonder if there is a problem with the parallel processing of named pipes created by mkfifo in your environment.
Because I have seen other similar issues #173 on macOS and the reporter said similar symptom.

And I am very interested in the cause of this problem.

If you don't mind, could you save the script below and run it in bash?
The script creates 50 named pipes and writes in parallel, easily replicating the behavior of xpanes.

#!/bin/bash
set -eu
## Create temporary directory
tmpdir=$(mktemp -d)
## Clean directory on exit
trap 'rm -rf $tmpdir' EXIT
## function to read from a pipe
readpipe() {
  grep . "$1" &
}

{
  cd "$tmpdir"

  # 1. Create a named pipe x 50 in the temporary directory (pipe.1 .. pipe.50)
  for i in {1..50}
  do
      mkfifo pipe."$i"
  done

  # 2. Create 50 threads to read from each pipe
  for i in {1..50}
  do
      readpipe pipe."$i"
  done

  # 3. Input a number from 1 to 50 into each pipe asynchronusly
  for i in {1..50}
  do
      printf "finish:$i" > pipe."$i" &
  done

  # 4. Each thread will read the number from the pipe and print it to the screen
  wait
}

In my environment, it successfully processes 50 named pipes as shown below. What about your environment?

$ bash mkfifos.sh
finish:1
finish:2
finish:3
finish:4
finish:5
finish:7
finish:6
finish:10
finish:9
finish:12
finish:18
finish:14
finish:13
finish:16
finish:15
finish:8
finish:17
finish:11
finish:19
finish:24
finish:22
finish:20
finish:23
finish:25
finish:21
finish:27
finish:29
finish:26
finish:30
finish:34
finish:31
finish:28
finish:38
finish:33
finish:44
finish:35
finish:47
finish:42
finish:32
finish:37
finish:39
finish:36
finish:40
finish:41
finish:43
finish:46
finish:49
finish:48
finish:45
finish:50

@greymd
Copy link
Owner

greymd commented Mar 13, 2023

@fawaf

The latest version, v4.1.4, the feature --interval option is implemented.
This may be used as a work-around for this problem.
For example, the following alias can be specified to sleep for 0.2 second for each pane creation or execution of each command.

alias xpanes='xpanes --interval 0.2'

Please make use of this.

@fawaf
Copy link
Author

fawaf commented Mar 13, 2023

output as requested. looks fine to me i think?

D6T:/tmp% bash ouixcouiioubzcbzcx
finish:1
finish:2
finish:3
finish:4
finish:5
finish:6
finish:7
finish:9
finish:10
finish:11
finish:13
finish:8
finish:16
finish:15
finish:14
finish:20
finish:19
finish:21
finish:12
finish:17
finish:18
finish:22
finish:24
finish:29
finish:25
finish:23
finish:26
finish:27
finish:31
finish:32
finish:28
finish:37
finish:30
finish:35
finish:34
finish:36
finish:33
finish:45
finish:41
finish:38
finish:43
finish:40
finish:39
finish:48
finish:42
finish:49
finish:47
finish:46
finish:44
finish:50
Mon Mar 13 1 %

@fawaf
Copy link
Author

fawaf commented Mar 13, 2023

submitted Homebrew/homebrew-core#125557 as well

@greymd
Copy link
Owner

greymd commented Mar 14, 2023

output as requested. looks fine to me i think?

Yes, it looks it works normally.
We need to investigate the issue from a different point of view.

submitted Homebrew/homebrew-core#125557 as well

Thank you so much 😃

Can you try to reproduce the issue when you get to use v4.1.4?
I removed an unnecessary background processing and it would change the situation.. I hope.

@fawaf
Copy link
Author

fawaf commented Mar 14, 2023

just tested out the new version and the issue still exists with v4.1.4 (without --interval). oddly though, the issue does not happen when running with the --debug flag.

@fawaf
Copy link
Author

fawaf commented Mar 14, 2023

hmm.... the issue disappears after running xpanes a few times. odd...

@greymd
Copy link
Owner

greymd commented Mar 14, 2023

Oh, that's weird.

Ok, if the issue reproduced next time, can you collect logs by following way?
I need to dive into more detailed log given by set -x.

  1. Save this file as xpanes.patch
diff --git a/xpanes b/xpanes
index d503b90..e2ecb08 100755
--- a/xpanes
+++ b/xpanes
@@ -47,7 +47,7 @@ readonly XP_ENOCMD=127
 # XP_THIS_FILE_NAME is supposed to be "xpanes".
 readonly XP_THIS_FILE_NAME="${0##*/}"
 readonly XP_THIS_DIR="$(cd "$(dirname "${BASH_SOURCE[0]:-$0}")" && pwd)"
-readonly XP_ABS_THIS_FILE_NAME="${XP_THIS_DIR}/${XP_THIS_FILE_NAME}"
+readonly XP_ABS_THIS_FILE_NAME="bash -x ${XP_THIS_DIR}/${XP_THIS_FILE_NAME}"

 # Prevent cache directory being created under root / directory in any case.
 # This is quite rare case (but it can be happened).
@@ -1516,7 +1516,7 @@ xpns_pre_execution() {
   ${TMUX_XPANES_EXEC} -S "${XP_SOCKET_PATH}" new-session \
     -s "${XP_SESSION_NAME}" \
     -n "${XP_TMP_WIN_NAME}" \
-    -d "${XP_ABS_THIS_FILE_NAME} ${_opts4args} ${_args4args}"
+    -d "${XP_ABS_THIS_FILE_NAME} ${_opts4args} ${_args4args} &> debug.log"

   # Avoid attaching (for unit testing).
   if [[ ${XP_OPT_ATTACH} -eq 1 ]]; then
  1. And run following and reproduce the issue.
$ wget https://raw.githubusercontent.com/greymd/tmux-xpanes/v4.1.4/bin/xpanes
$ patch < xpanes.patch
### Reproduce the issue
$ bash -x ./xpanes -s {1..5} 2> start-debug.log
  1. You'll get start-debug.log and debug.log files on current dir. Plz provide both of them.

@fawaf
Copy link
Author

fawaf commented Apr 25, 2023

cool, happened just now. attached log file as requested. oddly, i don't see the debug.log file though and only the start-debug file.
start-debug.log

@fawaf
Copy link
Author

fawaf commented Apr 25, 2023

btw, i think i totally forgot to mention that i'm running xpanes in an existing tmux session.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants