search

oduwsdl / MemGator

A Memento Aggregator CLI and Server in Go
https://memgator.cs.odu.edu/api.html
MIT License
56 stars 11 forks source link

MemGator crashes after an hour with moderate usage #137

Open machawk1 opened 3 years ago

machawk1 commented 3 years ago

I am encountering an issue with my MemGator instance at https://aggregator.matkelly.com that has recently had an uptick in traffic with its deferral in Mink since the ODUCS MemGator instance has been down. I have not been able to isolate the problem but thought I might report it here.

I am running MemGator 1.0-rc8 on Debian 10 in a screen session with memgator -l /logs/memgator.log -b /logs/memgator.bm --contact=me@matkelly.com --spoof -t 10s -T 2m30s -r 3m0s -c "@machawk1" --proxy=https://aggregator.matkelly.com server

There does not appear to be any indication of a failure in the .log or .bm file but I can provide those if they would be helpful. Otherwise, the partial trace is below.

Caddy is being used as a reverse proxy.

...
bufio.(*Reader).ReadSlice(0xc0008f15c0, 0xc00038790a, 0x43c4df, 0xc0003879c0, 0x40bd06, 0xc00364ae00, 0x100)
        /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:359 +0x3d
bufio.(*Reader).ReadLine(0xc0008f15c0, 0xc0003879c8, 0xc000032700, 0x7f3b78e18108, 0x0, 0x0, 0xc0005cf000)
        /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:388 +0x34
net/textproto.(*Reader).readLineSlice(0xc00097a030, 0xc00364ae00, 0x0, 0x4350ac, 0xc000387a28, 0x0)
        /opt/hostedtoolcache/go/1.14/x64/src/net/textproto/reader.go:58 +0x6c
net/textproto.(*Reader).ReadLine(...)
        /opt/hostedtoolcache/go/1.14/x64/src/net/textproto/reader.go:39
net/http.readRequest(0xc0008f15c0, 0x0, 0xc00364ae00, 0x0, 0x0)
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/request.go:1015 +0xa4
net/http.(*conn).readRequest(0xc0002ca0a0, 0x7e3dc0, 0xc0020880c0, 0x0, 0x0, 0x0)
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:966 +0x191
net/http.(*conn).serve(0xc0002ca0a0, 0x7e3dc0, 0xc0020880c0)
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:1822 +0x6d4
created by net/http.(*Server).Serve
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:2933 +0x35c

goroutine 4137 [select, 2 minutes]:
net/http.(*persistConn).writeLoop(0xc0004447e0)
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:2277 +0x11c
created by net/http.(*Transport).dialConn
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1648 +0xc7b

goroutine 823 [IO wait]:
internal/poll.runtime_pollWait(0x7f3b5219f3c8, 0x72, 0xffffffffffffffff)
        /opt/hostedtoolcache/go/1.14/x64/src/runtime/netpoll.go:203 +0x55
internal/poll.(*pollDesc).wait(0xc00048ff98, 0x72, 0x1000, 0x1000, 0xffffffffffffffff)
        /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
        /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc00048ff80, 0xc0001c7000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
        /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_unix.go:169 +0x19b
net.(*netFD).Read(0xc00048ff80, 0xc0001c7000, 0x1000, 0x1000, 0xc000176900, 0xc0000ccda8, 0xc0000ccc38)
        /opt/hostedtoolcache/go/1.14/x64/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc00000e3f8, 0xc0001c7000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
        /opt/hostedtoolcache/go/1.14/x64/src/net/net.go:184 +0x8e
net/http.(*persistConn).Read(0xc000011680, 0xc0001c7000, 0x1000, 0x1000, 0xc0000cceb0, 0x45edc0, 0xc0000cceb0)
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1825 +0x75
bufio.(*Reader).fill(0xc00018b4a0)
        /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:100 +0x103
bufio.(*Reader).Peek(0xc00018b4a0, 0x1, 0x2, 0x0, 0x0, 0xc00005c100, 0x0)
        /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:138 +0x4f
