Bash

通知偵聽器在後台執行時行為異常

  • June 16, 2016

我一直在努力讓我的 IRC-Bouncer/Notification Script 工作。

這是一個腳本,它將自動登錄到遠端電腦,附加到執行 weechat 的螢幕會話(或者如果目前不存在,則啟動一個),同時打開另一個使用 netcat 從套接字文件讀取通知的 ssh 連接微信外掛腳本將我的通知消息導出到其中。然後將這些通知輸入 lib-notify(通過 notify-send),以便我可以收到微信中的活動警報。

這是腳本:

#!/bin/bash

BOUNCER="MYUSER@MYBOUNCER.NET"

function irc_notify() {
 ssh $BOUNCER "nc -k -l -U /tmp/weechat.notify.sock" | \
   while read type message; do
    notify-send -i weechat -u critical "$(echo -n $type | base64 -di -)" "$(echo -n $message | base64 -di -)"
   done
}

# Start listening for notifications
irc_notify &

# Attach to remote IRC Bouncer Screen
ssh $BOUNCER -t 'screen -d -R -S irc weechat'

# Cleanup Socket Listener
echo "cleaning up notification socket listener…"
ssh $BOUNCER 'pkill -f -x "nc -k -l -U /tmp/weechat.notify.sock"'

該設置實際上執行良好,除了一個主要故障。 每次呼叫腳本時,只有兩個通知通過我的通知管理器。之後:什麼都沒有。

因此,為了消除 weechat 中通知腳本的問題,我刪除了第二個 ssh 呼叫(附加到螢幕會話並啟動 weechat 的那個),並read在我測試時將其替換為阻止執行的命令。然後,irb在遠端機器上使用,我用 ruby​​ 向套接字發送消息。

但是,即使我手動發送消息,在它停止工作之前仍然只會出現兩條消息

strace向我展示了一些有趣的行為(當我附加到分叉程序時),在第一條或第二條消息之後,消息似乎停止被換行符終止。但再過幾次之後,它們就不再出現strace在一起了。

在這一點上,我決定看看我的腳本中是否有什麼東西導致了奇怪的行為。 因此,在命令行中,我只是直接呼叫了 ssh 連接 ( ssh $BOUNCER "nc -k -l -U /tmp/weechat.notify.sock")。瞧,我手動發送的所有消息都出現了(當然,仍然是 base64 編碼的)。

然後我添加了邏輯來解碼每條消息,就像我在腳本中所做的那樣,它也適用於每條消息。包括當我將這些消息輸入通知發送時。

所以在這一點上,我決定當我 fork 函式時一定會發生一些奇怪的事情。但是當我將終端中的命令設置為背景時,我沒有觀察到效果上的差異。所以我想知道是否可能發生了一些奇怪的事情,因為它是從腳本中執行的。

就在這時,事情變得奇怪了……

我首先打破了函式的邏輯,直接呼叫它,在管道命令的末尾加上一個 & 符號。像這樣:

ssh $BOUNCER "nc -k -l -U /tmp/weechat.notify.sock" | \
 while read type message; do
   notify-send -i weechat -u critical "$(echo -n $type | base64 -di -)" "$(echo -n $message | base64 -di -)"
 done &

一旦我這樣做,消息突然開始工作。一旦我恢復了更改,我又回到了第一格,同樣奇怪的只有兩條消息的行為。

但是此修復程序引入了其他一些奇怪的行為。 一旦我進入螢幕會話,我必須多次點擊每個鍵才能被程序註冊。好像有一個競爭條件在爭奪 STDIN。

估計兩個 SSH 會話可能正在爭奪它(儘管我不確定為什麼),我試圖通過各種方式關閉和/或占用第一個 ssh 命令上的 STDIN。例如通過管道在: |它之前,或附加 <&-</dev/null在管道的 SSH 部分之後。雖然這似乎確實解決了競爭條件,但這重新引入了僅包含兩條消息的行為。

考慮到它可能與處於多層 sub-processing 下有關,然後我嘗試通過bash -c像這樣包裝 SSH 呼叫來重現這一點bash -c 'ssh $BOUNCER "nc -k -l -U /tmp/weechat.notify.sock" &':這也表現出只有兩條消息的行為。

