$user_agent - core.25213


2020/03/18 08:26:55 [debug] 25213#0: MEMSTORE:00: chanhead_gc max -1 count 0
2020/03/18 08:26:55 [debug] 25213#0: MEMSTORE:00: message GC results: started with 0, walked 0, deleted 0 msgs
2020/03/18 08:26:55 [debug] 25213#0: MEMSTORE:00: not ready to reap test/KZAJr96jRAKlxu5VqTuyhw, 1 subs left
2020/03/18 08:26:55 [debug] 25213#0: REAPER: reap chanhead churner again later (remaining: 1)
2020/03/18 08:26:55 [debug] 25213#0: SUB:LONGPOLL:create for req 0000000002620C80
2020/03/18 08:26:55 [debug] 25213#0: SUB:LONGPOLL:00000000025D56D0 created for request 0000000002620C80
2020/03/18 08:26:55 [debug] 25213#0: SUB:LONGPOLL:hodl request 0000000002620C80
2020/03/18 08:26:55 [debug] 25213#0: SUB:LONGPOLL:00000000025D56D0 reserve for req 0000000002620C80, reservations: 1
2020/03/18 08:26:55 [debug] 25213#0: *4127 [lua] init.lua:852: balancer(): setting address (try 1): 137.236.145.54:8002
2020/03/18 08:26:55 [warn] 25213#0: *4127 [lua] reports.lua:70: log(): [reports] unknown request scheme: http while logging request, client: 127.0.0.1, serv
er: kong, request: "GET /internal/subscribe HTTP/1.0", upstream: "http://137.236.145.54:8002/rfc/v1/events/streams", host: "localhost:8000"
2020/03/18 08:26:55 [debug] 25213#0: SUB:LONGPOLL:00000000025D56D0 release for req 0000000002620C80. reservations: 0
2020/03/18 08:26:55 [debug] 25213#0: SPOOL:start SPOOLER 00007F89849C8AC0
2020/03/18 08:26:55 [debug] 25213#0: MEMSTORE:00: ensure chanhead ready: chanhead 0000000002627CA0, status 1, foreign_ipc_sub:0000000000000000
2020/03/18 08:26:55 [debug] 25213#0: MEMSTORE:00: Chanhead churn add 0000000002627CA0 test/lOfn6-goR5ypMYvmKpFvqA
2020/03/18 08:26:55 [debug] 25213#0: MEMSTORE:00: chanhead_gc max -1 count 0
2020/03/18 08:26:55 [debug] 25213#0: MEMSTORE:00: message GC results: started with 0, walked 0, deleted 0 msgs
2020/03/18 08:26:55 [debug] 25213#0: MEMSTORE:00: not ready to reap 0000000002627CA0 test/lOfn6-goR5ypMYvmKpFvqA, 5 sec left
2020/03/18 08:26:55 [debug] 25213#0: REAPER: reap chanhead churner 0000000002627CA0 later (waiting to be reaped: 2)
2020/03/18 08:26:55 [debug] 25213#0: RBTREE:node not found
2020/03/18 08:26:55 [debug] 25213#0: RBTREE:created node 0000000002628080
2020/03/18 08:26:55 [debug] 25213#0: RBTREE:inserted node 0000000002628080
2020/03/18 08:26:55 [debug] 25213#0: SUB:RAWSTREAM:00000000025D56D0 output status to subscriber
2020/03/18 08:26:55 [debug] 25213#0: SUB:LONGPOLL:00000000025D56D0 enqueue
2020/03/18 08:26:55 [debug] 25213#0: SPOOL:00000000026280A8 fetch msg 0:0 for channel test/lOfn6-goR5ypMYvmKpFvqA
2020/03/18 08:26:55 [debug] 25213#0: MEMSTORE:00: ensure chanhead ready: chanhead 0000000002627CA0, status 4, foreign_ipc_sub:0000000000000000
2020/03/18 08:26:55 [debug] 25213#0: MEMSTORE:00: chanhead_gc max -1 count 0
2020/03/18 08:26:55 [debug] 25213#0: MEMSTORE:00: message GC results: started with 0, walked 0, deleted 0 msgs
2020/03/18 08:26:55 [debug] 25213#0: RBTREE:found node 0000000002628080
2020/03/18 08:26:55 [debug] 25213#0: SPOOL:fetchmsg callback for spool 00000000026280A8 msg EXPECTED
2020/03/18 08:26:55 [debug] 25213#0: SPOOL:spool 00000000026280A8 (0:0) (subs: 1) respond with msg 0000000000000000 or code 204
2020/03/18 08:26:56 [debug] 25213#0: *4131 [lua] base.lua:1202: cb_expire(): [ringbalancer 1] executing requery timer
2020/03/18 08:26:56 [debug] 25213#0: *4131 [lua] base.lua:1211: cb_expire(): [ringbalancer 1] requery completed
2020/03/18 08:26:57 [debug] 25213#0: *4135 [lua] base.lua:1202: cb_expire(): [ringbalancer 1] executing requery timer
2020/03/18 08:26:57 [debug] 25213#0: *4135 [lua] base.lua:1211: cb_expire(): [ringbalancer 1] requery completed
2020/03/18 08:26:58 [debug] 25213#0: *4139 [lua] base.lua:1202: cb_expire(): [ringbalancer 1] executing requery timer
2020/03/18 08:26:58 [debug] 25213#0: *4139 [lua] base.lua:1211: cb_expire(): [ringbalancer 1] requery completed
2020/03/18 08:26:59 [debug] 25213#0: *4143 [lua] base.lua:1202: cb_expire(): [ringbalancer 1] executing requery timer
2020/03/18 08:26:59 [debug] 25213#0: *4143 [lua] base.lua:1211: cb_expire(): [ringbalancer 1] requery completed
2020/03/18 08:26:59 [debug] 25213#0: *4144 [lua] init.lua:227: [cluster_events] polling events from: 1584533449.139 to: 1584534419.416
2020/03/18 08:27:00 [debug] 25213#0: *4148 [lua] base.lua:1202: cb_expire(): [ringbalancer 1] executing requery timer
2020/03/18 08:27:00 [debug] 25213#0: *4148 [lua] base.lua:1211: cb_expire(): [ringbalancer 1] requery completed
2020/03/18 08:27:01 [debug] 25213#0: *4152 [lua] base.lua:1202: cb_expire(): [ringbalancer 1] executing requery timer
2020/03/18 08:27:01 [debug] 25213#0: *4152 [lua] base.lua:1211: cb_expire(): [ringbalancer 1] requery completed
2020/03/18 08:27:02 [debug] 25213#0: *4156 [lua] base.lua:1202: cb_expire(): [ringbalancer 1] executing requery timer
2020/03/18 08:27:02 [debug] 25213#0: *4156 [lua] base.lua:1211: cb_expire(): [ringbalancer 1] requery completed
2020/03/18 08:27:03 [debug] 25213#0: *4160 [lua] base.lua:1202: cb_expire(): [ringbalancer 1] executing requery timer
2020/03/18 08:27:03 [debug] 25213#0: *4160 [lua] base.lua:1211: cb_expire(): [ringbalancer 1] requery completed
2020/03/18 08:27:04 [debug] 25213#0: *4164 [lua] base.lua:1202: cb_expire(): [ringbalancer 1] executing requery timer
2020/03/18 08:27:04 [debug] 25213#0: *4164 [lua] base.lua:1211: cb_expire(): [ringbalancer 1] requery completed
2020/03/18 08:27:04 [debug] 25213#0: *4165 [lua] init.lua:227: [cluster_events] polling events from: 1584533449.139 to: 1584534424.418
2020/03/18 08:27:05 [debug] 25213#0: *4169 [lua] base.lua:1202: cb_expire(): [ringbalancer 1] executing requery timer
2020/03/18 08:27:05 [debug] 25213#0: *4169 [lua] base.lua:1211: cb_expire(): [ringbalancer 1] requery completed
2020/03/18 08:27:05 [debug] 25213#0: REAPER: chanhead churner keep_place max notready 0, cur 000000000261BB90
2020/03/18 08:27:05 [debug] 25213#0: MEMSTORE:00: chanhead_gc max -1 count 0
2020/03/18 08:27:05 [debug] 25213#0: MEMSTORE:00: message GC results: started with 0, walked 0, deleted 0 msgs
2020/03/18 08:27:05 [debug] 25213#0: MEMSTORE:00: not ready to reap test/KZAJr96jRAKlxu5VqTuyhw, 1 subs left
2020/03/18 08:27:05 [debug] 25213#0: MEMSTORE:00: chanhead_gc max -1 count 0
2020/03/18 08:27:05 [debug] 25213#0: MEMSTORE:00: message GC results: started with 0, walked 0, deleted 0 msgs
2020/03/18 08:27:05 [debug] 25213#0: MEMSTORE:00: not ready to reap test/lOfn6-goR5ypMYvmKpFvqA, 1 subs left
2020/03/18 08:27:05 [debug] 25213#0: REAPER: reap chanhead churner again later (remaining: 2)
2020/03/18 08:27:05 [info] 25213#0: *4114 client prematurely closed connection while processing HTTP/2 connection, client: 137.236.145.223, server: 0.0.0.0:
8443
2020/03/18 08:27:05 [info] 25213#0: *4114 client prematurely closed connection, client: 137.236.145.223, server: kong, request: "GET /rfc/v1/events/streams/
lOfn6-goR5ypMYvmKpFvqA HTTP/2.0", host: "tf-vapigw-d002.xpedite.com:8443"
2020/03/18 08:27:05 [debug] 25213#0: SUB:LONGPOLL:00000000025D56D0 dequeue
2020/03/18 08:27:05 [debug] 25213#0: SPOOL:sub 00000000025D56D0 dequeue callback
2020/03/18 08:27:05 [debug] 25213#0: MEMSTORE:00: Chanhead gc add 0000000002627CA0 test/lOfn6-goR5ypMYvmKpFvqA: sub count == 0 after spooler dequeue
2020/03/18 08:27:05 [debug] 25213#0: MEMSTORE:00: Chanhead churn withdraw 0000000002627CA0 test/lOfn6-goR5ypMYvmKpFvqA
2020/03/18 08:27:05 [debug] 25213#0: REAPER: withdraw chanhead churner 0000000002627CA0
2020/03/18 08:27:05 [debug] 25213#0: MEMSTORE:00: chanhead_gc max -1 count 0
2020/03/18 08:27:05 [debug] 25213#0: MEMSTORE:00: message GC results: started with 0, walked 0, deleted 0 msgs
2020/03/18 08:27:05 [debug] 25213#0: MEMSTORE:00: not ready to reap test/lOfn6-goR5ypMYvmKpFvqA, 5 sec left
2020/03/18 08:27:05 [debug] 25213#0: REAPER: reap chanhead 0000000002627CA0 later (waiting to be reaped: 1)
2020/03/18 08:27:05 [debug] 25213#0: REAPER: reap chanhead again later (remaining: 1)
2020/03/18 08:27:05 [debug] 25213#0: SUB:LONGPOLL:00000000025D56D0 destroy for req 0000000002620C80
2020/03/18 08:27:05 [debug] 25213#0: *4172 [lua] init.lua:852: balancer(): setting address (try 1): 137.236.145.54:8002
2020/03/18 08:27:05 [warn] 25213#0: *4172 [lua] reports.lua:70: log(): [reports] unknown request scheme: http while logging request, client: 127.0.0.1, serv
er: kong, request: "GET /internal/unsubscribe HTTP/1.0", upstream: "http://137.236.145.54:8002/rfc/v1/events/streams/unsubscribe", host: "localhost:8000"
2020/03/18 08:27:07 [notice] 25212#0: signal 17 (SIGCHLD) received from 25213
2020/03/18 08:27:07 [alert] 25212#0: worker process 25213 exited on signal 11 (core dumped)
2020/03/18 08:27:07 [notice] 25212#0: start worker process 26515
2020/03/18 08:27:07 [debug] 26515#0: *4173 [lua] globalpatches.lua:243: randomseed(): seeding PRNG from OpenSSL RAND_bytes()
2020/03/18 08:27:07 [debug] 26515#0: *4173 [lua] globalpatches.lua:269: randomseed(): random seed: 455791179103 for worker nb 0
2020/03/18 08:27:07 [debug] 26515#0: *4173 [lua] events.lua:211: do_event_json(): worker-events: handling event; source=resty-worker-events, event=started,
pid=26515, data=nil
2020/03/18 08:27:07 [notice] 26515#0: *4173 [lua] cache_warmup.lua:42: cache_warmup_single_entity(): Preloading 'services' into the cache ..., context: init
_worker_by_lua*
2020/03/18 08:27:07 [notice] 26515#0: *4173 [lua] cache_warmup.lua:81: cache_warmup_single_entity(): finished preloading 'services' into the cache (in 39ms)
, context: init_worker_by_lua*
2020/03/18 08:27:07 [notice] 26515#0: *4173 [lua] cache_warmup.lua:42: cache_warmup_single_entity(): Preloading 'plugins' into the cache ..., context: init_
worker_by_lua*
2020/03/18 08:27:07 [notice] 26515#0: *4173 [lua] cache_warmup.lua:81: cache_warmup_single_entity(): finished preloading 'plugins' into the cache (in 19ms),
 context: init_worker_by_lua*
2020/03/18 08:27:07 [debug] 26515#0: REAPER: start reaper memstore message with tick time of 5 sec
2020/03/18 08:27:07 [debug] 26515#0: REAPER: start reaper memstore nobuffer message with tick time of 2 sec
2020/03/18 08:27:07 [debug] 26515#0: REAPER: start reaper chanhead with tick time of 4 sec
2020/03/18 08:27:07 [debug] 26515#0: REAPER: start reaper chanhead churner with tick time of 10 sec
2020/03/18 08:27:07 [debug] 26515#0: MEMSTORE:00: init memstore worker pid:26515 slot:0 max workers :1 or 1
2020/03/18 08:27:07 [debug] 26515#0: MEMSTORE:00: found my procslot (ngx_process_slot 0, procslot 0)
2020/03/18 08:27:07 [debug] 26515#0: MEMSTORE:00: shm: 00000000025859F0, shdata: 00007F896E767000
2020/03/18 08:27:07 [debug] 26515#0: WEBSOCKET_PUBLISHER:init WS publisher llist
2020/03/18 08:27:07 [debug] 26515#0: THINGCACHE: init fd_cache 00000000024FE420