I'm writing a microservice for validating SSL certificates for URLs, basically combining together these two things:
- An implementation of an SSL checker from here: https://github.com/alanorth/check-tls-certs/blob/master/main.go
- And this approach for spawning workers from an API call: https://medium.com/smsjunk/handling-1-million-requests-per-minute-with-golang-f70ac505fcaa
So, practically I'm launching the small service, which accepts a list of URLs and validates SSL certificates for them. The problem is, after some requests the SSL checker starts freezing for quite a long time, and I don't know why (each payload in this log is the same set of 5000 URLs every time):
DEBUG: 2018/09/29 14:33:58 dispatcher.go:34: DNS timeout set to 10 seconds
DEBUG: 2018/09/29 14:33:58 dispatcher.go:35: SSL timeout set to 10 seconds
DEBUG: 2018/09/29 14:33:58 dispatcher.go:36: HTTP timeout set to 10 seconds
DEBUG: 2018/09/29 14:33:58 dispatcher.go:37: Starting 10000 workers...
DEBUG: 2018/09/29 14:33:58 api.go:113: Starting API at :8888...
DEBUG: 2018/09/29 14:34:04 api.go:50: Received request, starting task '0af84d1e-52b3-41bc-935c-a5a22a007a2c'...
DEBUG: 2018/09/29 14:34:08 api.go:50: Received request, starting task 'e2379281-f98d-4185-8776-46c032bf6bf9'...
DEBUG: 2018/09/29 14:34:11 api.go:50: Received request, starting task 'faeb6b1d-8567-427f-81b7-63cdc2154314'...
DEBUG: 2018/09/29 14:34:15 api.go:50: Received request, starting task '702ca7b2-4b23-434c-9921-e72532766b16'...
DEBUG: 2018/09/29 14:34:15 dispatcher.go:59: Finished processing URLs for task '0af84d1e-52b3-41bc-935c-a5a22a007a2c' (took 11 seconds)!
DEBUG: 2018/09/29 14:34:20 dispatcher.go:59: Finished processing URLs for task 'e2379281-f98d-4185-8776-46c032bf6bf9' (took 12 seconds)!
DEBUG: 2018/09/29 14:34:22 api.go:50: Received request, starting task 'aa2a6bd6-f207-41a4-9dd4-a48ad72b85de'...
DEBUG: 2018/09/29 14:34:29 dispatcher.go:59: Finished processing URLs for task '702ca7b2-4b23-434c-9921-e72532766b16' (took 14 seconds)!
DEBUG: 2018/09/29 14:34:33 dispatcher.go:59: Finished processing URLs for task 'aa2a6bd6-f207-41a4-9dd4-a48ad72b85de' (took 11 seconds)!
DEBUG: 2018/09/29 14:34:55 api.go:50: Received request, starting task 'ea8c7c69-c533-4c9e-a4e4-439b41df2f52'...
DEBUG: 2018/09/29 14:34:59 api.go:50: Received request, starting task '6f2a2374-6911-4ff4-bbe2-b3aa378a2938'...
DEBUG: 2018/09/29 14:35:01 api.go:50: Received request, starting task '73cae838-9971-403f-bdfd-6e4790624fe8'...
DEBUG: 2018/09/29 14:35:04 api.go:50: Received request, starting task 'ee04997d-efd2-47df-9359-b46c90859224'...
DEBUG: 2018/09/29 14:35:06 dispatcher.go:59: Finished processing URLs for task 'ea8c7c69-c533-4c9e-a4e4-439b41df2f52' (took 11 seconds)!
DEBUG: 2018/09/29 14:35:07 api.go:50: Received request, starting task '5918b20d-ab52-484a-888e-2651344e8c5e'...
DEBUG: 2018/09/29 14:35:09 dispatcher.go:59: Finished processing URLs for task '6f2a2374-6911-4ff4-bbe2-b3aa378a2938' (took 10 seconds)!
DEBUG: 2018/09/29 14:35:19 dispatcher.go:59: Finished processing URLs for task 'ee04997d-efd2-47df-9359-b46c90859224' (took 15 seconds)!
DEBUG: 2018/09/29 14:35:20 dispatcher.go:59: Finished processing URLs for task '5918b20d-ab52-484a-888e-2651344e8c5e' (took 13 seconds)!
DEBUG: 2018/09/29 14:50:06 dispatcher.go:59: Finished processing URLs for task 'faeb6b1d-8567-427f-81b7-63cdc2154314' (took 955 seconds)!
DEBUG: 2018/09/29 14:50:57 dispatcher.go:59: Finished processing URLs for task '73cae838-9971-403f-bdfd-6e4790624fe8' (took 956 seconds)!
I have a timeout set to time.Second * 10 which I'm passing to net.DialTimeout(), but it doesn't save the day. That means, instead of this line: https://github.com/alanorth/check-tls-certs/blob/master/main.go#L232 I have something like this:
ipConn,err := net.DialTimeout("tcp", result.Domain + ":443", time.Second * 10)
if err != nil {
result.Errors["ssl"] = append(result.Errors["ssl"], err.Error())
if s.FailIfInvalid {
result.Success = false
}
return
}
tc := &tls.Config{ServerName: result.Domain}
if s.CheckInsecure {
tc.InsecureSkipVerify = true
}
conn:= tls.Client(ipConn, tc)
err = conn.Handshake()
if err != nil {
switch e := err.(type) {
case x509.CertificateInvalidError:
result.Errors["ssl"] = append(result.Errors["ssl"], e.Error())
if s.FailIfInvalid {
result.Success = false
}
return
}
defer conn.Close()
Also, strace on running thread says it hangs on epoll_pwait() syscall, and pprof gives me nothing, because the application itself is peacefully waiting in userspace during this time.
What should I do next to properly fix the issue? It doesn't seem to have anything to do with opened file descriptors or anything (the numbers are reasonable), also memory/CPU consumption is pretty low. Would really appreciate any help. Thanks!