net/http.(*persistConn).readLoop(0xc000011680)
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1978 +0x1a8
created by net/http.(*Transport).dialConn
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1647 +0xc56

goroutine 3961 [select, 2 minutes]:
net/http.(*persistConn).readLoop(0xc000011200)
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:2099 +0x99e
created by net/http.(*Transport).dialConn
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1647 +0xc56

goroutine 3962 [select, 2 minutes]:
net/http.(*persistConn).writeLoop(0xc000011200)
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:2277 +0x11c
created by net/http.(*Transport).dialConn
        /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1648 +0xc7b
ibnesayeed commented 3 years ago

Could the duplicate flags --contact and -c be the source of issue?

machawk1 commented 3 years ago

@ibnesayeed I had not noticed the duplicate flag. I will change it and get back to you. Here is a more complete dump after a subsequent crash last night that indicates that the application ran out of memory.

$ fatal error: runtime: out of memory

runtime stack:
runtime.throw(0x76d76d, 0x16)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/panic.go:1112 +0x72
runtime.sysMap(0xc024000000, 0x10000000, 0xa23c98)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/mem_linux.go:169 +0xc5
runtime.(*mheap).sysAlloc(0xa0f780, 0x10000000, 0xa0f788, 0x8000)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/malloc.go:715 +0x1cd
runtime.(*mheap).grow(0xa0f780, 0x8000, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/mheap.go:1286 +0x11c
runtime.(*mheap).allocSpan(0xa0f780, 0x8000, 0x31910100, 0xa23ca8, 0x100000001)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/mheap.go:1124 +0x6a0
runtime.(*mheap).alloc.func1()
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/mheap.go:871 +0x64
runtime.(*mheap).alloc(0xa0f780, 0x8000, 0xc001840101, 0xc000001080)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/mheap.go:865 +0x81
runtime.largeAlloc(0xffffe00, 0xc000030101, 0x43be27)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/malloc.go:1152 +0x92
runtime.mallocgc.func1()
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/malloc.go:1047 +0x46
runtime.systemstack(0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/asm_amd64.s:370 +0x66
runtime.mstart()
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/proc.go:1041

goroutine 26664 [running]:
runtime.systemstack_switch()
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/asm_amd64.s:330 fp=0xc000349bc0 sp=0xc000349bb8 pc=0x45f6f0
runtime.mallocgc(0xffffe00, 0x6f58e0, 0x1, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/malloc.go:1046 +0x895 fp=0xc000349c60 sp=0xc000349bc0 pc=0x40c285
runtime.makeslice(0x6f58e0, 0xffffe00, 0xffffe00, 0x62755c)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/slice.go:49 +0x6c fp=0xc000349c90 sp=0xc000349c60 pc=0x448c1c
bytes.makeSlice(0xffffe00, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/bytes/buffer.go:229 +0x73 fp=0xc000349cd0 sp=0xc000349c90 pc=0x4d01f3
bytes.(*Buffer).grow(0xc000349dc8, 0x200, 0xdd00c3)
    /opt/hostedtoolcache/go/1.14/x64/src/bytes/buffer.go:142 +0x15b fp=0xc000349d20 sp=0xc000349cd0 pc=0x4cfbcb
bytes.(*Buffer).ReadFrom(0xc000349dc8, 0x7ff8995281b0, 0xc0002f0a60, 0x7ff8995281b0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/bytes/buffer.go:202 +0x48 fp=0xc000349d90 sp=0xc000349d20 pc=0x4cffe8
io/ioutil.readAll(0x7ff8995281b0, 0xc0002f0a60, 0x200, 0x0, 0x0, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/io/ioutil/ioutil.go:36 +0xe3 fp=0xc000349e10 sp=0xc000349d90 pc=0x4e9da3
io/ioutil.ReadAll(...)
    /opt/hostedtoolcache/go/1.14/x64/src/io/ioutil/ioutil.go:45
main.fetchTimemap(0xc0002807c0, 0x18, 0xc00006c9c0, 0xc0000494a0, 0xc000272d80, 0x0, 0xc0001e1a00)
    /home/runner/work/MemGator/MemGator/main.go:315 +0x980 fp=0xc000349fa8 sp=0xc000349e10 pc=0x6bb7c0
runtime.goexit()
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/asm_amd64.s:1373 +0x1 fp=0xc000349fb0 sp=0xc000349fa8 pc=0x461681
created by main.aggregateTimemap
    /home/runner/work/MemGator/MemGator/main.go:433 +0x75d

goroutine 1 [IO wait, 4 minutes]:
internal/poll.runtime_pollWait(0x7ff8995110c8, 0x72, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/netpoll.go:203 +0x55
internal/poll.(*pollDesc).wait(0xc0000aea98, 0x72, 0x0, 0x0, 0x768383)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc0000aea80, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_unix.go:384 +0x1d4
net.(*netFD).accept(0xc0000aea80, 0x2, 0x0, 0x844f217677c4db2)
    /opt/hostedtoolcache/go/1.14/x64/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc0002f9ea0, 0x60e3a4fe, 0xc00003fbc0, 0x4adf46)
    /opt/hostedtoolcache/go/1.14/x64/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc0002f9ea0, 0xc00003fc10, 0x18, 0xc000000300, 0x66cebc)
    /opt/hostedtoolcache/go/1.14/x64/src/net/tcpsock.go:261 +0x64
net/http.(*Server).Serve(0xc0003f4620, 0x7e33c0, 0xc0002f9ea0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:2901 +0x25d
net/http.(*Server).ListenAndServe(0xc0003f4620, 0xc0003f4620, 0xc00003fea8)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:2830 +0xb7
net/http.ListenAndServe(...)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:3086
main.main()
    /home/runner/work/MemGator/MemGator/main.go:943 +0xb1f

goroutine 26655 [IO wait, 2 minutes]:
internal/poll.runtime_pollWait(0x7ff899510728, 0x72, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/netpoll.go:203 +0x55
internal/poll.(*pollDesc).wait(0xc000b67418, 0x72, 0x0, 0x1, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000b67400, 0xc000aa7de1, 0x1, 0x1, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_unix.go:169 +0x19b
net.(*netFD).Read(0xc000b67400, 0xc000aa7de1, 0x1, 0x1, 0xc0012b3198, 0x100000001, 0xc000db0f38)
    /opt/hostedtoolcache/go/1.14/x64/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc00000ec80, 0xc000aa7de1, 0x1, 0x1, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/net.go:184 +0x8e
net/http.(*connReader).backgroundRead(0xc000aa7dd0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:678 +0x58
created by net/http.(*connReader).startBackgroundRead
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:674 +0xd0

goroutine 27064 [select, 1 minutes]:
net/http.(*persistConn).writeLoop(0xc000c097a0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:2277 +0x11c
created by net/http.(*Transport).dialConn
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1648 +0xc7b

goroutine 27080 [chan send, 1 minutes]:
main.serializeLinks(0xc0001754c0, 0x1b, 0xc002518e10, 0xc00094c14d, 0x4, 0xc0060c6f00, 0x9f7500, 0xc0002ce360)
    /home/runner/work/MemGator/MemGator/main.go:382 +0x1016
created by main.memgatorService
    /home/runner/work/MemGator/MemGator/main.go:633 +0x5d7

goroutine 24231 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x7ff89952a160, 0x72, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/netpoll.go:203 +0x55
internal/poll.(*pollDesc).wait(0xc001348318, 0x72, 0x1000, 0x1000, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc001348300, 0xc000067000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_unix.go:169 +0x19b
net.(*netFD).Read(0xc001348300, 0xc000067000, 0x1000, 0x1000, 0xc001b1f3e0, 0xc00019cda8, 0xc00019cc38)
    /opt/hostedtoolcache/go/1.14/x64/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc00000e430, 0xc000067000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/net.go:184 +0x8e
net/http.(*persistConn).Read(0xc0004db560, 0xc000067000, 0x1000, 0x1000, 0xc00019ceb0, 0x45edc0, 0xc00019ceb0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1825 +0x75
bufio.(*Reader).fill(0xc0001a8c00)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:100 +0x103
bufio.(*Reader).Peek(0xc0001a8c00, 0x1, 0x2, 0x0, 0x0, 0xc001a30b00, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:138 +0x4f
net/http.(*persistConn).readLoop(0xc0004db560)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1978 +0x1a8
created by net/http.(*Transport).dialConn
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1647 +0xc56

goroutine 25141 [select, 2 minutes]:
net/http.(*persistConn).writeLoop(0xc001844c60)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:2277 +0x11c
created by net/http.(*Transport).dialConn
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1648 +0xc7b

goroutine 24232 [select, 1 minutes]:
net/http.(*persistConn).writeLoop(0xc0004db560)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:2277 +0x11c
created by net/http.(*Transport).dialConn
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1648 +0xc7b

goroutine 25518 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x7ff89952abe0, 0x77, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/netpoll.go:203 +0x55
internal/poll.(*pollDesc).wait(0xc000d81f98, 0x77, 0x1000, 0x1000, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitWrite(...)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:96
internal/poll.(*FD).Write(0xc000d81f80, 0xc0019a3000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_unix.go:276 +0x290
net.(*netFD).Write(0xc000d81f80, 0xc0019a3000, 0x1000, 0x1000, 0xc001b53418, 0x4c6ff2, 0xc0000a8103)
    /opt/hostedtoolcache/go/1.14/x64/src/net/fd_unix.go:220 +0x4f
net.(*conn).Write(0xc00000f030, 0xc0019a3000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/net.go:196 +0x8e
net/http.checkConnErrorWriter.Write(0xc001923860, 0xc0019a3000, 0x1000, 0x1000, 0xc001b53418, 0x4bed81, 0x9ebae0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:3434 +0x56
bufio.(*Writer).Flush(0xc0007226c0, 0xc0019a4000, 0x732)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:591 +0x75
bufio.(*Writer).Write(0xc0007226c0, 0xc0019a4000, 0x800, 0x800, 0xc001b534f8, 0x1, 0x1)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:627 +0xfa
net/http.(*chunkWriter).Write(0xc0002e6738, 0xc0019a4000, 0x800, 0x800, 0x800, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:383 +0x94
bufio.(*Writer).Flush(0xc000722780, 0xc000392000, 0x22)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:591 +0x75
bufio.(*Writer).Write(0xc000722780, 0xc000392000, 0x93, 0x180, 0x2, 0x0, 0xc001b536a0)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:627 +0xfa
net/http.(*response).write(0xc0002e6700, 0x93, 0xc000392000, 0x93, 0x180, 0x0, 0x0, 0xc001b538f8, 0x6f5720, 0xc006cec1c0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:1578 +0x2d5
net/http.(*response).Write(0xc0002e6700, 0xc000392000, 0x93, 0x180, 0x2, 0xc001b53790, 0x409ce5)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:1547 +0x56
fmt.Fprint(0x7de620, 0xc0002e6700, 0xc001b538f8, 0x1, 0x1, 0x2, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/fmt/print.go:233 +0x8b
main.memgatorService(0x7e3640, 0xc0002e6700, 0xc001a52100, 0xc0001754c0, 0x1b, 0xc00094c14d, 0x4, 0x0)
    /home/runner/work/MemGator/MemGator/main.go:639 +0x6e9
main.router(0x7e3640, 0xc0002e6700, 0xc001a52100)
    /home/runner/work/MemGator/MemGator/main.go:740 +0x404
net/http.HandlerFunc.ServeHTTP(0x7828c8, 0x7e3640, 0xc0002e6700, 0xc001a52100)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:2012 +0x44
net/http.serverHandler.ServeHTTP(0xc0003f4620, 0x7e3640, 0xc0002e6700, 0xc001a52100)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:2807 +0xa3
net/http.(*conn).serve(0xc001923860, 0x7e3dc0, 0xc000722680)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:1895 +0x86c
created by net/http.(*Server).Serve
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:2933 +0x35c

goroutine 27035 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x7ff899523ac8, 0x72, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/netpoll.go:203 +0x55
internal/poll.(*pollDesc).wait(0xc000b67798, 0x72, 0xd00, 0xd09, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000b67780, 0xc000415b00, 0xd09, 0xd09, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_unix.go:169 +0x19b
net.(*netFD).Read(0xc000b67780, 0xc000415b00, 0xd09, 0xd09, 0x203000, 0x4ee17b, 0xc000390251)
    /opt/hostedtoolcache/go/1.14/x64/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc00000e388, 0xc000415b00, 0xd09, 0xd09, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/net.go:184 +0x8e
crypto/tls.(*atLeastReader).Read(0xc000291800, 0xc000415b00, 0xd09, 0xd09, 0x0, 0x41255b, 0xc000932918)
    /opt/hostedtoolcache/go/1.14/x64/src/crypto/tls/conn.go:760 +0x60
bytes.(*Buffer).ReadFrom(0xc000297058, 0x7de0c0, 0xc000291800, 0x409ce5, 0x711ee0, 0x754ee0)
    /opt/hostedtoolcache/go/1.14/x64/src/bytes/buffer.go:204 +0xb1
crypto/tls.(*Conn).readFromUntil(0xc000296e00, 0x7de340, 0xc00000e388, 0x5, 0xc00000e388, 0xc000400800)
    /opt/hostedtoolcache/go/1.14/x64/src/crypto/tls/conn.go:782 +0xec
crypto/tls.(*Conn).readRecordOrCCS(0xc000296e00, 0x0, 0x0, 0xc00000e0b0)
    /opt/hostedtoolcache/go/1.14/x64/src/crypto/tls/conn.go:589 +0x115
crypto/tls.(*Conn).readRecord(...)
    /opt/hostedtoolcache/go/1.14/x64/src/crypto/tls/conn.go:557
crypto/tls.(*Conn).Read(0xc000296e00, 0xc000390000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/crypto/tls/conn.go:1233 +0x15b
net/http.(*persistConn).Read(0xc000c086c0, 0xc000390000, 0x1000, 0x1000, 0xc0018437a0, 0xc000932c70, 0x404da5)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1825 +0x75
bufio.(*Reader).fill(0xc000bd3200)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:100 +0x103
bufio.(*Reader).Peek(0xc000bd3200, 0x1, 0x0, 0x0, 0x1, 0xc001843600, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:138 +0x4f
net/http.(*persistConn).readLoop(0xc000c086c0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1978 +0x1a8
created by net/http.(*Transport).dialConn
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1647 +0xc56

goroutine 27063 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x7ff898fbfd98, 0x72, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/netpoll.go:203 +0x55
internal/poll.(*pollDesc).wait(0xc000b66d18, 0x72, 0x7b00, 0x7bd5, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000b66d00, 0xc0009ae000, 0x7bd5, 0x7bd5, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_unix.go:169 +0x19b
net.(*netFD).Read(0xc000b66d00, 0xc0009ae000, 0x7bd5, 0x7bd5, 0x203000, 0x8, 0x40bd06)
    /opt/hostedtoolcache/go/1.14/x64/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc00000e478, 0xc0009ae000, 0x7bd5, 0x7bd5, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/net.go:184 +0x8e
crypto/tls.(*atLeastReader).Read(0xc001b326e0, 0xc0009ae000, 0x7bd5, 0x7bd5, 0x28, 0xc001b319b0, 0xc000337918)
    /opt/hostedtoolcache/go/1.14/x64/src/crypto/tls/conn.go:760 +0x60
bytes.(*Buffer).ReadFrom(0xc000bd8258, 0x7de0c0, 0xc001b326e0, 0x409ce5, 0x711ee0, 0x754ee0)
    /opt/hostedtoolcache/go/1.14/x64/src/bytes/buffer.go:204 +0xb1
crypto/tls.(*Conn).readFromUntil(0xc000bd8000, 0x7de340, 0xc00000e478, 0x5, 0xc00000e478, 0xc000400800)
    /opt/hostedtoolcache/go/1.14/x64/src/crypto/tls/conn.go:782 +0xec
crypto/tls.(*Conn).readRecordOrCCS(0xc000bd8000, 0x0, 0x0, 0xc00000e1c8)
    /opt/hostedtoolcache/go/1.14/x64/src/crypto/tls/conn.go:589 +0x115
crypto/tls.(*Conn).readRecord(...)
    /opt/hostedtoolcache/go/1.14/x64/src/crypto/tls/conn.go:557
crypto/tls.(*Conn).Read(0xc000bd8000, 0xc000405000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/crypto/tls/conn.go:1233 +0x15b
net/http.(*persistConn).Read(0xc000c097a0, 0xc000405000, 0x1000, 0x1000, 0xc000a4f260, 0xc000337c70, 0x404da5)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1825 +0x75
bufio.(*Reader).fill(0xc0002f2120)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:100 +0x103
bufio.(*Reader).Peek(0xc0002f2120, 0x1, 0x0, 0x0, 0x1, 0xc000a4f100, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:138 +0x4f
net/http.(*persistConn).readLoop(0xc000c097a0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1978 +0x1a8
created by net/http.(*Transport).dialConn
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1647 +0xc56

goroutine 25140 [select, 2 minutes]:
net/http.(*persistConn).readLoop(0xc001844c60)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:2099 +0x99e
created by net/http.(*Transport).dialConn
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1647 +0xc56

goroutine 26958 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x7ff89952abe0, 0x72, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/netpoll.go:203 +0x55
internal/poll.(*pollDesc).wait(0xc000d81f98, 0x72, 0x0, 0x1, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000d81f80, 0xc000e26fa1, 0x1, 0x1, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_unix.go:169 +0x19b
net.(*netFD).Read(0xc000d81f80, 0xc000e26fa1, 0x1, 0x1, 0xc000c54840, 0x100000001, 0xc000c54840)
    /opt/hostedtoolcache/go/1.14/x64/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc00000f030, 0xc000e26fa1, 0x1, 0x1, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/net.go:184 +0x8e
net/http.(*connReader).backgroundRead(0xc000e26f90)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:678 +0x58
created by net/http.(*connReader).startBackgroundRead
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:674 +0xd0

goroutine 25293 [IO wait, 1 minutes]:
internal/poll.runtime_pollWait(0x7ff899529fa0, 0x72, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/netpoll.go:203 +0x55
internal/poll.(*pollDesc).wait(0xc000a06b98, 0x72, 0x1000, 0x1000, 0xffffffffffffffff)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc000a06b80, 0xc001391000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/internal/poll/fd_unix.go:169 +0x19b
net.(*netFD).Read(0xc000a06b80, 0xc001391000, 0x1000, 0x1000, 0x203000, 0x203000, 0x4ef0c2)
    /opt/hostedtoolcache/go/1.14/x64/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc00000e908, 0xc001391000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/net.go:184 +0x8e
net/http.(*connReader).Read(0xc0008bb320, 0xc001391000, 0x1000, 0x1000, 0x2, 0xf, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:786 +0xf4
bufio.(*Reader).fill(0xc000e5a120)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:100 +0x103
bufio.(*Reader).ReadSlice(0xc000e5a120, 0xc00090390a, 0x43c4df, 0xc0009039c0, 0x40bd06, 0xc00013c400, 0x100)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:359 +0x3d
bufio.(*Reader).ReadLine(0xc000e5a120, 0xc0009039c8, 0x9f82c0, 0x7ff8c019d108, 0x0, 0x74f680, 0xc000c2c840)
    /opt/hostedtoolcache/go/1.14/x64/src/bufio/bufio.go:388 +0x34
net/textproto.(*Reader).readLineSlice(0xc000c2c840, 0xc00013c400, 0x0, 0x4350ac, 0xc000903a28, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/textproto/reader.go:58 +0x6c
net/textproto.(*Reader).ReadLine(...)
    /opt/hostedtoolcache/go/1.14/x64/src/net/textproto/reader.go:39
net/http.readRequest(0xc000e5a120, 0x0, 0xc00013c400, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/request.go:1015 +0xa4
net/http.(*conn).readRequest(0xc000bd6960, 0x7e3dc0, 0xc0012b3e40, 0x0, 0x0, 0x0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:966 +0x191
net/http.(*conn).serve(0xc000bd6960, 0x7e3dc0, 0xc0012b3e40)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:1822 +0x6d4
created by net/http.(*Server).Serve
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:2933 +0x35c

goroutine 27036 [select, 1 minutes]:
net/http.(*persistConn).writeLoop(0xc000c086c0)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:2277 +0x11c
created by net/http.(*Transport).dialConn
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/transport.go:1648 +0xc7b

goroutine 25403 [chan receive, 2 minutes]:
main.aggregateTimemap(0xc0002807c0, 0x18, 0x0, 0xc0001e1a00, 0x1)
    /home/runner/work/MemGator/MemGator/main.go:440 +0x1ad
main.memgatorService(0x7e3640, 0xc0002e7880, 0xc00013c800, 0xc0002807c0, 0x18, 0xc00001cd0d, 0x4, 0x0)
    /home/runner/work/MemGator/MemGator/main.go:594 +0x28f
main.router(0x7e3640, 0xc0002e7880, 0xc00013c800)
    /home/runner/work/MemGator/MemGator/main.go:740 +0x404
net/http.HandlerFunc.ServeHTTP(0x7828c8, 0x7e3640, 0xc0002e7880, 0xc00013c800)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:2012 +0x44
net/http.serverHandler.ServeHTTP(0xc0003f4620, 0x7e3640, 0xc0002e7880, 0xc00013c800)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:2807 +0xa3
net/http.(*conn).serve(0xc001848820, 0x7e3dc0, 0xc0011cbf00)
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:1895 +0x86c
created by net/http.(*Server).Serve
    /opt/hostedtoolcache/go/1.14/x64/src/net/http/server.go:2933 +0x35c

goroutine 26672 [semacquire, 2 minutes]:
sync.runtime_Semacquire(0xc000272d88)
    /opt/hostedtoolcache/go/1.14/x64/src/runtime/sema.go:56 +0x42
sync.(*WaitGroup).Wait(0xc000272d80)
    /opt/hostedtoolcache/go/1.14/x64/src/sync/waitgroup.go:130 +0x64
main.aggregateTimemap.func1(0xc000272d80, 0xc0000494a0)
    /home/runner/work/MemGator/MemGator/main.go:436 +0x2b
created by main.aggregateTimemap
    /home/runner/work/MemGator/MemGator/main.go:435 +0x149
machawk1 commented 3 years ago

I am wondering if the requests are simply accumulating faster than the archives can respond, causing the connections to build up in the MemGator binary for a variety of requesters based on where the error is responds (main.go lines 435-436). I may try to recompile MemGator with a newer version of Golang and report back. In the meantime, I have re-invoked the instance.

ibnesayeed commented 3 years ago

It is possible that the TimeMap being processed is too large to fit in the memory of the machine.

machawk1 commented 3 years ago

I suppose that is possible. I have performed the above and recompiled MemGator for go 1.16.5 and re-launched the binary. If it crashes again, I will receive a report and see if the trace remains similar to the above.

machawk1 commented 3 years ago

I drastically reduced the parameters to have a Header timeout and Response timeout of 30s each and the instance seems more stable. This likely has the effect of excluding slow web archives but some results returned are better than the service being down.