☰

Debian 计算机上 auth.log 中的连接关闭日志行

tag-icon • tag-icon debian logs
Debian 计算机上 auth.log 中的连接关闭日志行

我auth.log的 Debian 机器上充满了以下消息：

CRON[1736]: pam_unix(cron:session): session opened for user root by (uid=0)
sshd[1742]: Connection closed by ::1 port 38518 [preauth]
CRON[1736]: pam_unix(cron:session): session closed for user root
sshd[1748]: Connection closed by ::1 port 38592 [preauth]
CRON[1752]: pam_unix(cron:session): session opened for user root by (uid=0)
sshd[1758]: Connection closed by ::1 port 38672 [preauth]
...

按照说明这里我添加了以下行/etc/pam.d/common-session-noninteractive：

session    [success=1 default=ignore] pam_succeed_if.so service in cron quiet use_uid

但是，以下行不断添加到auth.log文件中：

Jun 17 10:39:47 <machine> sshd[2175]: Connection closed by ::1 port 41262 [preauth]
Jun 17 10:40:21 <machine> sshd[2188]: Connection closed by ::1 port 41340 [preauth]
Jun 17 10:40:54 <machine> sshd[2194]: Connection closed by ::1 port 41416 [preauth]
Jun 17 10:41:28 <machine> sshd[2205]: Connection closed by ::1 port 41494 [preauth]
Jun 17 10:42:02 <machine> sshd[2228]: Connection closed by ::1 port 41576 [preauth]
Jun 17 10:42:35 <machine> sshd[2235]: Connection closed by ::1 port 41668 [preauth]
Jun 17 10:43:09 <machine> sshd[2246]: Connection closed by ::1 port 41764 [preauth]
Jun 17 10:43:42 <machine> sshd[2252]: Connection closed by ::1 port 41842 [preauth]
Jun 17 10:44:16 <machine> sshd[2262]: Connection closed by ::1 port 41922 [preauth]
Jun 17 10:44:50 <machine> sshd[2269]: Connection closed by ::1 port 41998 [preauth]
Jun 17 10:45:23 <machine> sshd[2285]: Connection closed by ::1 port 42084 [preauth]
Jun 17 10:45:57 <machine> sshd[2292]: Connection closed by ::1 port 42164 [preauth]
...

我不知道如何摆脱这些。首先，它显示 IP(v6) ::1（即 localhost）。但可以肯定的是：主机无法从外部世界访问（更不用说通过 IPv6 了，因为我的连接上未启用 IPv6）并且位于 OpenBSD 网关/防火墙后面。::1很可能是在我的本地计算机上运行的东西。所以我很确定它来自每分钟运行的 cronjob。这个 cronjob 看起来有点像这样：

php foo.php
sleep 30
php foo.php

这只是每 30 秒运行一次 PHP 脚本的一种（糟糕的）方式。脚本在几秒钟内完成。

然而，奇怪的是如果你看一下日志时间。你会期待一个条目整分钟（+/- 一两秒），然后，也许每半分钟再一次（+/- 几秒，具体取决于第一个脚本花费的时间 + 30 秒）。但事实并非如此。每个日志行之间的时间分别为 34, 33, 34, 34, 33, 34, 33, 34, 34, 33, 34, ... 秒。这意味着时间正在“漂移”。

更奇怪的是：如果我注释掉 crobtab 行，并且该作业每分钟运行一次，那么“连接​​被...关闭”行就会不断出现。即使该特定作业/脚本已被禁用。所以这告诉我这可能是不是导致这些行的 cronjob。也没有其他 cronjobs 可以解释这一点。

然后我运行了 tcpdump：

tcpdump -i lo port 22

果然，如果我稍等一下，我就会看到流量进来：