我還直接在遠端機器上進行了測試(SSH 到本地主機,並包裝在兩個bash -c呼叫中)並目睹了同樣的破壞行為。 它似乎也與導致孤立程序的雙分叉無關。 因為該過程是否最終成為孤兒似乎並不重要。

我還驗證了這也發生在zsh.

這似乎與在子處理層下執行程序時處理 STDIN 和 STDOUT 的方式有關。

複製品。指令和strace輸出:

為了簡化調試,我從圖片中刪除了 SSH,並編寫了兩個簡化的測試腳本,它們成功地完全在本地重現了該行為。

使用 Juergen Nickelsen 的socket命令,我創建了一個本地 UNIX 域套接字 ( socket -l -s ./test.sock),並且再次能夠irb使用以下 Ruby 程式碼塊向其發送測試消息:

require 'socket'
require 'base64'

SOCKET = './test.sock'

def send(subtitle, message)
 UNIXSocket.open(SOCKET) do |socket|
   socket.puts "#{Base64.strict_encode64(subtitle)} #{Base64.strict_encode64(message)}"
 end
end

send('test', 'hi')
send('test', 'hi')
send('test', 'hi')
send('test', 'hi')
send('test', 'hi')
send('test', 'hi')

第一個腳本僅後台處理管道表達式(如前所述,它處理了無限數量的消息):

#!/bin/bash

# to aid in cleanup when using Ctrl-C to exit strace
trap "pkill -f -x 'nc -k -l -U $HOME/test.sock'; exit" SIGINT

# Start listening for notifications
nc -k -l -U $HOME/test.sock | \
 while read type message; do
   # write messages to a local file instead of sending to notification daemon for simplicity.
   echo "$(echo -n $type | base64 -di -)" "$(echo -n $message | base64 -di -)" >> /tmp/msg
 done &

read

並在執行時產生以下輸出:http strace -f: //pastebin.com/SMjti3qW

第二個腳本為包裝函式提供背景(觸發 2-and-done 行為):

#!/bin/bash

# to aid in cleanup when using Ctrl-C to exit strace
trap "pkill -f -x 'nc -k -l -U $HOME/test.sock'; exit" SIGINT

# Start listening for notifications
function irc_notify() {
 nc -k -l -U $HOME/test.sock | \
   while read type message; do
     # write messages to a local file instead of sending to notification daemon for simplicity.
     echo "$(echo -n $type | base64 -di -)" "$(echo -n $message | base64 -di -)" >> /tmp/msg
   done
}

irc_notify &

read

反過來,在執行時產生以下輸出:http strace -f: //pastebin.com/WsrXX0EJ

strace在查看上述腳本的輸出時,令我印象深刻的一件事是特定於nc命令的輸出。這似乎表明了這兩個腳本的執行之間的主要區別之一。

第一個腳本的“工作”nc strace輸出:

