fatedier / frp

A fast reverse proxy to help you expose a local server behind a NAT or firewall to the internet.
Apache License 2.0
86.46k stars 13.37k forks source link

[Feature Request] log the duration of each connecttion #2915

Closed berlin2123 closed 2 years ago

berlin2123 commented 2 years ago

Describe the feature request

If the duration of each connecttion is loged, we can check if that is a Brute_Force_Attack connections by fail2ban in frps server.

most Brute_Force_Attack connections remains in a short time. So that, we can Identify it by its duration and repetition.

Describe alternatives you've considered

I am unfamiliar with go, so just a sample:

need change file server/proxy/proxy.go

startime = the time in microseconds
xl.Debug("join connections, workConn(l[%s] r[%s]) userConn(l[%s] r[%s])", workConn.LocalAddr().String(),
        workConn.RemoteAddr().String(), userConn.LocalAddr().String(), userConn.RemoteAddr().String())
......
endtime = the time in microseconds
connection_duration = endtime - startime
xl.Debug("join connections closed, it remains [%s]ms [%s]", connection_duration, userConn.RemoteAddr().String() )
or
xl.Info("connections closed, it remains [%s]ms [%s]", connection_duration, userConn.RemoteAddr().String() )

The expect log output like this

2022/04/27 11:40:54 ^[[1;34m[I] [proxy.go:168] [a34239f390123d] [ssh_test] connections closed, it remains [303202]ms [8.8.8.8:39283]^[[0m
2022/04/27 11:40:54 ^[[1;34m[I] [proxy.go:168] [a34239f390123d] [rdp_test] connections closed, it remains [3123202]ms [8.8.8.8:39252]^[[0m

It may not be loged for http connections, if it can be Identified. To reduce log file size, I recommend outputting this connection_duration log as xl.Info.

Affected area

fatedier commented 2 years ago

I'm not inclined to this change. There are already timestamps in log info.

But adding connection addresses in join closed is ok.

berlin2123 commented 2 years ago

The timestamps now, are indistinguishable for muti-connections at the same time. such as:

2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/25 19:51:30 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m

or

2022/04/27 14:11:44 ^[[1;34m[D] [control.go:248] [24a14323423e8a0] get work connection from pool^[[0m
2022/04/27 14:11:44 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/27 14:11:44 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:273] [24a14323423e8a0] [ssh_test] join connections, workConn(l[192.168.1.123:60000] r[111.111.111.111:10000]) userConn(l[192.168.1.123:12345] r[222.222.222.222:55730])^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:273] [24a14323423e8a0] [ssh_test] join connections, workConn(l[192.168.1.123:60000] r[111.111.111.111:10000]) userConn(l[192.168.1.123:12345] r[222.222.222.222:55838])^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [control.go:219] [24a14323423e8a0] new work connection registered^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:283] [24a14323423e8a0] [ssh_test] join connections closed^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [control.go:219] [24a14323423e8a0] new work connection registered^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:162] [24a14323423e8a0] [ssh_test] get a user connection [222.222.222.222:55944]^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [control.go:248] [24a14323423e8a0] get work connection from pool^[[0m
2022/04/27 14:11:44 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:273] [24a14323423e8a0] [ssh_test] join connections, workConn(l[192.168.1.123:60000] r[111.111.111.111:10000]) userConn(l[192.168.1.123:12345] r[222.222.222.222:55944])^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:162] [24a14323423e8a0] [ssh_test] get a user connection [222.222.222.222:55928]^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [control.go:248] [24a14323423e8a0] get work connection from pool^[[0m
2022/04/27 14:11:44 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:273] [24a14323423e8a0] [ssh_test] join connections, workConn(l[192.168.1.123:60000] r[111.111.111.111:10000]) userConn(l[192.168.1.123:12345] r[222.222.222.222:55928])^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [control.go:219] [24a14323423e8a0] new work connection registered^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:162] [24a14323423e8a0] [ssh_test] get a user connection [222.222.222.222:55956]^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [control.go:248] [24a14323423e8a0] get work connection from pool^[[0m
2022/04/27 14:11:44 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:162] [24a14323423e8a0] [ssh_test] get a user connection [222.222.222.222:55872]^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [control.go:248] [24a14323423e8a0] get work connection from pool^[[0m
2022/04/27 14:11:44 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:273] [24a14323423e8a0] [ssh_test] join connections, workConn(l[192.168.1.123:60000] r[111.111.111.111:10000]) userConn(l[192.168.1.123:12345] r[222.222.222.222:55956])^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:273] [24a14323423e8a0] [ssh_test] join connections, workConn(l[192.168.1.123:60000] r[111.111.111.111:10000]) userConn(l[192.168.1.123:12345] r[222.222.222.222:55872])^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [control.go:219] [24a14323423e8a0] new work connection registered^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:283] [24a14323423e8a0] [ssh_test] join connections closed^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [control.go:219] [24a14323423e8a0] new work connection registered^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [control.go:219] [24a14323423e8a0] new work connection registered^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:283] [24a14323423e8a0] [ssh_test] join connections closed^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:283] [24a14323423e8a0] [ssh_test] join connections closed^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:283] [24a14323423e8a0] [ssh_test] join connections closed^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:162] [24a14323423e8a0] [ssh_test] get a user connection [222.222.222.222:55994]^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [control.go:248] [24a14323423e8a0] get work connection from pool^[[0m
2022/04/27 14:11:44 ^[[1;34m[I] [proxy.go:103] [24a14323423e8a0] [ssh_test] get a new work connection: [111.111.111.111:10000]^[[0m
2022/04/27 14:11:44 ^[[1;34m[D] [proxy.go:273] [24a14323423e8a0] [ssh_test] join connections, workConn(l[192.168.1.123:60000] r[111.111.111.111:10000]) userConn(l[192.168.1.123:12345] r[222.222.222.222:55994])^[[0m

All connection is at the same time. And there is no distinguishable ID for each connection. How could you Identify which one is the start and end time of each connecttion.

At the same time, if there has a distinguishable ID for each connection, it will still be hard (need to write another script file, instead of just a few lines in fail2ban conf) to read and analyze out the duration. However, it will be much easy to log it as a line in log file by the frps.

berlin2123 commented 2 years ago

The PR #2916 is added to achieve this Feature now.

github-actions[bot] commented 2 years ago

Issues go stale after 30d of inactivity. Stale issues rot after an additional 7d of inactivity and eventually close.