Я снова вернулся к любимой задаче для освоения новых языков. После написания движка для блога на Go, захотелось снова поразмять пальцы, болезный TCP/IP proxy/debugger теперь написан на Go.
Вкратце, TCP/IP proxy - это программа, которая умеет принимать соединения и “пробрасывать” их на указанный адрес. Попутно ведутся логи переданных данных. Это очень удобно при отладке различных самодельных сетевых протоколов.
В плане функциональности версия на Go, как и эрланговская, ведет три лога: двунаправленный шестнадцатеричный дамп и бинарные логи в обоих направлениях, “от” и “к” удаленному хосту. Питоновская версия бинарные логи не ведет.
Конечно, все многопоточно. И так как в Go параллельное программирование настолько просто (и безопасно), количество параллельных активностей для каждого соединения даже больше, чем в версии на Эрланге.
На Эрланге для каждого соединения работали следующие четыре потока:
В версии на Go немного иначе:
Итого, 5.
В обоих случаях потоки чтения логируют данные, посылая сообщения потокам-логгерам. Конечно, нет никаких глупостей типа мьютексов или условных переменных. Проблемы согласования элегантно решаются через каналы Go.
Ниже привожу исходник. Он отличается от того, что в репозитории, наличием обильных комментариев. Для людей, не очень знакомых с Go, могут быть интересны некоторые моменты.
package main import ( "flag" "fmt" "net" "os" "strings" "time" "encoding/hex" "runtime" ) var ( host *string = flag.String("host", "", "target host or address") port *string = flag.String("port", "0", "target port") listen_port *string = flag.String("listen_port", "0", "listen port") ) func die(format string, v ...interface{}) { os.Stderr.WriteString(fmt.Sprintf(format+"\n", v...)) os.Exit(1) } // Данная функция реализует поток для двунаправленного дампа. func connection_logger(data chan []byte, conn_n int, local_info, remote_info string) { log_name := fmt.Sprintf("log-%s-%04d-%s-%s.log", format_time(time.Now()), conn_n, local_info, remote_info) logger_loop(data, log_name) } // Данная функция реализует двоичный лог. func binary_logger(data chan []byte, conn_n int, peer string) { log_name := fmt.Sprintf("log-binary-%s-%04d-%s.log", format_time(time.Now()), conn_n, peer) logger_loop(data, log_name) } // Данная функция реализует поток логирования. Создает лог-файл и начинает // принимает сообщения. Каждое сообщение - это кусок данных для помещения // в лог. Если пришли пустые данные - выходим. // func logger_loop(data chan []byte, log_name string) { f, err := os.Create(log_name) if err != nil { die("Unable to create file %s, %v\n", log_name, err) } defer f.Close() // Гарантируем закрытие файла в случае падения. for { b := <-data if len(b) == 0 { break } f.Write(b) f.Sync() // На всякий случай flush'имся. } } func format_time(t time.Time) string { return t.Format("2006.01.02-15.04.05") } func printable_addr(a net.Addr) string { return strings.Replace(a.String(), ":", "-", -1) } // Структура, в которой передаются параметры соединения. Объединено, чтобы // не таскать много параметров. type Channel struct { from, to net.Conn logger, binary_logger chan []byte ack chan bool } // Функция, "качающая" данные из одного сокета и передающая их в другой. // Попутно ведется логирование. func pass_through(c *Channel) { from_peer := printable_addr(c.from.LocalAddr()) to_peer := printable_addr(c.to.LocalAddr()) b := make([]byte, 10240) offset := 0 packet_n := 0 for { n, err := c.from.Read(b) if err != nil { c.logger <- []byte(fmt.Sprintf("Disconnected from %s\n", from_peer)) break } if n > 0 { // Если что-то пришло, то логируем и пересылаем на выход. c.logger <- []byte(fmt.Sprintf("Received (#%d, %08X) %d bytes from %s\n", packet_n, offset, n, from_peer)) // Это все, что нужно для преобразования в hex-дамп. Удобно, не так ли? c.logger <- []byte(hex.Dump(b[:n])) c.binary_logger <- b[:n] c.to.Write(b[:n]) c.logger <- []byte(fmt.Sprintf("Sent (#%d) to %s\n", packet_n, to_peer)) offset += n packet_n += 1 } } c.from.Close() c.to.Close() c.ack <- true // Посылаем сообщение в главный поток, что мы закончили. } // Данная функция обслуживает соединение. Запускает необходимые потоки и ждет // их завершения. func process_connection(local net.Conn, conn_n int, target string) { // Соединяемся к удаленном сокету, куда будем пересылать данные. remote, err := net.Dial("tcp", target) if err != nil { fmt.Printf("Unable to connect to %s, %v\n", target, err) } local_info := printable_addr(remote.LocalAddr()) remote_info := printable_addr(remote.RemoteAddr()) // Засекаем начальное время. started := time.Now() // Создаем каналы для обмена с логгерами. logger := make(chan []byte) from_logger := make(chan []byte) to_logger := make(chan []byte) // Канал для получения подтверждений от качающих потоков. ack := make(chan bool) // Запускаем логгеры. go connection_logger(logger, conn_n, local_info, remote_info) go binary_logger(from_logger, conn_n, local_info) go binary_logger(to_logger, conn_n, remote_info) logger <- []byte(fmt.Sprintf("Connected to %s at %s\n", target, format_time(started))) // Запускаем качающие потоки. go pass_through(&Channel{remote, local, logger, to_logger, ack}) go pass_through(&Channel{local, remote, logger, from_logger, ack}) // Ждем подтверждения об их завершении. <-ack <-ack // Вычисляем длительность соединения. finished := time.Now() duration := finished.Sub(started) logger <- []byte(fmt.Sprintf("Finished at %s, duration %s\n", format_time(started), duration.String())) // Посылаем логгерам команды закругляться. Мы тут не ждем от них // подтверждения, так как они и так завершатся рано или поздно, а они нам // более не нужны. logger <- []byte{} from_logger <- []byte{} to_logger <- []byte{} } func main() { // Просим Go использовать все имеющиеся в системе процессоры. runtime.GOMAXPROCS(runtime.NumCPU()) // Разбираем командную строку (несложно, не правда ли?) flag.Parse() if flag.NFlag() != 3 { fmt.Printf("usage: gotcpspy -host target_host -port target_port -listen_post=local_port\n") flag.PrintDefaults() os.Exit(1) } target := net.JoinHostPort(*host, *port) fmt.Printf("Start listening on port %s and forwarding data to %s\n", *listen_port, target) ln, err := net.Listen("tcp", ":"+*listen_port) if err != nil { fmt.Printf("Unable to start listener, %v\n", err) os.Exit(1) } conn_n := 1 for { // Ждем новых соединений. if conn, err := ln.Accept(); err == nil { // Запускаем поток обработки соединения. go process_connection(conn, conn_n, target) conn_n += 1 } else { fmt.Printf("Accept failed, %v\n", err) } } }
Повторюсь, каждое соединения обслуживается пятью потоками. И сделал я это не ради прикола. Просто мне показалось, что логически есть явно независимые подзадачи, которые было бы логично запустить параллельно. Если б я писал все на C++/boost, я б скорее всего замутил все одном потоке для каждого соединения (а может быть и вся программа была бы чисто однопотоковой через какие-нибудь изощренные библиотеки мультиплексирования), и не исключено, что на C++ в итоге еще и работало бы быстрее, несмотря на один поток. Но я хочу сказать не об этом. Go подталкивает на многопоточное программирование (а не отталкивает, как C++, даже на стероидах нового стандарта). Так или иначе, будут задачи, где удобная многопоточность станет ключевым фактором.
Запустить можно так (требуется как минимум Go релиз 1):
go run gotcpspy.go -host pop.yandex.ru -port 110 -local_port 8080
Выведется:
Start listening on port 8080 and forwarding data to pop.yandex.ru:110
Затем, если в другом окне ввести:
telnet localhost 8080
и ввести, например, USER test <ENTER> и PASS none <ENTER>, то будут созданы три лога (дата в имени будет, конечно, другая).
Общий лог log-2012.04.20-19.55.17-0001-192.168.1.41-49544-213.180.204.37-110.log:
Connected to pop.yandex.ru:110 at 2012.04.20-19.55.17
Received (#0, 00000000) 38 bytes from 192.168.1.41-49544
00000000 2b 4f 4b 20 50 4f 50 20 59 61 21 20 76 31 2e 30 |+OK POP Ya! v1.0|
00000010 2e 30 6e 61 40 32 36 20 48 74 6a 4a 69 74 63 50 |.0na@26 HtjJitcP|
00000020 52 75 51 31 0d 0a |RuQ1..|
Sent (#0) to [--1]-8080
Received (#0, 00000000) 11 bytes from [--1]-8080
00000000 55 53 45 52 20 74 65 73 74 0d 0a |USER test..|
Sent (#0) to 192.168.1.41-49544
Received (#1, 00000026) 23 bytes from 192.168.1.41-49544
00000000 2b 4f 4b 20 70 61 73 73 77 6f 72 64 2c 20 70 6c |+OK password, pl|
00000010 65 61 73 65 2e 0d 0a |ease...|
Sent (#1) to [--1]-8080
Received (#1, 0000000B) 11 bytes from [--1]-8080
00000000 50 41 53 53 20 6e 6f 6e 65 0d 0a |PASS none..|
Sent (#1) to 192.168.1.41-49544
Received (#2, 0000003D) 72 bytes from 192.168.1.41-49544
00000000 2d 45 52 52 20 5b 41 55 54 48 5d 20 6c 6f 67 69 |-ERR [AUTH] logi|
00000010 6e 20 66 61 69 6c 75 72 65 20 6f 72 20 50 4f 50 |n failure or POP|
00000020 33 20 64 69 73 61 62 6c 65 64 2c 20 74 72 79 20 |3 disabled, try |
00000030 6c 61 74 65 72 2e 20 73 63 3d 48 74 6a 4a 69 74 |later. sc=HtjJit|
00000040 63 50 52 75 51 31 0d 0a |cPRuQ1..|
Sent (#2) to [--1]-8080
Disconnected from 192.168.1.41-49544
Disconnected from [--1]-8080
Finished at 2012.04.20-19.55.17, duration 5.253979s
Двоичный лог исходящих данных log-binary-2012.04.20-19.55.17-0001-192.168.1.41-49544.log:
USER test
PASS none
Двоичный лог входящих данных log-binary-2012.04.20-19.55.17-0001-213.180.204.37-110.log:
+OK POP Ya! v1.0.0na@26 HtjJitcPRuQ1
+OK password, please.
-ERR [AUTH] login failure or POP3 disabled, try later. sc=HtjJitcPRuQ1
Теперь измерим производительность. Прокачаем файл напрямую, а потом через эту программу.
Качаем напрямую (файл размером около 72MB):
time wget http://www.erlang.org/download/otp_src_R15B01.tar.gz
...
Saving to: `otp_src_R15B01.tar.gz'
...
real 1m2.819s
Теперь закачаем через программу, предварительно запустив ее:
go run gotcpspy.go -host=www.erlang.org -port=80 -listen_port=8080
Качаем:
time wget http://localhost:8080/download/otp_src_R15B01.tar.gz
...
Saving to: `otp_src_R15B01.tar.gz.1'
...
real 0m56.209s
На всякий случай, можно сравнить результаты:
diff otp_src_R15B01.tar.gz otp_src_R15B01.tar.gz.1
У меня файлы одинаковые, значит все работает верно.
Теперь время. Я повторял эксперимент несколько раз (на Mac Air), и, что удивительно, закачка через программу всегда была не то, чтобы медленнее, а даже немного быстрее. Например, напрямую – 1m2.819s, через программу – 0m56.209s. Единственное объяснение, что wget возможно работает в один поток, а программа принимает данные из локального и удаленного сокета в два потока, что может давать небольшое ускорение. Но, разница все равно минимальна, и возможно на другой машине или сети ее будет не видно, но главное, что работает как минимум не медленнее, чем напрямую, несмотря на создание в процессе передачи весьма массивных логов.
Итак, пока среди трех вариантов такой программы, на Питоне, Эрланге и Go, последняя мне нравится больше всего.
Как мне показалось, неплохой эксперимент с параллельностью в Go.
Кстати, если кто-то из джавистов замутил бы схожую программу (если можно, не требующую для сборки Eclipse/IDEA/ant/maven/spring/log4j/ivy и прочее), было бы очень интересно сравнить. И не в плане эффективности и скорости, а в плане красоты, изящности.