accept(3, {sa_family=AF_FILE, NULL}, [2]) = 4
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "dGVzdA== aGk=\n", 2048)        = 14
write(1, "dGVzdA== aGk=\n", 14)         = 14
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "", 2048)                       = 0
shutdown(4, 0 /* receive */)            = 0
close(4)                                = 0
accept(3, {sa_family=AF_FILE, NULL}, [2]) = 4
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "dGVzdA== aGk=\n", 2048)        = 14
write(1, "dGVzdA== aGk=\n", 14)         = 14
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "", 2048)                       = 0
shutdown(4, 0 /* receive */)            = 0
close(4)                                = 0
accept(3, {sa_family=AF_FILE, NULL}, [2]) = 4
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "dGVzdA== aGk=\n", 2048)        = 14
write(1, "dGVzdA== aGk=\n", 14)         = 14
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "", 2048)                       = 0
shutdown(4, 0 /* receive */)            = 0
close(4)                                = 0
accept(3, {sa_family=AF_FILE, NULL}, [2]) = 4
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "dGVzdA== aGk=\n", 2048)        = 14
write(1, "dGVzdA== aGk=\n", 14)         = 14
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "", 2048)                       = 0
shutdown(4, 0 /* receive */)            = 0
close(4)                                = 0
accept(3, {sa_family=AF_FILE, NULL}, [2]) = 4
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "dGVzdA== aGk=\n", 2048)        = 14
write(1, "dGVzdA== aGk=\n", 14)         = 14
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "", 2048)                       = 0
shutdown(4, 0 /* receive */)            = 0
close(4)                                = 0
accept(3, {sa_family=AF_FILE, NULL}, [2]) = 4
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "dGVzdA== aGk=\n", 2048)        = 14
write(1, "dGVzdA== aGk=\n", 14)         = 14
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "", 2048)                       = 0
shutdown(4, 0 /* receive */)            = 0
close(4)                                = 0
accept(3,

輸出中看到的第二個腳本的“2-and-done”行為nc strace

accept(3, {sa_family=AF_FILE, NULL}, [2]) = 4
poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 2 ([{fd=4, revents=POLLIN|POLLHUP}, {fd=0, revents=POLLHUP}])
read(4, "dGVzdA== aGk=\n", 2048)        = 14
write(1, "dGVzdA== aGk=\n", 14)         = 14
shutdown(4, 1 /* send */)               = 0
close(0)                                = 0
poll([{fd=4, events=POLLIN}, {fd=-1}], 2, -1) = 1 ([{fd=4, revents=POLLIN|POLLHUP}])
read(4, "", 2048)                       = 0
shutdown(4, 0 /* receive */)            = 0
close(4)                                = 0
accept(3, {sa_family=AF_FILE, NULL}, [2]) = 0
poll([{fd=0, events=POLLIN}, {fd=0, events=POLLIN}], 2, -1) = 2 ([{fd=0, revents=POLLIN|POLLHUP}, {fd=0, revents=POLLIN|POLLHUP}])
read(0, "dGVzdA== aGk=\n", 2048)        = 14
write(1, "dGVzdA== aGk=\n", 14)         = 14
read(0, "", 2048)                       = 0
shutdown(0, 1 /* send */)               = 0
close(0)                                = 0
poll([{fd=0, events=POLLIN}, {fd=-1}], 2, -1) = 1 ([{fd=0, revents=POLLNVAL}])
poll([{fd=0, events=POLLIN}, {fd=-1}], 2, -1) = 1 ([{fd=0, revents=POLLNVAL}])
poll([{fd=0, events=POLLIN}, {fd=-1}], 2, -1) = 1 ([{fd=0, revents=POLLNVAL}])
poll([{fd=0, events=POLLIN}, {fd=-1}], 2, -1) = 1 ([{fd=0, revents=POLLNVAL}])
poll([{fd=0, events=POLLIN}, {fd=-1}], 2, -1) = 1 ([{fd=0, revents=POLLNVAL}])
poll([{fd=0, events=POLLIN}, {fd=-1}], 2, -1) = 1 ([{fd=0, revents=POLLNVAL}])
poll([{fd=0, events=POLLIN}, {fd=-1}], 2, -1) = 1 ([{fd=0, revents=POLLNVAL}])
poll([{fd=0, events=POLLIN}, {fd=-1}], 2, -1) = 1 ([{fd=0, revents=POLLNVAL}])
poll([{fd=0, events=POLLIN}, {fd=-1}], 2, -1) = 1 ([{fd=0, revents=POLLNVAL}])
poll([{fd=0, events=POLLIN}, {fd=-1}], 2, -1) = 1 ([{fd=0, revents=POLLNVAL}])
.......[truncated].......

關於我的strace輸出可讀性,我不是我想要的,所以我不完全確定這些不同的輸出意味著什麼——除了一個顯然工作而另一個沒有工作的事實。

當我探勘更大的strace輸出時,似乎前兩個之後的消息不再被換行符終止?但同樣,我不確定這意味著什麼,或者我是否正確閱讀。

而且我絕對不明白不同的子處理技術,甚至關閉 STDIN,會如何影響這種行為。

知道我在這裡遇到什麼嗎?

tl;博士

我試圖弄清楚為什麼在多於一層的子處理下執行我的通知偵聽器會導致只處理兩條消息;並且不這樣做會導致 STDIN 上的競爭條件。

OpenBSD 的更新衍生產品netcat,包括 FreeBSD

$$ 1 $$和 Debian$$ 2 $$,支持-d阻止從標準輸入讀取並修復您描述的問題的標誌。 問題是 netcat 正在輪詢標準輸入及其“網路”fd,並且/dev/null在上面的第二種情況下重新打開標準輸入,其中 shell 函式在創建管道之前在後台執行。這意味著第一次從標準輸入(fd 0)讀取時立即出現 EOF,但 netcat 將繼續poll(2)在現在關閉的標準輸入上,創建一個無限循環。

這是創建管道之前的標準輸入重定向:

249 [pid 23186] open("/dev/null", O_RDONLY <unfinished ...>
251 [pid 23186] <... open resumed> )        = 3
253 [pid 23186] dup2(3, 0)                  = 0
254 [pid 23186] close(3)                    = 0

現在當 netcat (pid 23187) 呼叫它的 firstpoll(2)時,它從 stdin 讀取 EOF 並關閉 fd 0:

444 [pid 23187] poll([{fd=4, events=POLLIN}, {fd=0, events=POLLIN}], 2, 4294967295) = 2 ([{fd=4, revents=POLLIN|POLLHUP}, {fd=0, revents=POLLIN}])
448 [pid 23187] read(0,  <unfinished ...>
450 [pid 23187] <... read resumed> "", 2048) = 0
456 [pid 23187] close(0 <unfinished ...>
458 [pid 23187] <... close resumed> )       = 0

下一次呼叫accept(2)在 fd 0 上產生一個客戶端,它現在是編號最小的空閒 fd:

476 [pid 23187] accept(3,  <unfinished ...>
929 [pid 23187] <... accept resumed> {sa_family=AF_LOCAL, NULL}, [2]) = 0

請注意,netcat 現在將 fd 0 包含在 args 中poll(2)兩次:一次用於STDIN_FILENO,在缺少-d命令行參數的情況下始終包含,一次用於新連接的客戶端:

930 [pid 23187] poll([{fd=0, events=POLLIN}, {fd=0, events=POLLIN}], 2, 4294967295) = 2 ([{fd=0, revents=POLLIN|POLLHUP}, {fd=0, revents=POLLIN|POLLHUP}])

客戶端發送 EOF 和 netcat 斷開連接:

936 [pid 23187] read(0,  <unfinished ...>
938 [pid 23187] <... read resumed> "", 2048) = 0
940 [pid 23187] shutdown(0, SHUT_WR <unfinished ...>
942 [pid 23187] <... shutdown resumed> )    = 0
944 [pid 23187] close(0 <unfinished ...>
947 [pid 23187] <... close resumed> )       = 0

但是現在它遇到了麻煩,因為它將繼續在 fd 0 上進行輪詢,該 fd 0 現在已關閉。netcat 程式碼不處理POLLNVAL被設置在.revents成員中的情況struct pollfd,因此進入死循環,不再呼叫accept(2)

949 [pid 23187] poll([{fd=0, events=POLLIN}, {fd=-1}], 2, 4294967295 <unfinished ...>
951 [pid 23187] <... poll resumed> )        = 1 ([{fd=0, revents=POLLNVAL}])
953 [pid 23187] poll([{fd=0, events=POLLIN}, {fd=-1}], 2, 4294967295 <unfinished ...>
955 [pid 23187] <... poll resumed> )        = 1 ([{fd=0, revents=POLLNVAL}])
...

在第一個命令中,管道在後台執行但未在 shell 函式中執行,s​​tdin 保持打開狀態,因此不會出現這種情況。

程式碼參考(見readwrite函式):

  1. http://svnweb.freebsd.org/base/head/contrib/netcat/
  2. https://sources.debian.net/src/netcat-openbsd/1.105-7/

引用自:https://unix.stackexchange.com/questions/224499