The second part of exercise 2 in Chapter 1 Basics of Software Engineering for Internet Applications.
Go won't let you write a divide-by-zero.
When I tried
y := 1/0,
it would not compile:
./reqproc.go:121:9: division by zero
So, I used panic:
fmt.Println("About to panic ...") panic("Hello Crash")
The start command is:
./hacs 2>&,1 | multilog /var/log/hacs s1048576 n50 &
so I expected each line of the log output would have a timestamp on it, as that is one feature of multilog.
In this case, neither the line before the panic nor the panic message itself has timestamps.
About to panic ... 2021/04/18 00:28:55 http: panic serving 127.0.0.1:59178: Hello Crash goroutine 7 [running]: net/http.(*conn).serve.func1(0xc4200a2dc0) /usr/local/go/src/net/http/server.go:1726 +0xd0 panic(0x13025e0, 0x13c5620) /usr/local/go/src/runtime/panic.go:502 +0x229 main.(*ReqProc).ServeHTTP(0xc420010be0, 0x13ca120, 0xc42013c0e0, 0xc42013a100) /Users/mark/src/mycode/gardening/hacs/reqproc.go:122 +0x332 net/http.(*ServeMux).ServeHTTP(0x15738c0, 0x13ca120, 0xc42013c0e0, 0xc42013a100) /usr/local/go/src/net/http/server.go:2340 +0x130 net/http.serverHandler.ServeHTTP(0xc4200972b0, 0x13ca120, 0xc42013c0e0, 0xc42013a100) /usr/local/go/src/net/http/server.go:2697 +0xbc net/http.(*conn).serve(0xc4200a2dc0, 0x13ca3e0, 0xc420020500) /usr/local/go/src/net/http/server.go:1830 +0x651 created by net/http.(*Server).Serve /usr/local/go/src/net/http/server.go:2798 +0x27b
Note that the nginx proxy log output was a 502, not a 500.
garden:~$ grep crashme /var/log/nginx/access.log 18.104.22.168 - - [18/Apr/2021:07:36:47 -0400] "GET /basics/my-first-program.crashme HTTP/1.1" 502 150 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/14.0.3 Safari/605.1.15" "-" garden:~$ grep crashme /var/log/nginx/error.log 2021/04/18 07:36:47 [error] 16814#16814: *15124 upstream prematurely closed connection while reading response header from upstream, client: 22.214.171.124, server: garden.markbucciarelli.com, request: "GET /basics/my-first-program.crashme HTTP/1.1", upstream: "http://127.0.0.1:8100/basics/my-first-program.crashme", host: "garden.markbucciarelli.com"
I was wrong about multilog. D.J. Bernsten's daemontools has another utility tai64n that does the timestamping.
I want any panic to be stamped with the current time, so I'll update the start script to be:
./hacs 2>&1 | tai64n | ./hacs 2>&1 | multilog /var/log/hacs s1048576 n50 &
change all my log statements in the golang code
and add a helper script to convert the TAI64N timestamps to local time.
garden:~$ cat seelog.sh #! /bin/sh -e # Convert TAI64N labels in log to local time. # April 18, 2021 tai64nlocal < /var/log/hacs/current garden:~$
-- Mark Bucciarelli, April 18, 2021