$ ./shogi-board-server -app_config ./app.config.yml (base)
____ __
/ __/___/ / ___
/ _// __/ _ \/ _ \
/___/\__/_//_/\___/ v4.1.15
High performance, minimalist Go web framework
https://echo.labstack.com
____________________________________O/_______
O\
⇨ http server started on [::]:8080
{"level":"info","time":"2020-03-21T21:33:49.331+0900","caller":"controllers/init.go:33","msg":"[Init]","names":["kristallweizen"]}
{"time":"2020-03-21T21:33:49.331899+09:00","id":"","remote_ip":"::1","host":"localhost:8080","method":"POST","uri":"/init","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.149 Safari/537.36","status":200,"error":"","latency":505993,"latency_human":"505.993µs","bytes_in":0,"bytes_out":19}
{"level":"info","time":"2020-03-21T21:33:51.309+0900","caller":"controllers/connect.go:28","msg":"[Connect] param check","name":"kristallweizen","path":"/Users/paalon/shogi/yaneuraou-kristallweizen/YaneuraOu-by-gcc"}
{"level":"info","time":"2020-03-21T21:33:51.314+0900","caller":"engine/engine.go:90","msg":"[engine.New]","exec":"usi"}
{"level":"info","time":"2020-03-21T21:33:51.314+0900","caller":"engine/engine.go:95","msg":"[engine.New]","wait":"usiok"}
{"level":"info","time":"2020-03-21T21:33:51.314+0900","caller":"engine/engine.go:163","msg":"[waitFor]","exitWord":"usiok"}
{"level":"info","time":"2020-03-21T21:33:51.314+0900","caller":"engine/engine.go:146","msg":"[catch]","start catching":""}
{"level":"error","time":"2020-03-21T21:34:01.318+0900","caller":"engine/engine.go:253","msg":"[waitFor] timed out","error":"Execution timed out","errorVerbose":"Execution timed out\ngithub.com/murosan/shogi-board-server/app/domain/model/exception.init\n\t/Users/paalon/go/src/github.com/murosan/shogi-board-server/app/domain/model/exception/errors.go:13\nruntime.doInit\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/proc.go:5414\nruntime.doInit\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/proc.go:5409\nruntime.doInit\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/proc.go:5409\nruntime.doInit\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/proc.go:5409\nruntime.main\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/proc.go:190\nruntime.goexit\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/asm_amd64.s:1373","stacktrace":"github.com/murosan/shogi-board-server/app/domain/entity/engine.(*Engine).waitFor\n\t/Users/paalon/go/src/github.com/murosan/shogi-board-server/app/domain/entity/engine/engine.go:253\ngithub.com/murosan/shogi-board-server/app/domain/entity/engine.New\n\t/Users/paalon/go/src/github.com/murosan/shogi-board-server/app/domain/entity/engine/engine.go:96\ngithub.com/murosan/shogi-board-server/app/server/controllers.Connect.func1\n\t/Users/paalon/go/src/github.com/murosan/shogi-board-server/app/server/controllers/connect.go:53\ngithub.com/labstack/echo.(*Echo).add.func1\n\t/Users/paalon/go/src/github.com/labstack/echo/echo.go:512\ngithub.com/labstack/echo/middleware.CORSWithConfig.func1.1\n\t/Users/paalon/go/src/github.com/labstack/echo/middleware/cors.go:121\ngithub.com/labstack/echo/middleware.RecoverWithConfig.func1.1\n\t/Users/paalon/go/src/github.com/labstack/echo/middleware/recover.go:78\ngithub.com/labstack/echo/middleware.LoggerWithConfig.func2.1\n\t/Users/paalon/go/src/github.com/labstack/echo/middleware/logger.go:117\ngithub.com/labstack/echo.(*Echo).ServeHTTP\n\t/Users/paalon/go/src/github.com/labstack/echo/echo.go:623\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/Cellar/go/1.14/libexec/src/net/http/server.go:2807\nnet/http.(*conn).serve\n\t/usr/local/Cellar/go/1.14/libexec/src/net/http/server.go:1895"}
{"level":"error","time":"2020-03-21T21:34:01.319+0900","caller":"controllers/connect.go:56","msg":"[Connect] initialize Engine","error":"could not get 'usiok' from the engine: Execution timed out","errorVerbose":"Execution timed out\ngithub.com/murosan/shogi-board-server/app/domain/model/exception.init\n\t/Users/paalon/go/src/github.com/murosan/shogi-board-server/app/domain/model/exception/errors.go:13\nruntime.doInit\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/proc.go:5414\nruntime.doInit\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/proc.go:5409\nruntime.doInit\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/proc.go:5409\nruntime.doInit\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/proc.go:5409\nruntime.main\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/proc.go:190\nruntime.goexit\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/asm_amd64.s:1373\ncould not get 'usiok' from the engine\ngithub.com/murosan/shogi-board-server/app/domain/entity/engine.New\n\t/Users/paalon/go/src/github.com/murosan/shogi-board-server/app/domain/entity/engine/engine.go:97\ngithub.com/murosan/shogi-board-server/app/server/controllers.Connect.func1\n\t/Users/paalon/go/src/github.com/murosan/shogi-board-server/app/server/controllers/connect.go:53\ngithub.com/labstack/echo.(*Echo).add.func1\n\t/Users/paalon/go/src/github.com/labstack/echo/echo.go:512\ngithub.com/labstack/echo/middleware.CORSWithConfig.func1.1\n\t/Users/paalon/go/src/github.com/labstack/echo/middleware/cors.go:121\ngithub.com/labstack/echo/middleware.RecoverWithConfig.func1.1\n\t/Users/paalon/go/src/github.com/labstack/echo/middleware/recover.go:78\ngithub.com/labstack/echo/middleware.LoggerWithConfig.func2.1\n\t/Users/paalon/go/src/github.com/labstack/echo/middleware/logger.go:117\ngithub.com/labstack/echo.(*Echo).ServeHTTP\n\t/Users/paalon/go/src/github.com/labstack/echo/echo.go:623\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/Cellar/go/1.14/libexec/src/net/http/server.go:2807\nnet/http.(*conn).serve\n\t/usr/local/Cellar/go/1.14/libexec/src/net/http/server.go:1895\nruntime.goexit\n\t/usr/local/Cellar/go/1.14/libexec/src/runtime/asm_amd64.s:1373","stacktrace":"github.com/murosan/shogi-board-server/app/server/controllers.Connect.func1\n\t/Users/paalon/go/src/github.com/murosan/shogi-board-server/app/server/controllers/connect.go:56\ngithub.com/labstack/echo.(*Echo).add.func1\n\t/Users/paalon/go/src/github.com/labstack/echo/echo.go:512\ngithub.com/labstack/echo/middleware.CORSWithConfig.func1.1\n\t/Users/paalon/go/src/github.com/labstack/echo/middleware/cors.go:121\ngithub.com/labstack/echo/middleware.RecoverWithConfig.func1.1\n\t/Users/paalon/go/src/github.com/labstack/echo/middleware/recover.go:78\ngithub.com/labstack/echo/middleware.LoggerWithConfig.func2.1\n\t/Users/paalon/go/src/github.com/labstack/echo/middleware/logger.go:117\ngithub.com/labstack/echo.(*Echo).ServeHTTP\n\t/Users/paalon/go/src/github.com/labstack/echo/echo.go:623\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/Cellar/go/1.14/libexec/src/net/http/server.go:2807\nnet/http.(*conn).serve\n\t/usr/local/Cellar/go/1.14/libexec/src/net/http/server.go:1895"}
{"time":"2020-03-21T21:34:01.324128+09:00","id":"","remote_ip":"::1","host":"localhost:8080","method":"POST","uri":"/connect?key=kristallweizen","user_agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/80.0.3987.149 Safari/537.36","status":500,"error":"","latency":10014686750,"latency_human":"10.01468675s","bytes_in":0,"bytes_out":0}