11:18:29.548247 IP6 localhost.46846 > localhost.ssh: Flags [S], seq 1675216317, win 43690, options [mss 65476,sackOK,TS val 1107033 ecr 0,nop,wscale 7], length 0
11:18:29.548270 IP6 localhost.ssh > localhost.46846: Flags [S.], seq 3867254410, ack 1675216318, win 43690, options [mss 65476,sackOK,TS val 1107033 ecr 1107033,nop,wscale 7], length 0
11:18:29.548279 IP6 localhost.46846 > localhost.ssh: Flags [.], ack 1, win 342, options [nop,nop,TS val 1107033 ecr 1107033], length 0
11:18:29.551956 IP6 localhost.ssh > localhost.46846: Flags [P.], seq 1:40, ack 1, win 342, options [nop,nop,TS val 1107034 ecr 1107033], length 39
11:18:29.551967 IP6 localhost.46846 > localhost.ssh: Flags [.], ack 40, win 342, options [nop,nop,TS val 1107034 ecr 1107034], length 0
11:18:29.551982 IP6 localhost.46846 > localhost.ssh: Flags [P.], seq 1:40, ack 40, win 342, options [nop,nop,TS val 1107034 ecr 1107034], length 39
11:18:29.552005 IP6 localhost.ssh > localhost.46846: Flags [.], ack 40, win 342, options [nop,nop,TS val 1107034 ecr 1107034], length 0
11:18:29.552448 IP6 localhost.ssh > localhost.46846: Flags [P.], seq 40:792, ack 40, win 342, options [nop,nop,TS val 1107034 ecr 1107034], length 752
11:18:29.552475 IP6 localhost.46846 > localhost.ssh: Flags [F.], seq 40, ack 792, win 354, options [nop,nop,TS val 1107034 ecr 1107034], length 0
11:18:29.552778 IP6 localhost.ssh > localhost.46846: Flags [F.], seq 792, ack 41, win 342, options [nop,nop,TS val 1107034 ecr 1107034], length 0
11:18:29.552784 IP6 localhost.46846 > localhost.ssh: Flags [.], ack 793, win 354, options [nop,nop,TS val 1107034 ecr 1107034], length 0
11:19:03.202403 IP6 localhost.46962 > localhost.ssh: Flags [S], seq 4240077294, win 43690, options [mss 65476,sackOK,TS val 1115447 ecr 0,nop,wscale 7], length 0
11:19:03.202427 IP6 localhost.ssh > localhost.46962: Flags [S.], seq 3703193700, ack 4240077295, win 43690, options [mss 65476,sackOK,TS val 1115447 ecr 1115447,nop,wscale 7], length 0
11:19:03.202442 IP6 localhost.46962 > localhost.ssh: Flags [.], ack 1, win 342, options [nop,nop,TS val 1115447 ecr 1115447], length 0
11:19:03.206034 IP6 localhost.ssh > localhost.46962: Flags [P.], seq 1:40, ack 1, win 342, options [nop,nop,TS val 1115448 ecr 1115447], length 39
11:19:03.206044 IP6 localhost.46962 > localhost.ssh: Flags [.], ack 40, win 342, options [nop,nop,TS val 1115448 ecr 1115448], length 0
11:19:03.206077 IP6 localhost.46962 > localhost.ssh: Flags [P.], seq 1:40, ack 40, win 342, options [nop,nop,TS val 1115448 ecr 1115448], length 39
11:19:03.206093 IP6 localhost.ssh > localhost.46962: Flags [.], ack 40, win 342, options [nop,nop,TS val 1115448 ecr 1115448], length 0
11:19:03.206573 IP6 localhost.ssh > localhost.46962: Flags [P.], seq 40:792, ack 40, win 342, options [nop,nop,TS val 1115448 ecr 1115448], length 752
11:19:03.206601 IP6 localhost.46962 > localhost.ssh: Flags [F.], seq 40, ack 792, win 354, options [nop,nop,TS val 1115448 ecr 1115448], length 0
11:19:03.206981 IP6 localhost.ssh > localhost.46962: Flags [F.], seq 792, ack 41, win 342, options [nop,nop,TS val 1115448 ecr 1115448], length 0
11:19:03.206986 IP6 localhost.46962 > localhost.ssh: Flags [.], ack 793, win 354, options [nop,nop,TS val 1115448 ecr 1115448], length 0

大约 33/34 秒后，更多流量涌入。但是，同样，不知道流量来自何处......

所以我有两个问题：

  1. 我如何找出哪个进程/什么原因导致这些日志行
  2. 我如何摆脱这些日志行（这可能取决于 1 当然）

答案1

没关系，我已经弄清楚了。它是监控监控 SSH 守护进程。我是个笨蛋。我停止了 monit ( service monit stop)，跟踪了auth.log，然后，什么，没有更多的条目了。这样谜团就解决了，monit 重新启动了。现在我知道原因了，我不再介意这些梗概了。

相关内容